[Home]

Summary:ASTERISK-11042: "No audio" on incoming bluetooth call to voicemail, call dropped
Reporter:non-poster (non-poster)Labels:
Date Opened:2007-12-14 14:55:07.000-0600Date Closed:2009-04-21 13:29:49
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Addons/chan_mobile
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 11556.diff
( 1) audio1.diff
Description:I have "context=incoming-mobile" in mobile.conf for my bluetooth phone.  It connects, and Asterisk indicates that "Usable" for voice = "Yes", "Type" = "Phone".

The incoming-mobile context directs the call to voicemail:
context incoming-mobile {
   _. => {
       VoiceMail(9999,b);
       Hangup();
   };
}


When I call the bluetooth phone, I hear the outgoing voicemail message "...9999 is busy... leave message...beep", then the call is dropped.  The logs contain:

channel.c:2992 in set_format: Set channel Mobile/SCP2500-f304 to write format slin
-- Recording the message
app.c:603 in __ast_play_and_record: Recording Formats: sfmts=sln
rtp.c:1089 in ast_rtcp_read: Got RTCP report of 104 bytes
app.c:657 in __ast_play_and_record: One waitfor failed, trying another
app.c:661 in __ast_play_and_record: No audio available on Mobile/SCP2500-f304??
channel.c:1465 in ast_hangup: Hanging up channel 'Mobile/SCP2500-f304'
chan_mobile.c:667 in mbl_hangup: Hanging up device SCP2500.

The chan_mobile messages:
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CIEV: 3,1]
chan_mobile.c:1418 in do_monitor_phone: Device SCP2500 [+CIEV: 3,1]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [RING]
chan_mobile.c:1418 in do_monitor_phone: Device SCP2500 [RING]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CLIP: "206xxxyyyy",129]
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [ATA ]
chan_mobile.c:869 in mbl_devicestate: Checking device state for device SCP2500
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CIEV: 2,1]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CIEV: 3,0]
chan_mobile.c:1831 in do_sco_listen: accept()ed socket.
chan_mobile.c:1836 in do_sco_listen: Incoming Audio Connection from device 00:00:A0:2E:XX:XX MTU is 64
chan_mobile.c:1828 in do_sco_listen: About to accept() socket.
chan_mobile.c:943 in do_alignment_detection: Alignment Detection result is [0 0 0 0]
chan_mobile.c:667 in mbl_hangup: Hanging up device SCP2500.
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+CHUP ]
chan_mobile.c:869 in mbl_devicestate: Checking device state for device SCP2500
chan_mobile.c:869 in mbl_devicestate: Checking device state for device SCP2500
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CIEV: 2,0]
chan_mobile.c:1418 in do_monitor_phone: Device SCP2500 [+CIEV: 2,0]


****** ADDITIONAL INFORMATION ******

asterisk-92526
asterisk-addons-496
Linux kernel 2.6.23-gentoo-r3
bluez-libs-3.23
bluez-utils-3.23

# hciconfig -a

hci0:   Type: USB
       BD Address: 00:18:E7:22:XX:XX ACL MTU: 1017:8 SCO MTU: 64:8
       UP RUNNING PSCAN ISCAN
       RX bytes:253752 acl:43 sco:4545 events:2153 errors:0
       TX bytes:177751 acl:25 sco:3140 commands:1077 errors:0
       Features: 0xff 0xff 0x8d 0xfe 0x9b 0xf9 0x00 0x80
       Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3
       Link policy: RSWITCH HOLD SNIFF PARK
       Link mode: SLAVE ACCEPT
       Name: 'BlueZ (0)'
       Class: 0x000100
       Service Classes: Unspecified
       Device Class: Computer, Uncategorized
       HCI Ver: 2.0 (0x3) HCI Rev: 0x4020 LMP Ver: 2.0 (0x3) LMP Subver: 0x430e
       Manufacturer: Broadcom Corporation (15)
Comments:By: non-poster (non-poster) 2007-12-14 15:10:33.000-0600

voicemail.conf contains:
format=sln
By: non-poster (non-poster) 2007-12-14 15:28:40.000-0600

Possibly useful docs for Bluetooth:
http://www.bluetooth.com/Bluetooth/Learn/Technology/Specifications/
eg "Hands-Free Profile"
By: non-poster (non-poster) 2007-12-14 15:37:51.000-0600

Phone bluetooth info:
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+BRSF=4 ]
chan_mobile.c:1828 in do_sco_listen: About to accept() socket.
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+BRSF: 359]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+CIND=? ]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CIND: ("service",(0-1)),("call",(0-1)),("callsetup",(0-3)),("signal",(0-5)),("roam",(0-1)),("battchg",(0-5)),("callheld",(0-2))]
chan_mobile.c:1367 in do_monitor_phone: CIEV_CALL=2 CIEV_CALLSETUP=3
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+CIND? ]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+CIND: 1,0,0,1,0,5,0]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+CMER=3,0,0,1 ]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+CLIP=1 ]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [+VGS: 7]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [OK]
chan_mobile.c:1002 in rfcomm_write: rfcomm_write() (SCP2500) [AT+CMGF=1 ]
chan_mobile.c:1326 in do_monitor_phone: rfcomm_read() (SCP2500) [ERROR]
By: non-poster (non-poster) 2007-12-15 03:14:52.000-0600

A few thoughts...

- Could this be related to "ATA" (answer) being sent to the bluetooth phone and then a very short time later, Asterisk answers the channel and starts sending audio, before the phone has actually connected to the call?

- mbl_write() is the only place where sco_read() is called... is mbl_write() called when Voicemail is recording?

- Is there a missed release of a mutex somewhere?
By: Jason Parker (jparker) 2007-12-28 16:58:22.000-0600

If the problem is as non-poster suspects, with sending audio before the channel is actually up - the patch I just added should help...maybe.
By: non-poster (non-poster) 2007-12-29 00:07:17.000-0600

No change with the 11556.diff 12-28-07 16:57 patch.
By: jmls (jmls) 2008-05-03 14:29:19

qwell - any further thoughts ?
By: horbra (horbra) 2008-06-26 04:11:33

I am having the same issue here (using trunk version of chan_mobile (revision 600), backported to asterisk 1.4.21, on a MIPS-based routerbox using OpenWRT, bluez-libs/utils 3.32, kernel 2.6.22 with all bluetooth-mods backported from 2.6.25.4, (but could also reproduce the issue on x86 (2.6.25-kernel with bluez 3.24), and earlier versions of kernel mods (2.6.22) and bluz-libs (2.something and 3.24) on MIPS).

I did a little debugging myself, and noticed the following issues:

- in my backported version, I in the beginning had no audio at all any more, whereas an older patched version (rev 451) still had "one-way" audio as described in this report. I figured when in sco_read() switching back to using recv() instead of read() on the sco_socket, it worked again one-way

- in sco_read(), whenever an non-blocking recv() (see previous bullet) was performed the return value was -1 and errno was 11 (EAGAIN), I _never_ got any successful recv from the socket. It that context it seemed even more strange that switching from recv() to read() would kill the audio completely (also from the send-side)... Could it be that for some reason the socket is only established one-way? I am only beginning to look into how this should work on the bluez-side

- I am new to asterisk and bluez, did some reading on the API docs, but cannot say that I have fully grasped all concepts yet. Yet it occurred to me that mbl_read() (which seems to be registered as the read-method for the mobile asterisk channel), seemed never to be called at all, I never saw any debug message from that routine in the logs, whereas mbl_write() is called frequently. Maybe I overlooked some signaling mechanism that would indicate to asterisk that no useful data was available due to the failing sco_reads (which seem to be actually called by mbl_write(), piping data to the mbl_read(), yet another thing I did not fully grasp)...? Also it could be that asterisk maybe does not really use that function at all, as said, haven't figured it all out yet. ;-)

- As the issue seemed somewhat hardware-dependent: I tested several BT-sticks with different chipsets. CSR and ISSC -chipsets worked as described (ISSC being somewhat unstable), an Anycom-200 (Broadcom-chipset-based) had no audio at all no matter what. I was only able to test SonyEricsson phones (K600i, W850i, T610), all having the issue described here; will try to get hands on some other brands.

- I used echo testing and forwarding the call via misdn, both having the same issue (no audio can be heard on the called side when calling the mobile and forwarding the audio to asterisk via chan_mobile)

- As mentioned I used an earlier semi-officially backport-patch from the web, based on trunk revision 451, then switched to 600 which I backported myself (basically removing the new cli-stuff and changing some log messages and name changes), but keeping most of the other fixes since 451) . The 451-version had the same problem.

Hope this helps...


By: horbra (horbra) 2008-06-27 05:35:59

Update on my previous note:
- I also now tested Bluez-Libs/Utils 3.34 and manually applied a patch for an issue with (e)sco connections on the bluetooth -kernel module on the MIPS-based architecture. No effect.


By: Matthew Nicholson (mnicholson) 2009-02-18 18:15:23.000-0600

This error appears to be caused because of the way chan_mobile handles audio data.  Currently chan_mobile only reads audio from the phone when it writes audio to the phone.  I am working on a fix.
By: Matthew Nicholson (mnicholson) 2009-02-19 17:09:15.000-0600

I just uploaded the audio1.diff patch.  Please test this patch and see if it resolves your issue.
By: Matthew Nicholson (mnicholson) 2009-02-25 17:37:58.000-0600

Please test the patch associated with this issue to see if it resolves your problem.
By: horbra (horbra) 2009-03-02 04:46:31.000-0600

I patched the revision 600 of chan_mobile.c with the audio1.diff and tried it under the MIPS-based system I described earlier. After some additional manual patches (basically backporting to 1.4-asterisk), I was able to compile and run that version, yet the behavior is unchanged, only one-way audio available.
By: Matthew Nicholson (mnicholson) 2009-03-02 10:48:08.000-0600

Please test with the trunk version of asterisk addons and the trunk version of asterisk.
By: Matthew Nicholson (mnicholson) 2009-04-21 13:29:48

This should be fixed in addons trunk.