[asterisk-users] No Voice - only "noisy audio"

Tue May 26 12:20:23 CDT 2009

Hi Folks,

I'm trying to use my mobile as a trunk via bluetooth - calls done in a
softphone go thru GSM network and calls destinated to my mobile are answered
at the softphone.

I have asterisk configured to do so but I'm facing an issue - Audio is
audible but it’s not intelligible. I feel like the audio is breaking.
Below is the asterisk log. I also get lots of “hci_scodata_packet: hci0 SCO
packet for unknown connection handle XXXXX” and "btusb_isoc_complete: hci0
corrupted SCO packet" entries in kernel logs.

Can anybody please help?
Tks
++++++
13:37:17 chan_sip.c: Allocating new SIP dialog for
42eb60ff04309999607e7eb97cc86c69 at 192.168.0.204 - OPTIONS (No RTP)
13:37:17 acl.c: Found IP address for this socket
13:37:17 chan_sip.c: Initializing initreq for method OPTIONS - callid
5bae8a561541036e45990a137366cb14 at 192.168.0.204
13:37:17 chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for
192.168.0.84:27928
13:37:17 chan_sip.c: Stopping retransmission on '
5bae8a561541036e45990a137366cb14 at 192.168.0.204' of Request 102: Match Found
13:37:17 chan_sip.c: Destroying SIP dialog
5bae8a561541036e45990a137366cb14 at 192.168.0.204
13:37:40 acl.c: Found IP address for this socket
13:37:40 netsock.c:   == Using SIP RTP CoS mark 5
13:37:40 chan_sip.c: Setting NAT on RTP to Off
13:37:40 chan_sip.c: Allocating new SIP dialog for
N2ExYWUwNGJkODAzZGMyYjBmYzQwMTY1YzgwMGQ5MWM. - INVITE (With RTP)
13:37:40 chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
13:37:40 chan_sip.c: Setting NAT on RTP to Off
13:37:40 chan_sip.c: Trying to put 'SIP/2.0 40' onto UDP socket destined for
192.168.0.84:27928
13:37:40 chan_sip.c: **** Received ACK (6) - Command in SIP ACK
13:37:40 chan_sip.c: Stopping retransmission on
'N2ExYWUwNGJkODAzZGMyYjBmYzQwMTY1YzgwMGQ5MWM.' of Response 1: Match Found
13:37:40 chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
13:37:40 chan_sip.c: Setting NAT on RTP to Off
13:37:40 chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw)
13:37:40 chan_sip.c: Checking SIP call limits for device 1000
13:37:40 chan_sip.c: Updating call counter for incoming call
13:37:40 devicestate.c: No provider found, checking channel drivers for SIP
- 1000
13:37:40 chan_sip.c: Checking device state for peer 1000
13:37:40 devicestate.c: Changing state for SIP/1000 - state 2 (In use)
13:37:40 devicestate.c: device 'SIP/1000' state '2'
13:37:40 app_queue.c: Device 'SIP/1000' changed to state '2' (In use) but we
don't care because they're not a member of any queue.
13:37:40 chan_sip.c: *** Our native formats are 0x4 (ulaw)
13:37:40 chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw)
13:37:40 chan_sip.c: *** Our capabilities are 0xe (gsm|ulaw|alaw)
13:37:40 chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
13:37:40 chan_sip.c: This channel will not be able to handle video.
13:37:40 chan_sip.c: build_route: Contact hop: <sip:1000 at 192.168.0.84:27928>
13:37:40 chan_sip.c: SIP/1000-0021a568: New call is still down.... Trying...

13:37:40 chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for
192.168.0.84:27928
13:37:40 devicestate.c: No provider found, checking channel drivers for SIP
- 1000
13:37:40 chan_sip.c: Checking device state for peer 1000
13:37:40 devicestate.c: Changing state for SIP/1000 - state 2 (In use)
13:37:40 devicestate.c: device 'SIP/1000' state '2'
13:37:40 app_queue.c: Device 'SIP/1000' changed to state '2' (In use) but we
don't care because they're not a member of any queue.
13:37:40 pbx.c: Launching 'Answer'
13:37:40 ] pbx.c:     -- Executing [1234 at from-internal:1]
Answer("SIP/1000-0021a568", "") in new stack
13:37:40 devicestate.c: No provider found, checking channel drivers for SIP
- 1000
13:37:40 chan_sip.c: Checking device state for peer 1000
13:37:40 devicestate.c: Changing state for SIP/1000 - state 2 (In use)
13:37:40 devicestate.c: device 'SIP/1000' state '2'
13:37:40 app_queue.c: Device 'SIP/1000' changed to state '2' (In use) but we
don't care because they're not a member of any queue.
13:37:40 chan_sip.c: SIP answering channel: SIP/1000-0021a568
13:37:40 chan_sip.c: Setting framing from config on incoming call
13:37:40 chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True
Text flag: True
13:37:40 chan_sip.c: ** Our prefcodec: 0x0 (nothing)
13:37:40 chan_sip.c: -- Done with adding codecs to SDP
13:37:40 channel.c: Internal timing is disabled (option_internal_timing=0
chan->timingfd=28)
13:37:40 chan_sip.c: Done building SDP. Settling with this capability: 0xc
(ulaw|alaw)
13:37:40 chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for
192.168.0.84:27928
13:37:40 rtp.c: Got RTCP report of 132 bytes
13:37:40 pbx.c: Launching 'Dial'
13:37:40 ] pbx.c:     -- Executing [1234 at from-internal:2]
Dial("SIP/1000-0021a568", "Mobile/Carlos/909037079681") in new stack
13:37:40 rtp.c: Channel 'Mobile/Carlos-0213' has no RTP, not doing anything
13:37:40 channel.c: Not copying variable DIALEDTIME.
13:37:40 channel.c: Not copying variable ANSWEREDTIME.
13:37:40 channel.c: Not copying variable DIALEDPEERNAME.
13:37:40 channel.c: Not copying variable DIALEDPEERNUMBER.
13:37:40 channel.c: Not copying variable DIALSTATUS.
13:37:40 channel.c: Not copying variable SIPCALLID.
13:37:40 channel.c: Not copying variable SIPDOMAIN.
13:37:40 channel.c: Not copying variable SIPURI.
13:37:40 chan_mobile.c: Calling Carlos/909037079681 on Mobile/Carlos-0213
13:37:40 ] app_dial.c:     -- Called Carlos/909037079681
13:37:40 channel.c: Set channel Mobile/Carlos-0213 to read format ulaw
13:37:40 channel.c: Set channel SIP/1000-0021a568 to read format slin
13:37:40 chan_mobile.c: *** mbl_write
13:37:40 chan_mobile.c: sco_write() not ready
13:37:40 chan_sip.c: **** Received ACK (6) - Command in SIP ACK
13:37:40 chan_sip.c: Stopping retransmission on
'N2ExYWUwNGJkODAzZGMyYjBmYzQwMTY1YzgwMGQ5MWM.' of Response 2: Match Found
13:37:40 chan_mobile.c: *** mbl_write
13:37:40 chan_mobile.c: sco_write() not ready
13:37:40 chan_mobile.c: sco_read() not ready
13:37:40 chan_mobile.c: rfcomm_write() (Carlos) [ATD909037079681;
13:37:41 chan_mobile.c: sco_write() not ready
13:37:41 chan_mobile.c: sco_read() not ready
13:37:41 chan_mobile.c: rfcomm_read() (Carlos) [OK]
13:37:41 devicestate.c: No provider found, checking channel drivers for
Mobile - Carlos
13:37:41 chan_mobile.c: Checking device state for device Carlos
13:37:41 devicestate.c: Changing state for Mobile/Carlos - state 2 (In use)
13:37:41 devicestate.c: device 'Mobile/Carlos' state '2'
13:37:41 app_queue.c: Device 'Mobile/Carlos' changed to state '2' (In use)
13:37:41 chan_mobile.c: rfcomm_read() (Carlos) [+CIEV: 2,2]
13:37:41 chan_mobile.c: *** mbl_write
13:37:41 chan_mobile.c: sco_write() not ready
13:37:41 chan_mobile.c: sco_read() not ready
13:37:41 chan_mobile.c: accept()ed socket.
13:37:41 chan_mobile.c: Incoming Audio Connection from device
00:21:FB:B4:45:07 MTU is 48
13:37:41 chan_mobile.c: About to accept() socket.
13:37:41 chan_mobile.c: *** mbl_write
13:37:45 chan_mobile.c: sco_write()
13:37:45 chan_mobile.c: sco_read()
13:37:45 chan_mobile.c: rfcomm_read() (Carlos) [+CIEV: 2,3]
13:37:47 chan_mobile.c: sco_write()
13:37:47 chan_mobile.c: sco_read()
13:37:47 ] app_dial.c:     -- Mobile/Carlos-0213 is ringing
13:37:47 channel.c: Driver for channel 'SIP/1000-0021a568' does not support
indication 3, emulating it
13:37:47 channel.c: Set channel SIP/1000-0021a568 to write format slin
13:37:47 channel.c: Scheduling timer at (50 requested / 50 actual) timer
ticks per second
13:37:47 channel.c: Internal timing is disabled (option_internal_timing=0
chan->timingfd=28)
13:37:47 channel.c: Generator got voice, switching to phase locked mode
13:37:47 channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks
per second
13:37:47 rtp.c: Ooh, format changed from unknown to ulaw
13:37:47 rtp.c: Created smoother: format: 4 ms: 20 len: 160
13:37:47 chan_mobile.c: *** mbl_write
13:37:47 chan_mobile.c: sco_write()
13:37:47 chan_mobile.c: sco_read()
13:37:58 chan_mobile.c: rfcomm_read() (Carlos) [+CIEV: 2,0]
13:37:58 devicestate.c: No provider found, checking channel drivers for
Mobile - Carlos
13:37:58 chan_mobile.c: Checking device state for device Carlos
13:37:58 devicestate.c: Changing state for Mobile/Carlos - state 2 (In use)
13:37:58 devicestate.c: device 'Mobile/Carlos' state '2'
13:37:58 app_queue.c: Device 'Mobile/Carlos' changed to state '2'
13:37:58 ] app_dial.c:     -- Mobile/Carlos-0213 answered SIP/1000-0021a568
13:37:58 channel.c: Set channel SIP/1000-0021a568 to write format ulaw
13:37:58 channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks
per second
13:37:58 features.c: bridge answer set, chan answer set
13:37:58 chan_mobile.c: *** mbl_write
13:37:58 chan_mobile.c: sco_write()
13:37:58 chan_mobile.c: sco_read()
13:38:17 chan_mobile.c: *** mbl_read()
13:38:17 chan_mobile.c: *** mbl_write
13:38:17 chan_mobile.c: sco_write()
13:38:17 chan_mobile.c: sco_read()
13:38:17 chan_sip.c: Allocating new SIP dialog for
722c10b0225c5f792e6a6782773f69c1 at 192.168.0.204 - OPTIONS (No RTP)
13:38:17 acl.c: Found IP address for this socket
13:38:17 chan_sip.c: Initializing initreq for method OPTIONS - callid
2017d8501354b495687908065564fd2b at 192.168.0.204
13:38:17 chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for
192.168.0.84:27928
13:38:17 chan_sip.c: Stopping retransmission on '
2017d8501354b495687908065564fd2b at 192.168.0.204' of Request 102: Match Found
13:38:17 chan_sip.c: Destroying SIP dialog
2017d8501354b495687908065564fd2b at 192.168.0.204
13:38:40 chan_mobile.c: sco_write()
13:38:40 chan_mobile.c: sco_read()
13:38:40 chan_mobile.c: rfcomm_read() (Carlos) [+CIEV: 1,0]
13:38:40 chan_mobile.c: sco_read() error 104
13:38:40 chan_mobile.c: sco_write()
13:38:40 chan_mobile.c: sco write error 107
13:38:40 chan_mobile.c: sco_read()
13:38:40 chan_mobile.c: sco_read() error 107
13:38:40 chan_mobile.c: sco_write()
13:38:40 chan_mobile.c: sco write error 107
13:38:40 chan_mobile.c: sco_read()
13:38:40 chan_mobile.c: sco_write()
13:38:40 chan_mobile.c: sco write error 107
13:38:40 chan_mobile.c: sco_read()
13:38:40 chan_mobile.c: sco_read() error 107
13:38:40 channel.c: Didn't get a frame from channel: Mobile/Carlos-0213
13:38:40 channel.c: Bridge stops bridging channels SIP/1000-0021a568 and
Mobile/Carlos-0213
13:38:40 channel.c: Hanging up channel 'Mobile/Carlos-0213'
13:38:40 chan_mobile.c: Hanging up device Carlos.
13:38:40 rtp.c: Channel '<unspecified>' has no RTP, not doing anything
13:38:40 app_dial.c: Exiting with DIALSTATUS=ANSWER.
13:38:40 pbx.c: Spawn extension (from-internal,1234,2) exited non-zero on
'SIP/1000-0021a568'
13:38:40 ] pbx.c:   == Spawn extension (from-internal, 1234, 2) exited
non-zero on 'SIP/1000-0021a568'
13:38:40 channel.c: Soft-Hanging up channel 'SIP/1000-0021a568'
13:38:40 channel.c: Hanging up channel 'SIP/1000-0021a568'
13:38:40 chan_sip.c: Hangup call SIP/1000-0021a568, SIP callid
N2ExYWUwNGJkODAzZGMyYjBmYzQwMTY1YzgwMGQ5MWM.
13:38:40 chan_sip.c: Updating call counter for incoming call
13:38:40 chan_sip.c: Trying to put 'BYE sip:10' onto UDP socket destined for
192.168.0.84:27928
13:38:40 devicestate.c: No provider found, checking channel drivers for
Mobile - Carlos
13:38:40 chan_mobile.c: Checking device state for device Carlos
13:38:40 devicestate.c: Changing state for Mobile/Carlos - state 1 (Not in
use)
13:38:40 devicestate.c: device 'Mobile/Carlos' state '1'
13:38:40 devicestate.c: No provider found, checking channel drivers for
Mobile - Carlos
13:38:40 chan_mobile.c: Checking device state for device Carlos
13:38:40 devicestate.c: Changing state for Mobile/Carlos - state 1 (Not in
use)
13:38:40 devicestate.c: device 'Mobile/Carlos' state '1'
13:38:40 devicestate.c: No provider found, checking channel drivers for SIP
- 1000
13:38:40 chan_sip.c: Checking device state for peer 1000
13:38:40 devicestate.c: Changing state for SIP/1000 - state 1 (Not in use)
13:38:40 devicestate.c: device 'SIP/1000' state '1'
13:38:40 devicestate.c: No provider found, checking channel drivers for SIP
- 1000
13:38:40 chan_sip.c: Checking device state for peer 1000
13:38:40 devicestate.c: Changing state for SIP/1000 - state 1 (Not in use)
13:38:40 devicestate.c: device 'SIP/1000' state '1'
13:38:40 app_queue.c: Device 'Mobile/Carlos' changed to state '1' (Not in
use) but we don't care because they're not a member of any queue.
13:38:40 app_queue.c: Device 'Mobile/Carlos' changed to state '1' (Not in
use) but we don't care because they're not a member of any queue.
13:38:40 app_queue.c: Device 'SIP/1000' changed to state '1' (Not in use)
but we don't care because they're not a member of any queue.
13:38:40 app_queue.c: Device 'SIP/1000' changed to state '1' (Not in use)
but we don't care because they're not a member of any queue.
13:38:41 chan_sip.c: Stopping retransmission on
'N2ExYWUwNGJkODAzZGMyYjBmYzQwMTY1YzgwMGQ5MWM.' of Request 102: Match Found
13:38:41 chan_sip.c: Destroying SIP dialog
N2ExYWUwNGJkODAzZGMyYjBmYzQwMTY1YzgwMGQ5MWM.
13:39:17 chan_sip.c: Allocating new SIP dialog for
6525582122c4dee623105dae29c8f54e at 192.168.0.204 - OPTIONS (No RTP)
13:39:17 acl.c: Found IP address for this socket
13:39:17 chan_sip.c: Initializing initreq for method OPTIONS - callid
21e561fe62326fbb3606dc972e9140c9 at 192.168.0.204
13:39:17 chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for
192.168.0.84:27928
13:39:17 chan_sip.c: Stopping retransmission on '
21e561fe62326fbb3606dc972e9140c9 at 192.168.0.204' of Request 102: Match Found
13:39:17 chan_sip.c: Destroying SIP dialog
21e561fe62326fbb3606dc972e9140c9 at 192.168.0.204
13:40:17 chan_sip.c: Allocating new SIP dialog for
3a36fd06486a2c264101bf60396aa03d at 192.168.0.204 - OPTIONS (No RTP)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20090526/e1dcfc79/attachment.htm 