Bug 11514 - bluetooth headset works with 2.6.26, only hisses with 2.6.27-rc5
Summary: bluetooth headset works with 2.6.26, only hisses with 2.6.27-rc5
Status: RESOLVED OBSOLETE
Alias: None
Product: Drivers
Classification: Unclassified
Component: Bluetooth (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: drivers_bluetooth@kernel-bugs.osdl.org
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2008-09-07 03:33 UTC by Stuart Pook
Modified: 2012-07-02 13:46 UTC (History)
5 users (show)

See Also:
Kernel Version: 2.6.27-rc8
Subsystem:
Regression: Yes
Bisected commit-id:

Attachments
output from hcidump during aplay on 2.6.27-rc5 (10.73 KB, text/plain)
2008-09-07 03:48 UTC, Stuart Pook 		Details
messages from bluetoothd on 2.6.27-rc5 during aplay (11.89 KB, text/plain)
2008-09-07 03:59 UTC, Stuart Pook 		Details
hcidump during aplay on 2.6.26-1-686 (24.00 KB, text/plain)
2008-09-07 04:08 UTC, Stuart Pook 		Details
messages from bluetoothd during aplay on 2.6.26 (12.00 KB, text/x-log)
2008-09-07 04:22 UTC, Stuart Pook 		Details
output from hcidump -X -V during aplay on 2.6.27-rc5 (719.16 KB, application/octet-stream)
2008-09-22 12:57 UTC, Stuart Pook 		Details
hcidump -XV during aplay on 2.6.26 (Debian) (609.69 KB, text/plain)
2008-09-29 13:38 UTC, Stuart Pook 		Details
Show Obsolete (2) Add an attachment (proposed patch, testcase, etc.)

Description Stuart Pook 2008-09-07 03:33:22 UTC 
Latest working kernel version: 2.6.26-1-686 (Debian)
Earliest failing kernel version: 2.6.27-rc5 (vanilla)
Distribution: Debian
Hardware Environment: Intel Core2 Duo CPU E6550
Software Environment: Debian unstable + bluez-4.4
Problem Description: my Jabra JX10 bluetooth works with 2.6.26-1-686 and bluez-4.4. With 2.6.27-rc5 (btusb) it only hisses.

Steps to reproduce: install bluez-4.4 http://www.bluez.org/ and
add the following to ~/.asoundrc
pcm.JX10 {
	type bluetooth
	device "00:1A:45:2F:49:98" # Jabra JX10 series 2
}
as root run bluetoothd -dn
run aplay -D JX10 alarm.wav

with 2.6.26-1-686 I could hear the music, now I just hear a soft hiss during 40 seconds and then get an error message.

hcitool shows 2 connections during the 40 seconds:
:; hcitool con
Connections:
	< SCO 00:1A:45:2F:49:98 handle 44 state 1 lm SLAVE 
	< ACL 00:1A:45:2F:49:98 handle 41 state 1 lm MASTER 

In /var/log/kern.log

Sep  7 12:16:08 kooka kernel: [ 1250.901715] Bluetooth: SCO (Voice Link) ver 0.6
Sep  7 12:16:08 kooka kernel: [ 1250.901719] Bluetooth: SCO socket layer initialized

in /var/log/kern.log I sometimes see 
hci_scodata_packet: hci0 SCO packet for unknown connection handle 44
btusb_isoc_complete: hci0 corrupted SCO packet

:; aplay -vvv -D JX10 lib/alarm.wav 
Playing WAVE 'lib/alarm.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
aplay: set_params:979: Unable to install hw params:
ACCESS:  RW_INTERLEAVED
FORMAT:  S16_LE
SUBFORMAT:  STD
SAMPLE_BITS: 16
FRAME_BITS: 16
CHANNELS: 1
RATE: 8000
PERIOD_TIME: 125000
PERIOD_SIZE: 1000
PERIOD_BYTES: 2000
PERIODS: 4
BUFFER_TIME: 500000
BUFFER_SIZE: 4000
BUFFER_BYTES: 8000
TICK_TIME: [0 0]

bluetoothd says

bluetoothd[4944]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[4944]: Received AT+VGS=15
bluetoothd[4944]: connect(): Connection timed out (110)
bluetoothd[4944]: Audio API: sending BT_SETCONFIGURATION_RSP
bluetoothd[4944]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_CONNECTED

:; /usr/local/sbin/hciconfig hci0 version
hci0:	Type: USB
	BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
	HCI Ver: 1.1 (0x1) HCI Rev: 0x20d LMP Ver: 1.1 (0x1) LMP Subver: 0x20d
	Manufacturer: Cambridge Silicon Radio (10)
:; /usr/local/sbin/hciconfig hci0
hci0:	Type: USB
	BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
	UP RUNNING 
	RX bytes:666323 acl:16 sco:13034 events:64 errors:0
	TX bytes:910 acl:19 sco:0 commands:33 errors:0
:; /usr/local/sbin/hciconfig hci0 features
hci0:	Type: USB
	BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
	Features: 0xff 0xff 0x0f 0x00 0x00 0x00 0x00 0x00
		<3-slot packets> <5-slot packets> <encryption> <slot offset> 
		<timing accuracy> <role switch> <hold mode> <sniff mode> 
		<park state> <RSSI> <channel quality> <SCO link> <HV2 packets> 
		<HV3 packets> <u-law log> <A-law log> <CVSD> <paging scheme> 
		<power control> <transparent SCO> 
:; lsusb | grep Blue
Bus 001 Device 003: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
:; hcitool info  $JX10
Requesting information ...
	BD Address:  00:1A:45:2F:49:98
	Device Name: Jabra JX10 series 2
	LMP Version: 2.0 (0x3) LMP Subversion: 0x106e
	Manufacturer: Cambridge Silicon Radio (10)
	Features: 0xbf 0xfe 0x8b 0xf8 0x1b 0x18 0x00 0x80
		<3-slot packets> <5-slot packets> <encryption> <slot offset> 
		<timing accuracy> <role switch> <sniff mode> <RSSI> 
		<channel quality> <SCO link> <HV2 packets> <HV3 packets> 
		<u-law log> <A-law log> <CVSD> <paging scheme> 
		<transparent SCO> <broadcast encrypt> <enhanced iscan> 
		<interlaced iscan> <interlaced pscan> <inquiry with RSSI> 
		<extended SCO> <EV4 packets> <EV5 packets> <AFH cap. slave> 
		<AFH class. slave> <AFH cap. master> <AFH class. master> 
		<extended features> 
:; sdptool records  00:1A:45:2F:49:98
Service Name: Hands-Free unit
Service RecHandle: 0x10000
Service Class ID List:
  "Handsfree" (0x111e)
  "Generic Audio" (0x1203)
Protocol Descriptor List:
  "L2CAP" (0x0100)
  "RFCOMM" (0x0003)
    Channel: 1
Language Base Attr List:
  code_ISO639: 0x656e
  encoding:    0x6a
  base_offset: 0x100
Profile Descriptor List:
  "Handsfree" (0x111e)
    Version: 0x0105

Service Name: Headset
Service RecHandle: 0x10001
Service Class ID List:
  "Headset" (0x1108)
  "Generic Audio" (0x1203)
Protocol Descriptor List:
  "L2CAP" (0x0100)
  "RFCOMM" (0x0003)
    Channel: 2
Language Base Attr List:
  code_ISO639: 0x656e
  encoding:    0x6a
  base_offset: 0x100
Profile Descriptor List:
  "Headset" (0x1108)
    Version: 0x0100

:; lsmod | grep usb
usb_storage            77960  1 
snd_usb_audio          72288  0 
snd_usb_lib            15168  1 snd_usb_audio
snd_rawmidi            20512  2 snd_usb_lib,snd_seq_midi
snd_hwdep               8004  1 snd_usb_audio
usbhid                 37924  0 
hid                    35660  1 usbhid
ff_memless              6216  1 usbhid
btusb                  11864  3 
bluetooth              49184  9 sco,bnep,rfcomm,l2cap,btusb
snd_pcm                64708  2 snd_usb_audio,snd_hda_intel
snd                    47480  10 snd_usb_audio,snd_seq_oss,snd_seq,snd_rawmidi,snd_seq_device,snd_hwdep,snd_hda_intel,snd_mixer_oss,snd_pcm,snd_timer

:; lsmod | grep hcd
uhci_hcd               20816  0 

Note that I have removed ehci_hcd because it seems to cause problems with 2.6.27-rc5. More on that later :-(
Comment 1 Stuart Pook 2008-09-07 03:48:21 UTC 
Created attachment 17649 [details]
output from hcidump during aplay on 2.6.27-rc5

I captured the output of "hcidump | uniq -c" while running "bluetoothd -dn" and "aplay -D JX10 alarm.wav". While aplay was running I also pressed on the volume up and down buttons on my headset. After 40 seconds bluetoothd said "connect(): Connection timed out (110)" and aplay said "Unable to install hw params".
Comment 2 Stuart Pook 2008-09-07 03:59:37 UTC 
Created attachment 17650 [details]
messages from bluetoothd on 2.6.27-rc5 during aplay

This is what bluetoothd (bluez-4.4) wrote to /var/log/daemon.log when I ran "aplay -D JX10 alarm.wav". I logged the aplay command as well. Note the 40 seconds between the connection and the "Connection timed out". Duing these 40 seconds (see the previous attachment) lots of packets were received from the headset.
Comment 3 Anonymous Emailer 2008-09-07 04:01:37 UTC 
Reply-To: akpm@linux-foundation.org


(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

On Sun,  7 Sep 2008 03:33:23 -0700 (PDT) bugme-daemon@bugzilla.kernel.org wrote:

> http://bugzilla.kernel.org/show_bug.cgi?id=11514
> 
>            Summary: bluetooth headset works with 2.6.26, only hisses with
>                     2.6.27-rc5
>            Product: Drivers
>            Version: 2.5
>      KernelVersion: 2.6.27-rc5
>           Platform: All
>         OS/Version: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: Bluetooth
>         AssignedTo: drivers_bluetooth@kernel-bugs.osdl.org
>         ReportedBy: kernel6org@pook.es
> 
> 
> Latest working kernel version: 2.6.26-1-686 (Debian)
> Earliest failing kernel version: 2.6.27-rc5 (vanilla)

A post-2.6.26 regression.

> Distribution: Debian
> Hardware Environment: Intel Core2 Duo CPU E6550
> Software Environment: Debian unstable + bluez-4.4
> Problem Description: my Jabra JX10 bluetooth works with 2.6.26-1-686 and
> bluez-4.4. With 2.6.27-rc5 (btusb) it only hisses.
> 
> Steps to reproduce: install bluez-4.4 http://www.bluez.org/ and
> add the following to ~/.asoundrc
> pcm.JX10 {
>         type bluetooth
>         device "00:1A:45:2F:49:98" # Jabra JX10 series 2
> }
> as root run bluetoothd -dn
> run aplay -D JX10 alarm.wav
> 
> with 2.6.26-1-686 I could hear the music, now I just hear a soft hiss during
> 40
> seconds and then get an error message.
> 
> hcitool shows 2 connections during the 40 seconds:
> :; hcitool con
> Connections:
>         < SCO 00:1A:45:2F:49:98 handle 44 state 1 lm SLAVE 
>         < ACL 00:1A:45:2F:49:98 handle 41 state 1 lm MASTER 
> 
> In /var/log/kern.log
> 
> Sep  7 12:16:08 kooka kernel: [ 1250.901715] Bluetooth: SCO (Voice Link) ver
> 0.6
> Sep  7 12:16:08 kooka kernel: [ 1250.901719] Bluetooth: SCO socket layer
> initialized
> 
> in /var/log/kern.log I sometimes see 
> hci_scodata_packet: hci0 SCO packet for unknown connection handle 44
> btusb_isoc_complete: hci0 corrupted SCO packet
> 
> :; aplay -vvv -D JX10 lib/alarm.wav 
> Playing WAVE 'lib/alarm.wav' : Signed 16 bit Little Endian, Rate 8000 Hz,
> Mono
> aplay: set_params:979: Unable to install hw params:
> ACCESS:  RW_INTERLEAVED
> FORMAT:  S16_LE
> SUBFORMAT:  STD
> SAMPLE_BITS: 16
> FRAME_BITS: 16
> CHANNELS: 1
> RATE: 8000
> PERIOD_TIME: 125000
> PERIOD_SIZE: 1000
> PERIOD_BYTES: 2000
> PERIODS: 4
> BUFFER_TIME: 500000
> BUFFER_SIZE: 4000
> BUFFER_BYTES: 8000
> TICK_TIME: [0 0]
> 
> bluetoothd says
> 
> bluetoothd[4944]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98:
> HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
> bluetoothd[4944]: Received AT+VGS=15
> bluetoothd[4944]: connect(): Connection timed out (110)
> bluetoothd[4944]: Audio API: sending BT_SETCONFIGURATION_RSP
> bluetoothd[4944]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98:
> HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_CONNECTED
> 
> :; /usr/local/sbin/hciconfig hci0 version
> hci0:   Type: USB
>         BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
>         HCI Ver: 1.1 (0x1) HCI Rev: 0x20d LMP Ver: 1.1 (0x1) LMP Subver:
>         0x20d
>         Manufacturer: Cambridge Silicon Radio (10)
> :; /usr/local/sbin/hciconfig hci0
> hci0:   Type: USB
>         BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
>         UP RUNNING 
>         RX bytes:666323 acl:16 sco:13034 events:64 errors:0
>         TX bytes:910 acl:19 sco:0 commands:33 errors:0
> :; /usr/local/sbin/hciconfig hci0 features
> hci0:   Type: USB
>         BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
>         Features: 0xff 0xff 0x0f 0x00 0x00 0x00 0x00 0x00
>                 <3-slot packets> <5-slot packets> <encryption> <slot offset> 
>                 <timing accuracy> <role switch> <hold mode> <sniff mode> 
>                 <park state> <RSSI> <channel quality> <SCO link> <HV2
>                 packets> 
>                 <HV3 packets> <u-law log> <A-law log> <CVSD> <paging scheme> 
>                 <power control> <transparent SCO> 
> :; lsusb | grep Blue
> Bus 001 Device 003: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth
> Dongle
> (HCI mode)
> :; hcitool info  $JX10
> Requesting information ...
>         BD Address:  00:1A:45:2F:49:98
>         Device Name: Jabra JX10 series 2
>         LMP Version: 2.0 (0x3) LMP Subversion: 0x106e
>         Manufacturer: Cambridge Silicon Radio (10)
>         Features: 0xbf 0xfe 0x8b 0xf8 0x1b 0x18 0x00 0x80
>                 <3-slot packets> <5-slot packets> <encryption> <slot offset> 
>                 <timing accuracy> <role switch> <sniff mode> <RSSI> 
>                 <channel quality> <SCO link> <HV2 packets> <HV3 packets> 
>                 <u-law log> <A-law log> <CVSD> <paging scheme> 
>                 <transparent SCO> <broadcast encrypt> <enhanced iscan> 
>                 <interlaced iscan> <interlaced pscan> <inquiry with RSSI> 
>                 <extended SCO> <EV4 packets> <EV5 packets> <AFH cap. slave> 
>                 <AFH class. slave> <AFH cap. master> <AFH class. master> 
>                 <extended features> 
> :; sdptool records  00:1A:45:2F:49:98
> Service Name: Hands-Free unit
> Service RecHandle: 0x10000
> Service Class ID List:
>   "Handsfree" (0x111e)
>   "Generic Audio" (0x1203)
> Protocol Descriptor List:
>   "L2CAP" (0x0100)
>   "RFCOMM" (0x0003)
>     Channel: 1
> Language Base Attr List:
>   code_ISO639: 0x656e
>   encoding:    0x6a
>   base_offset: 0x100
> Profile Descriptor List:
>   "Handsfree" (0x111e)
>     Version: 0x0105
> 
> Service Name: Headset
> Service RecHandle: 0x10001
> Service Class ID List:
>   "Headset" (0x1108)
>   "Generic Audio" (0x1203)
> Protocol Descriptor List:
>   "L2CAP" (0x0100)
>   "RFCOMM" (0x0003)
>     Channel: 2
> Language Base Attr List:
>   code_ISO639: 0x656e
>   encoding:    0x6a
>   base_offset: 0x100
> Profile Descriptor List:
>   "Headset" (0x1108)
>     Version: 0x0100
> 
> :; lsmod | grep usb
> usb_storage            77960  1 
> snd_usb_audio          72288  0 
> snd_usb_lib            15168  1 snd_usb_audio
> snd_rawmidi            20512  2 snd_usb_lib,snd_seq_midi
> snd_hwdep               8004  1 snd_usb_audio
> usbhid                 37924  0 
> hid                    35660  1 usbhid
> ff_memless              6216  1 usbhid
> btusb                  11864  3 
> bluetooth              49184  9 sco,bnep,rfcomm,l2cap,btusb
> snd_pcm                64708  2 snd_usb_audio,snd_hda_intel
> snd                    47480  10
>
> snd_usb_audio,snd_seq_oss,snd_seq,snd_rawmidi,snd_seq_device,snd_hwdep,snd_hda_intel,snd_mixer_oss,snd_pcm,snd_timer
> 
> :; lsmod | grep hcd
> uhci_hcd               20816  0 
> 
> Note that I have removed ehci_hcd because it seems to cause problems with
> 2.6.27-rc5. More on that later :-(
>
Comment 4 Stuart Pook 2008-09-07 04:08:25 UTC 
Created attachment 17651 [details]
hcidump during aplay on 2.6.26-1-686

So that you can compare 2.6.26 and 2.6.27-rc5, this is what hcidump saw during an aplay on my 2.6.26-1-686 kernel. There were lots of SCO data packets in each direction and I heard the music! I was using bluez-4.4 here as well.
Comment 5 Stuart Pook 2008-09-07 04:22:59 UTC 
Created attachment 17652 [details]
messages from bluetoothd during aplay on 2.6.26

This is what bluetoothd said when playing on 2.6.26. On 2.6.26 the headset works (but not all the time) and I can hear the music.
Comment 6 Stuart Pook 2008-09-13 09:32:45 UTC 
On 07/09/08 13:01, Andrew Morton wrote:

> A post-2.6.26 regression.

yes. I read the change log for 2.6.27-rc6 and it doesn't seem to address my
problem. Should I try it anyway?

I forgot to mention that my bluetooth dongle is a USB

ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)

# hciconfig  -a
hci0:	Type: USB
BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
UP RUNNING
RX bytes:3713306 acl:72248 sco:0 events:299153 errors:0
TX bytes:2985713 acl:109155 sco:0 commands:157763 errors:0
Features: 0xff 0xff 0x0f 0x00 0x00 0x00 0x00 0x00
Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3
Link policy: RSWITCH HOLD SNIFF PARK
Link mode: SLAVE ACCEPT
Name: 'kooka-0'
Class: 0x0a0000
Service Classes: Networking, Capturing
Device Class: Miscellaneous,
HCI Ver: 1.1 (0x1) HCI Rev: 0x20d LMP Ver: 1.1 (0x1) LMP Subver: 0x20d
Manufacturer: Cambridge Silicon Radio (10)


If I can help in finding a solution to this problem please let me know!

Stuart
Comment 7 Stuart Pook 2008-09-22 12:57:34 UTC 
Created attachment 17958 [details]
output from hcidump -X -V during aplay on 2.6.27-rc5

This is the output from hcidump -X -V when I ran aplay under 2.6.27-rc5. (I had to remove some of the outpot from the middle of the file to make it fit under the 1000KB limit). I didn't hear any sound and got the error message:

:; logcommand aplay -D JX10 alarm.wav
Playing WAVE 'alarm.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
aplay: set_params:979: Unable to install hw params:
ACCESS:  RW_INTERLEAVED
FORMAT:  S16_LE
SUBFORMAT:  STD
SAMPLE_BITS: 16
FRAME_BITS: 16
CHANNELS: 1
RATE: 8000
PERIOD_TIME: 125000
PERIOD_SIZE: 1000
PERIOD_BYTES: 2000
PERIODS: 4
BUFFER_TIME: 500000
BUFFER_SIZE: 4000
BUFFER_BYTES: 8000
TICK_TIME: [0 0]


My ~/.asoundrc now contains
pcm.JX10 {
	type bluetooth
	device "00:1A:45:2F:49:98" # Jabra JX10 series 2
}
ctl.JX10 {
   type bluetooth
}

The dumo starts with:

HCI sniffer - Bluetooth packet analyzer ver 1.42
device: hci0 snap_len: 1028 filter: 0xffffffff
< HCI Command: Create Connection (0x01|0x0005) plen 13
    bdaddr 00:1A:45:2F:49:98 ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
    Packet type: DM1 DM3 DM5 DH1 DH3 DH5 
> HCI Event: Command Status (0x0f) plen 4
    Create Connection (0x01|0x0005) status 0x00 ncmd 1
> HCI Event: Connect Complete (0x03) plen 11
    status 0x00 handle 41 bdaddr 00:1A:45:2F:49:98 type ACL encrypt 0x00
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
    handle 41
> HCI Event: Command Status (0x0f) plen 4
    Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 0
> HCI Event: Page Scan Repetition Mode Change (0x20) plen 7
    bdaddr 00:1A:45:2F:49:98 mode 1
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 41 slots 5
> HCI Event: Command Status (0x0f) plen 4
    Unknown (0x00|0x0000) status 0x00 ncmd 1
< HCI Command: Remote Name Request (0x01|0x0019) plen 10
    bdaddr 00:1A:45:2F:49:98 mode 2 clkoffset 0x0000
> HCI Event: Command Status (0x0f) plen 4
    Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
> HCI Event: Read Remote Supported Features (0x0b) plen 11
    status 0x00 handle 41
    Features: 0xbf 0xfe 0x8b 0xf8 0x1b 0x18 0x00 0x80
< ACL data: handle 41 flags 0x02 dlen 10
    L2CAP(s): Info req: type 2
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 16
    L2CAP(s): Info rsp: type 2 result 0
      Extended feature mask 0x0000
< ACL data: handle 41 flags 0x02 dlen 12
    L2CAP(s): Connect req: psm 3 scid 0x0040
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0046 scid 0x0040 result 1 status 2
      Connection pending - Authorization pending
> HCI Event: Remote Name Req Complete (0x07) plen 255
    status 0x00 bdaddr 00:1A:45:2F:49:98 name 'Jabra JX10 series 2'
> HCI Event: Link Key Request (0x17) plen 6
    bdaddr 00:1A:45:2F:49:98
< HCI Command: Link Key Request Reply (0x01|0x000b) plen 22
    bdaddr 00:1A:45:2F:49:98 key F63331CE2D0DBCA190DC73C930CD6117
> HCI Event: Command Complete (0x0e) plen 10
    Link Key Request Reply (0x01|0x000b) ncmd 1
    status 0x00 bdaddr 00:1A:45:2F:49:98
> ACL data: handle 41 flags 0x02 dlen 16
    L2CAP(s): Connect rsp: dcid 0x0046 scid 0x0040 result 0 status 0
      Connection successful
< ACL data: handle 41 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0046 flags 0x00 clen 4
      MTU 1013 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 14
    L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
      Success
> ACL data: handle 41 flags 0x02 dlen 16
    L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
      MTU 1013 
< ACL data: handle 41 flags 0x02 dlen 18
    L2CAP(s): Config rsp: scid 0x0046 flags 0x00 result 0 clen 4
      MTU 1013 
< ACL data: handle 41 flags 0x02 dlen 8
    L2CAP(d): cid 0x0046 len 4 [psm 3]
      RFCOMM(s): SABM: cr 1 dlci 0 pf 1 ilen 0 fcs 0x1c 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 8
    L2CAP(d): cid 0x0040 len 4 [psm 3]
      RFCOMM(s): UA: cr 1 dlci 0 pf 1 ilen 0 fcs 0xd7 
< ACL data: handle 41 flags 0x02 dlen 18
    L2CAP(d): cid 0x0046 len 14 [psm 3]
      RFCOMM(s): PN CMD: cr 1 dlci 0 pf 0 ilen 10 fcs 0x70 mcc_len 8
      dlci 2 frame_type 0 credit_flow 15 pri 7 ack_timer 0
      frame_size 1008 max_retrans 0 credits 7
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 18
    L2CAP(d): cid 0x0040 len 14 [psm 3]
      RFCOMM(s): PN RSP: cr 0 dlci 0 pf 0 ilen 10 fcs 0xaa mcc_len 8
      dlci 2 frame_type 0 credit_flow 14 pri 7 ack_timer 0
      frame_size 127 max_retrans 0 credits 0
< ACL data: handle 41 flags 0x02 dlen 8
    L2CAP(d): cid 0x0046 len 4 [psm 3]
      RFCOMM(s): SABM: cr 1 dlci 2 pf 1 ilen 0 fcs 0x59 
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 8
    L2CAP(d): cid 0x0040 len 4 [psm 3]
      RFCOMM(s): UA: cr 1 dlci 2 pf 1 ilen 0 fcs 0x92 
< ACL data: handle 41 flags 0x02 dlen 12
    L2CAP(d): cid 0x0046 len 8 [psm 3]
      RFCOMM(s): MSC CMD: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
      dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 0 b2 0 b3 0 len 0
> ACL data: handle 41 flags 0x02 dlen 12
    L2CAP(d): cid 0x0040 len 8 [psm 3]
      RFCOMM(s): MSC CMD: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
      dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 0 b1 0 b2 0 b3 0 len 0
< ACL data: handle 41 flags 0x02 dlen 12
    L2CAP(d): cid 0x0046 len 8 [psm 3]
      RFCOMM(s): MSC RSP: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
      dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 0 b1 0 b2 0 b3 0 len 0
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 12
    L2CAP(d): cid 0x0040 len 8 [psm 3]
      RFCOMM(s): MSC RSP: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
      dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 0 b2 0 b3 0 len 0
< ACL data: handle 41 flags 0x02 dlen 9
    L2CAP(d): cid 0x0046 len 5 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 1 ilen 0 fcs 0x86 credits 33
> ACL data: handle 41 flags 0x02 dlen 9
    L2CAP(d): cid 0x0040 len 5 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 0 fcs 0x5c credits 15
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 19
    L2CAP(d): cid 0x0040 len 15 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 2 pf 0 ilen 11 fcs 0x40 
      0000: 41 54 2b 42 52 53 46 3d  32 37 0d                 AT+BRSF=27.
< ACL data: handle 41 flags 0x02 dlen 19
    L2CAP(d): cid 0x0046 len 15 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 11 fcs 0x9a 
      0000: 0d 0a 2b 42 52 53 46 3d  30 0d 0a                 ..+BRSF=0..
< ACL data: handle 41 flags 0x02 dlen 14
    L2CAP(d): cid 0x0046 len 10 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 19
    L2CAP(d): cid 0x0040 len 15 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 10 fcs 0x5c credits 2
      0000: 41 54 2b 43 49 4e 44 3d  3f 0d                    AT+CIND=?.
< ACL data: handle 41 flags 0x02 dlen 135
    L2CAP(d): cid 0x0046 len 131 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 127 fcs 0x9a 
      0000: 0d 0a 2b 43 49 4e 44 3a  28 22 62 61 74 74 63 68  ..+CIND:("battch
      0010: 67 22 2c 28 30 2d 35 29  29 2c 28 22 73 69 67 6e  g",(0-5)),("sign
      0020: 61 6c 22 2c 28 30 2d 35  29 29 2c 28 22 73 65 72  al",(0-5)),("ser
      0030: 76 69 63 65 22 2c 28 30  2c 31 29 29 2c 28 22 63  vice",(0,1)),("c
      0040: 61 6c 6c 22 2c 28 30 2c  31 29 29 2c 28 22 63 61  all",(0,1)),("ca
      0050: 6c 6c 73 65 74 75 70 22  2c 28 30 2d 33 29 29 2c  llsetup",(0-3)),
      0060: 28 22 63 61 6c 6c 68 65  6c 64 22 2c 28 30 2d 32  ("callheld",(0-2
      0070: 29 29 2c 28 22 72 6f 61  6d 22 2c 28 30 2c 31     )),("roam",(0,1
< ACL data: handle 41 flags 0x02 dlen 12
    L2CAP(d): cid 0x0046 len 8 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 4 fcs 0x9a 
      0000: 29 29 0d 0a                                       ))..
< ACL data: handle 41 flags 0x02 dlen 14
    L2CAP(d): cid 0x0046 len 10 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 18
    L2CAP(d): cid 0x0040 len 14 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 9 fcs 0x5c credits 3
      0000: 41 54 2b 43 49 4e 44 3f  0d                       AT+CIND?.
< ACL data: handle 41 flags 0x02 dlen 31
    L2CAP(d): cid 0x0046 len 27 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 23 fcs 0x9a 
      0000: 0d 0a 2b 43 49 4e 44 3a  35 2c 35 2c 31 2c 30 2c  ..+CIND:5,5,1,0,
      0010: 30 2c 30 2c 30 0d 0a                              0,0,0..
< ACL data: handle 41 flags 0x02 dlen 14
    L2CAP(d): cid 0x0046 len 10 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> ACL data: handle 41 flags 0x02 dlen 28
    L2CAP(d): cid 0x0040 len 24 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 19 fcs 0x5c credits 2
      0000: 41 54 2b 43 4d 45 52 3d  33 2c 20 30 2c 20 30 2c  AT+CMER=3, 0, 0,
      0010: 20 31 0d                                           1.
< HCI Command: Add SCO Connection (0x01|0x0007) plen 4
    handle 41 ptype 0x00e0
    Packet type: HV1 HV2 HV3 
< ACL data: handle 41 flags 0x02 dlen 14
    L2CAP(d): cid 0x0046 len 10 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Command Status (0x0f) plen 4
    Add SCO Connection (0x01|0x0007) status 0x00 ncmd 1
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 41 slots 1
> ACL data: handle 41 flags 0x02 dlen 17
> ACL data: handle 41 flags 0x01 dlen 2
    L2CAP(d): cid 0x0040 len 15 [psm 3]
      RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 10 fcs 0x5c credits 1
      0000: 41 54 2b 56 47 53 3d 31  30 0d                    AT+VGS=10.
< ACL data: handle 41 flags 0x02 dlen 14
    L2CAP(d): cid 0x0046 len 10 [psm 3]
      RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a 
      0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
> HCI Event: Number of Completed Packets (0x13) plen 5
    handle 41 packets 1
> HCI Event: Connect Complete (0x03) plen 11
    status 0x00 handle 44 bdaddr 00:1A:45:2F:49:98 type SCO encrypt 0x00
> HCI Event: Max Slots Change (0x1b) plen 3
    handle 41 slots 3
> SCO data: handle 44 flags 0x00 dlen 48
    0000: 51 00 51 00 51 00 51 00  51 00 51 00 51 00 51 00  Q.Q.Q.Q.Q.Q.Q.Q.
    0010: 51 00 51 00 51 00 51 00  51 00 51 00 51 00 51 2c  Q.Q.Q.Q.Q.Q.Q.Q,
    0020: 00 30 35 2c 35 2c 35 2c  35 2c 35 2c 35 2c 35 2c  .05,5,5,5,5,5,5,
Comment 8 Stuart Pook 2008-09-22 13:01:47 UTC 
This is what was written into /var/log/daemon.log while I ran aplay.

Sep 22 21:37:42 kooka bluetoothd[32442]: Bluetooth daemon
Sep 22 21:37:42 kooka bluetoothd[32442]: Enabling debug information
Sep 22 21:37:42 kooka bluetoothd[32442]: parsing main.conf
Sep 22 21:37:42 kooka bluetoothd[32442]: offmode=NoScan
Sep 22 21:37:42 kooka bluetoothd[32442]: discovto=0
Sep 22 21:37:42 kooka bluetoothd[32442]: pageto=8192
Sep 22 21:37:42 kooka bluetoothd[32442]: name=%h-%d
Sep 22 21:37:42 kooka bluetoothd[32442]: class=0x000100
Sep 22 21:37:42 kooka bluetoothd[32442]: inqmode=0
Sep 22 21:37:42 kooka bluetoothd[32442]: Starting SDP server
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb892da80
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x1
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb892fa90
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x0
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x00
Sep 22 21:37:42 kooka bluetoothd[32442]: Loading plugins /usr/local/lib/bluetooth/plugins
Sep 22 21:37:42 kooka bluetoothd[32442]: /usr/local/lib/bluetooth/plugins/audio.so
Sep 22 21:37:42 kooka bluetoothd[32442]: Parsing /etc/bluetooth/audio.conf failed: No such file or directory
Sep 22 21:37:42 kooka bluetoothd[32442]: Unix socket created: 11
Sep 22 21:37:42 kooka bluetoothd[32442]: Telephony plugin initialized
Sep 22 21:37:42 kooka bluetoothd[32442]: HFP AG features: (none)
Sep 22 21:37:42 kooka bluetoothd[32442]: /usr/local/lib/bluetooth/plugins/serial.so
Sep 22 21:37:42 kooka bluetoothd[32442]: /usr/local/lib/bluetooth/plugins/service.so
Sep 22 21:37:42 kooka bluetoothd[32442]: /usr/local/lib/bluetooth/plugins/network.so
Sep 22 21:37:42 kooka bluetoothd[32442]: Parsing /etc/bluetooth/network.conf failed: No such file or directory
Sep 22 21:37:42 kooka bluetoothd[32442]: Config options: InterfacePrefix=bnep%d, PANU_Script=(null), GN_Script=(null), NAP_Script=(null), GN_Interface=pan0, NAP_Interface=pan1, Security=true
Sep 22 21:37:42 kooka bluetoothd[32442]: bridge pan0 created
Sep 22 21:37:42 kooka bluetoothd[32442]: /usr/local/lib/bluetooth/plugins/input.so
Sep 22 21:37:42 kooka bluetoothd[32442]: input.conf: Key file does not have key 'IdleTimeout'
Sep 22 21:37:42 kooka bluetoothd[32442]: HCI dev 0 registered
Sep 22 21:37:42 kooka bluetoothd[32442]: HCI dev 0 already up
Sep 22 21:37:42 kooka bluetoothd[32442]: headset_server_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10000
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10000
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb8932460
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10000
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x00
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10001
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10001
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb8930588
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10001
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x00
Sep 22 21:37:42 kooka bluetoothd[32442]: a2dp_server_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: SEP 0xb8930b68 registered: type:0 codec:0 seid:1
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10002
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10002
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb8930870
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10002
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x08
Sep 22 21:37:42 kooka bluetoothd[32442]: avrcp_server_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10003
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10003
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb8930848
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10003
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x08
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10004
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10004
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb89325b0
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10004
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x08
Sep 22 21:37:42 kooka bluetoothd[32442]: proxy_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.SerialProxyManager on path /org/bluez/hci0
Sep 22 21:37:42 kooka bluetoothd[32442]: service_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.Service on path /org/bluez/hci0
Sep 22 21:37:42 kooka bluetoothd[32442]: network_server_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10005
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10005
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb89335b0
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10005
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x0a
Sep 22 21:37:42 kooka bluetoothd[32442]: register_server_record: got record id 0x10005
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.NetworkPeer on path /org/bluez/hci0
Sep 22 21:37:42 kooka bluetoothd[32442]: network_server_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10006
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10006
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb8933bd8
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10006
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x0a
Sep 22 21:37:42 kooka bluetoothd[32442]: register_server_record: got record id 0x10006
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.NetworkHub on path /org/bluez/hci0
Sep 22 21:37:42 kooka bluetoothd[32442]: network_server_probe: path /org/bluez/hci0 
Sep 22 21:37:42 kooka bluetoothd[32442]: Couldn't find record for : 0x10007
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding record with handle 0x10007
Sep 22 21:37:42 kooka bluetoothd[32442]: Adding rec : 0xb8934200
Sep 22 21:37:42 kooka bluetoothd[32442]: with handle : 0x10007
Sep 22 21:37:42 kooka bluetoothd[32442]: Service classes 0x0a
Sep 22 21:37:42 kooka bluetoothd[32442]: register_server_record: got record id 0x10007
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.NetworkRouter on path /org/bluez/hci0
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_1A_45_2F_49_98
Sep 22 21:37:42 kooka bluetoothd[32442]: Probe drivers for /org/bluez/hci0/dev_00_1A_45_2F_49_98
Sep 22 21:37:42 kooka bluetoothd[32442]: Found Headset record
Sep 22 21:37:42 kooka bluetoothd[32442]: Discovered Headset service on RFCOMM channel 2
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.Headset on path /org/bluez/hci0/dev_00_1A_45_2F_49_98
Sep 22 21:37:42 kooka bluetoothd[32442]: Found Hansfree record
Sep 22 21:37:42 kooka bluetoothd[32442]: Discovered Handsfree service on RFCOMM channel 1
Sep 22 21:37:42 kooka bluetoothd[32442]: headset_probe: path /org/bluez/hci0/dev_00_1A_45_2F_49_98 
Sep 22 21:37:42 kooka bluetoothd[32442]: Registered interface org.bluez.Input on path /org/bluez/hci0/dev_00_1A_45_2F_49_98
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_14_A7_74_D3_AF
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_03_89_B7_F8_D3
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_0A_94_94_4F_B3
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_03_89_DC_5C_9F
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_03_89_DC_FC_EC
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_03_89_FE_E6_19
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_0E_6D_8F_91_6A
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_17_E5_E6_25_AB
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_17_E5_16_88_6C
Sep 22 21:37:42 kooka bluetoothd[32442]: Creating device /org/bluez/hci0/dev_00_17_E5_0C_EA_70
Sep 22 21:37:42 kooka bluetoothd[32442]: Adapter /org/bluez/hci0 has been enabled
Sep 22 21:37:42 kooka bluetoothd[32442]: Starting security manager 0
Sep 22 21:37:42 kooka bluetoothd[32442]: child 32445 exited
Sep 22 21:37:42 kooka bluetoothd[32442]: child 32446 exited
Sep 22 21:39:27 kooka hcidump: hcidump -X -V
Sep 22 21:39:37 kooka aplay: aplay -D JX10 alarm.wav
Sep 22 21:39:37 kooka bluetoothd[32442]: Accepted new client connection on unix socket (fd=21)
Sep 22 21:39:37 kooka bluetoothd[32442]: Audio API: received BT_GETCAPABILITIES_REQ
Sep 22 21:39:37 kooka bluetoothd[32442]: Audio API: sending BT_GETCAPABILITIES_RSP
Sep 22 21:39:37 kooka bluetoothd[32442]: Audio API: received BT_SETCONFIGURATION_REQ
Sep 22 21:39:37 kooka bluetoothd[32442]: config sco - device = 00:1A:45:2F:49:98 access_mode = 2
Sep 22 21:39:37 kooka bluetoothd[32442]: /org/bluez/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
Sep 22 21:39:37 kooka bluetoothd[32442]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
Sep 22 21:39:41 kooka bluetoothd[32442]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
Sep 22 21:39:41 kooka bluetoothd[32442]: kernel auth requirements = 0x00
Sep 22 21:39:41 kooka bluetoothd[32442]: stored link key type = 0x00
Sep 22 21:39:42 kooka bluetoothd[32442]: /org/bluez/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
Sep 22 21:39:42 kooka bluetoothd[32442]: Received AT+BRSF=27
Sep 22 21:39:42 kooka bluetoothd[32442]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control" 
Sep 22 21:39:42 kooka bluetoothd[32442]: Received AT+CIND=?
Sep 22 21:39:43 kooka bluetoothd[32442]: Received AT+CIND?
Sep 22 21:39:43 kooka bluetoothd[32442]: Received AT+CMER=3, 0, 0, 1
Sep 22 21:39:43 kooka bluetoothd[32442]: Event reporting (CMER): mode=3, ind=1
Sep 22 21:39:43 kooka bluetoothd[32442]: HFP Service Level Connection established
Sep 22 21:39:43 kooka bluetoothd[32442]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
Sep 22 21:39:43 kooka bluetoothd[32442]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
Sep 22 21:39:44 kooka bluetoothd[32442]: Received AT+VGS=10
Sep 22 21:40:19 kooka bluetoothd[32442]: Received AT+VGS=12
Sep 22 21:40:23 kooka bluetoothd[32442]: Received AT+VGS=14
Sep 22 21:40:23 kooka bluetoothd[32442]: connect(): Connection timed out (110)
Sep 22 21:40:23 kooka bluetoothd[32442]: Audio API: sending BT_SETCONFIGURATION_RSP
Sep 22 21:40:23 kooka bluetoothd[32442]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_CONNECTED
Sep 22 21:40:23 kooka bluetoothd[32442]: Audio API: received BT_STREAMSTART_REQ
Sep 22 21:40:23 kooka bluetoothd[32442]: Audio API: sending BT_STREAMSTART_RSP
Sep 22 21:40:23 kooka bluetoothd[32442]: Audio API: sending BT_STREAMFD_IND
Sep 22 21:40:23 kooka bluetoothd[32442]: unix_sendmsg_fd: Bad file descriptor(9)
Sep 22 21:40:23 kooka bluetoothd[32442]: resume failed
Sep 22 21:40:23 kooka bluetoothd[32442]: Audio API: sending BT_STREAMSTART_RSP
Sep 22 21:40:23 kooka bluetoothd[32442]: Unix client disconnected (fd=21)
Sep 22 21:40:23 kooka bluetoothd[32442]: No matching connection for handle 44
Comment 9 Stuart Pook 2008-09-22 13:05:05 UTC 
Running a aplay a second time gives a slightly different message from bluetoothd

bluetoothd[32442]: Accepted new client connection on unix socket (fd=21)
bluetoothd[32442]: Audio API: received BT_GETCAPABILITIES_REQ
bluetoothd[32442]: Audio API: sending BT_GETCAPABILITIES_RSP
bluetoothd[32442]: Audio API: received BT_SETCONFIGURATION_REQ
bluetoothd[32442]: config sco - device = 00:1A:45:2F:49:98 access_mode = 2
bluetoothd[32442]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
bluetoothd[32442]: connect(): Connection timed out (110)
bluetoothd[32442]: Unable to lock headset
bluetoothd[32442]: config failed
bluetoothd[32442]: Audio API: sending BT_SETCONFIGURATION_RSP
bluetoothd[32442]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[32442]: Unix client disconnected (fd=21)
bluetoothd[32442]: No matching connection for handle 44
Comment 10 Stuart Pook 2008-09-29 13:38:15 UTC 
Created attachment 18107 [details]
hcidump -XV during aplay on 2.6.26 (Debian)

aplay works using bluez-4.4 on 2.6.26-1-686 from Debian. This attachement is what hcidump saw while using aplay to play my .wav file.

Aplay doesn't work with bluez-4.7 on 2.6.26-1-686 from Debian. Bluetoothd from 4.7 says:

bluetoothd[12297]: Accepted new client connection on unix socket (fd=23)
bluetoothd[12297]: Audio API: received BT_GETCAPABILITIES_REQ
bluetoothd[12297]: Audio API: sending BT_GETCAPABILITIES_RSP
bluetoothd[12297]: Audio API: received BT_SETCONFIGURATION_REQ
bluetoothd[12297]: config sco - device = 00:1A:45:2F:49:98 access_mode = 2
bluetoothd[12297]: /org/bluez/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd[12297]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd[12297]: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd[12297]: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd[12297]: kernel auth requirements = 0x00
bluetoothd[12297]: stored link key type = 0x00
bluetoothd[12297]: /org/bluez/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd[12297]: Received AT+BRSF=27
bluetoothd[12297]: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control" 
bluetoothd[12297]: Received AT+CIND=?
bluetoothd[12297]: Received AT+CIND?
bluetoothd[12297]: Received AT+CMER=3, 0, 0, 1
bluetoothd[12297]: Event reporting (CMER): mode=3, ind=1
bluetoothd[12297]: HFP Service Level Connection established
bluetoothd[12297]: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd[12297]: connect: Operation not permitted (1)
bluetoothd[12297]: config failed
bluetoothd[12297]: Audio API: sending BT_SETCONFIGURATION_RSP
bluetoothd[12297]: Unix client disconnected (fd=23)
bluetoothd[12297]: Received AT+VGS=00

aplay says
ALSA lib pcm_bluetooth.c:464:(bluetooth_hsp_hw_params) BT_SETCONFIGURATION failed : Input/output error(5)
aplay: set_params:979: Unable to install hw params:
ACCESS:  RW_INTERLEAVED
FORMAT:  S16_LE
SUBFORMAT:  STD
SAMPLE_BITS: 16
FRAME_BITS: 16
CHANNELS: 1
RATE: 8000
PERIOD_TIME: 125000
PERIOD_SIZE: 1000
PERIOD_BYTES: 2000
PERIODS: 4
BUFFER_TIME: 500000
BUFFER_SIZE: 4000
BUFFER_BYTES: 8000
TICK_TIME: [0 0]
Comment 11 Stuart Pook 2008-09-30 14:57:32 UTC 
On 07/09/08 13:01, Andrew Morton wrote:
>> Latest working kernel version: 2.6.26-1-686 (Debian)
>> Earliest failing kernel version: 2.6.27-rc5 (vanilla)
> A post-2.6.26 regression.

I just installed bluez-4.9 and linux 2.6.27-rc8 hoping that my
Jabra JX10 bluetooth headset would start working. Still no luck.
Bluetoothd says "connect: Operation not permitted (1)" and
aplay "BT_SETCONFIGURATION failed".

I also downloaded the 2.6.26-mh6 patches from
http://www.bluez.org/more-usb-driver-fixes-and-quirks/ and recompiled
another kernel. The kernel crashed twice (I only booted it twice)
rather quickly. I did get time to run aplay once and it gave the same
errors as shown here. The hcidump is almost exactly the same.

The Jabra JX10 "features Bluetooth 2.0 and e-SCO for improved
audio quality and MultiPoint capability for connecting to 2 devices
at once" and I am using an old Bluetooth 1.2 Linksys USBBT100
USB dongle. Could that be what is causing the problem?

I ran strace on bluetoothd and it appears that it is
"bind(25, {sa_family=AF_BLUETOOTH, sa_data="0\377\341A\f\0\310\261\v\270H\225d\271"...}, 8)"
that is returning -1 with errno set to EADDRINUSE

Bluetoothd says:

bluetoothd: Accepted new client connection on unix socket (fd=23)
bluetoothd: Audio API: received BT_GETCAPABILITIES_REQ
bluetoothd: Audio API: sending BT_GETCAPABILITIES_RSP
bluetoothd: Audio API: received BT_SETCONFIGURATION_REQ
bluetoothd: config sco - device = 00:1A:45:2F:49:98 access_mode = 2
bluetoothd: /org/bluez/hci0/dev_00_1A_45_2F_49_98: Connecting to 00:1A:45:2F:49:98 channel 1
bluetoothd: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
bluetoothd: adapter_get_device(00:1A:45:2F:49:98)
bluetoothd: link_key_request (sba=00:0C:41:E1:FF:30, dba=00:1A:45:2F:49:98)
bluetoothd: kernel auth requirements = 0x04
bluetoothd: stored link key type = 0x00
bluetoothd: /org/bluez/hci0/dev_00_1A_45_2F_49_98: Connected to 00:1A:45:2F:49:98
bluetoothd: Received AT+BRSF=27
bluetoothd: HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control"
bluetoothd: Received AT+CIND=?
bluetoothd: Received AT+CIND?
bluetoothd: Received AT+CMER=3, 0, 0, 1
bluetoothd: Event reporting (CMER): mode=3, ind=1
bluetoothd: HFP Service Level Connection established
bluetoothd: State changed /org/bluez/hci0/dev_00_1A_45_2F_49_98: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
bluetoothd: connect: Operation not permitted (1)
bluetoothd: config failed
bluetoothd: Audio API: sending BT_SETCONFIGURATION_RSP
bluetoothd: Unix client disconnected (fd=23)
bluetoothd: Received AT+VGS=00

% aplay -D JX10 lib/alarm.wav
Playing WAVE 'lib/alarm.wav' : Signed 16 bit Little Endian, Rate 8000 Hz, Mono
ALSA lib pcm_bluetooth.c:464:(bluetooth_hsp_hw_params) BT_SETCONFIGURATION failed : Input/output error(5)
aplay: set_params:979: Unable to install hw params:
ACCESS:  RW_INTERLEAVED
FORMAT:  S16_LE
SUBFORMAT:  STD
SAMPLE_BITS: 16
FRAME_BITS: 16
CHANNELS: 1
RATE: 8000
PERIOD_TIME: 125000
PERIOD_SIZE: 1000
PERIOD_BYTES: 2000
PERIODS: 4
BUFFER_TIME: 500000
BUFFER_SIZE: 4000
BUFFER_BYTES: 8000
TICK_TIME: [0 0]

# hciconfig hci0 revision
hci0:    Type: USB
     BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
     HCI 16.4
     Chip version: BlueCore02-External
     Max key size: 56 bit
     SCO mapping:  HCI
# hciconfig hci0 version
hci0:    Type: USB
     BD Address: 00:0C:41:E1:FF:30 ACL MTU: 192:8 SCO MTU: 64:8
     HCI Ver: 1.1 (0x1) HCI Rev: 0x20d LMP Ver: 1.1 (0x1) LMP Subver: 0x20d
     Manufacturer: Cambridge Silicon Radio (10)

HCI sniffer - Bluetooth packet analyzer ver 1.42
device: hci0 snap_len: 1028 filter: 0xffffffff
< HCI Command: Create Connection (0x01|0x0005) plen 13
     bdaddr 00:1A:45:2F:49:98 ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
     Packet type: DM1 DM3 DM5 DH1 DH3 DH5
 > HCI Event: Command Status (0x0f) plen 4
     Create Connection (0x01|0x0005) status 0x00 ncmd 1
 > HCI Event: Connect Complete (0x03) plen 11
     status 0x00 handle 41 bdaddr 00:1A:45:2F:49:98 type ACL encrypt 0x00
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
     handle 41
 > HCI Event: Command Status (0x0f) plen 4
     Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 0
 > HCI Event: Page Scan Repetition Mode Change (0x20) plen 7
     bdaddr 00:1A:45:2F:49:98 mode 1
 > HCI Event: Max Slots Change (0x1b) plen 3
     handle 41 slots 5
 > HCI Event: Command Status (0x0f) plen 4
     Unknown (0x00|0x0000) status 0x00 ncmd 1
< HCI Command: Remote Name Request (0x01|0x0019) plen 10
     bdaddr 00:1A:45:2F:49:98 mode 2 clkoffset 0x0000
 > HCI Event: Command Status (0x0f) plen 4
     Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
 > HCI Event: Read Remote Supported Features (0x0b) plen 11
     status 0x00 handle 41
     Features: 0xbf 0xfe 0x8b 0xf8 0x1b 0x18 0x00 0x80
< ACL data: handle 41 flags 0x02 dlen 10
     L2CAP(s): Info req: type 2
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 16
     L2CAP(s): Info rsp: type 2 result 0
       Extended feature mask 0x0000
< ACL data: handle 41 flags 0x02 dlen 12
     L2CAP(s): Connect req: psm 3 scid 0x0040
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 16
     L2CAP(s): Connect rsp: dcid 0x0058 scid 0x0040 result 1 status 2
       Connection pending - Authorization pending
 > HCI Event: Remote Name Req Complete (0x07) plen 255
     status 0x00 bdaddr 00:1A:45:2F:49:98 name 'Jabra JX10 series 2'
 > HCI Event: Link Key Request (0x17) plen 6
     bdaddr 00:1A:45:2F:49:98
< HCI Command: Link Key Request Reply (0x01|0x000b) plen 22
     bdaddr 00:1A:45:2F:49:98 key F63331CE2D0DBCA190DC73C930CD6117
 > HCI Event: Command Complete (0x0e) plen 10
     Link Key Request Reply (0x01|0x000b) ncmd 1
     status 0x00 bdaddr 00:1A:45:2F:49:98
 > ACL data: handle 41 flags 0x02 dlen 16
     L2CAP(s): Connect rsp: dcid 0x0058 scid 0x0040 result 0 status 0
       Connection successful
< ACL data: handle 41 flags 0x02 dlen 16
     L2CAP(s): Config req: dcid 0x0058 flags 0x00 clen 4
       MTU 1013
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 14
     L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 0
       Success
 > ACL data: handle 41 flags 0x02 dlen 16
     L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
       MTU 1013
< ACL data: handle 41 flags 0x02 dlen 18
     L2CAP(s): Config rsp: scid 0x0058 flags 0x00 result 0 clen 4
       MTU 1013
< ACL data: handle 41 flags 0x02 dlen 8
     L2CAP(d): cid 0x0058 len 4 [psm 3]
       RFCOMM(s): SABM: cr 1 dlci 0 pf 1 ilen 0 fcs 0x1c
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 8
     L2CAP(d): cid 0x0040 len 4 [psm 3]
       RFCOMM(s): UA: cr 1 dlci 0 pf 1 ilen 0 fcs 0xd7
< ACL data: handle 41 flags 0x02 dlen 18
     L2CAP(d): cid 0x0058 len 14 [psm 3]
       RFCOMM(s): PN CMD: cr 1 dlci 0 pf 0 ilen 10 fcs 0x70 mcc_len 8
       dlci 2 frame_type 0 credit_flow 15 pri 7 ack_timer 0
       frame_size 1008 max_retrans 0 credits 7
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 18
     L2CAP(d): cid 0x0040 len 14 [psm 3]
       RFCOMM(s): PN RSP: cr 0 dlci 0 pf 0 ilen 10 fcs 0xaa mcc_len 8
       dlci 2 frame_type 0 credit_flow 14 pri 7 ack_timer 0
       frame_size 127 max_retrans 0 credits 0
< ACL data: handle 41 flags 0x02 dlen 8
     L2CAP(d): cid 0x0058 len 4 [psm 3]
       RFCOMM(s): SABM: cr 1 dlci 2 pf 1 ilen 0 fcs 0x59
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 8
     L2CAP(d): cid 0x0040 len 4 [psm 3]
       RFCOMM(s): UA: cr 1 dlci 2 pf 1 ilen 0 fcs 0x92
< ACL data: handle 41 flags 0x02 dlen 12
     L2CAP(d): cid 0x0058 len 8 [psm 3]
       RFCOMM(s): MSC CMD: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
       dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 0 b2 0 b3 0 len 0
 > ACL data: handle 41 flags 0x02 dlen 12
     L2CAP(d): cid 0x0040 len 8 [psm 3]
       RFCOMM(s): MSC CMD: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
       dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 0 b1 0 b2 0 b3 0 len 0
< ACL data: handle 41 flags 0x02 dlen 12
     L2CAP(d): cid 0x0058 len 8 [psm 3]
       RFCOMM(s): MSC RSP: cr 1 dlci 0 pf 0 ilen 4 fcs 0x70 mcc_len 2
       dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 0 b1 0 b2 0 b3 0 len 0
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 12
     L2CAP(d): cid 0x0040 len 8 [psm 3]
       RFCOMM(s): MSC RSP: cr 0 dlci 0 pf 0 ilen 4 fcs 0xaa mcc_len 2
       dlci 2 fc 0 rtc 1 rtr 1 ic 0 dv 1 b1 0 b2 0 b3 0 len 0
< ACL data: handle 41 flags 0x02 dlen 9
     L2CAP(d): cid 0x0058 len 5 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 1 ilen 0 fcs 0x86 credits 33
 > ACL data: handle 41 flags 0x02 dlen 9
     L2CAP(d): cid 0x0040 len 5 [psm 3]
       RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 0 fcs 0x5c credits 15
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 19
     L2CAP(d): cid 0x0040 len 15 [psm 3]
       RFCOMM(d): UIH: cr 0 dlci 2 pf 0 ilen 11 fcs 0x40
       0000: 41 54 2b 42 52 53 46 3d  32 37 0d                 AT+BRSF=27.
< ACL data: handle 41 flags 0x02 dlen 19
     L2CAP(d): cid 0x0058 len 15 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 11 fcs 0x9a
       0000: 0d 0a 2b 42 52 53 46 3d  30 0d 0a                 ..+BRSF=0..
< ACL data: handle 41 flags 0x02 dlen 14
     L2CAP(d): cid 0x0058 len 10 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a
       0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 19
     L2CAP(d): cid 0x0040 len 15 [psm 3]
       RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 10 fcs 0x5c credits 2
       0000: 41 54 2b 43 49 4e 44 3d  3f 0d                    AT+CIND=?.
< ACL data: handle 41 flags 0x02 dlen 135
     L2CAP(d): cid 0x0058 len 131 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 127 fcs 0x9a
       0000: 0d 0a 2b 43 49 4e 44 3a  28 22 62 61 74 74 63 68  ..+CIND:("battch
       0010: 67 22 2c 28 30 2d 35 29  29 2c 28 22 73 69 67 6e  g",(0-5)),("sign
       0020: 61 6c 22 2c 28 30 2d 35  29 29 2c 28 22 73 65 72  al",(0-5)),("ser
       0030: 76 69 63 65 22 2c 28 30  2c 31 29 29 2c 28 22 63  vice",(0,1)),("c
       0040: 61 6c 6c 22 2c 28 30 2c  31 29 29 2c 28 22 63 61  all",(0,1)),("ca
       0050: 6c 6c 73 65 74 75 70 22  2c 28 30 2d 33 29 29 2c  llsetup",(0-3)),
       0060: 28 22 63 61 6c 6c 68 65  6c 64 22 2c 28 30 2d 32  ("callheld",(0-2
       0070: 29 29 2c 28 22 72 6f 61  6d 22 2c 28 30 2c 31     )),("roam",(0,1
< ACL data: handle 41 flags 0x02 dlen 12
     L2CAP(d): cid 0x0058 len 8 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 4 fcs 0x9a
       0000: 29 29 0d 0a                                       ))..
< ACL data: handle 41 flags 0x02 dlen 14
     L2CAP(d): cid 0x0058 len 10 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a
       0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 18
     L2CAP(d): cid 0x0040 len 14 [psm 3]
       RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 9 fcs 0x5c credits 3
       0000: 41 54 2b 43 49 4e 44 3f  0d                       AT+CIND?.
< ACL data: handle 41 flags 0x02 dlen 31
     L2CAP(d): cid 0x0058 len 27 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 23 fcs 0x9a
       0000: 0d 0a 2b 43 49 4e 44 3a  35 2c 35 2c 31 2c 30 2c  ..+CIND:5,5,1,0,
       0010: 30 2c 30 2c 30 0d 0a                              0,0,0..
< ACL data: handle 41 flags 0x02 dlen 14
     L2CAP(d): cid 0x0058 len 10 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a
       0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 28
     L2CAP(d): cid 0x0040 len 24 [psm 3]
       RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 19 fcs 0x5c credits 2
       0000: 41 54 2b 43 4d 45 52 3d  33 2c 20 30 2c 20 30 2c  AT+CMER=3, 0, 0,
       0010: 20 31 0d                                           1.
< ACL data: handle 41 flags 0x02 dlen 14
     L2CAP(d): cid 0x0058 len 10 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a
       0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
 > ACL data: handle 41 flags 0x02 dlen 19
     L2CAP(d): cid 0x0040 len 15 [psm 3]
       RFCOMM(d): UIH: cr 0 dlci 2 pf 1 ilen 10 fcs 0x5c credits 1
       0000: 41 54 2b 56 47 53 3d 30  30 0d                    AT+VGS=00.
< ACL data: handle 41 flags 0x02 dlen 14
     L2CAP(d): cid 0x0058 len 10 [psm 3]
       RFCOMM(d): UIH: cr 1 dlci 2 pf 0 ilen 6 fcs 0x9a
       0000: 0d 0a 4f 4b 0d 0a                                 ..OK..
 > HCI Event: Number of Completed Packets (0x13) plen 5
     handle 41 packets 1
Comment 12 Martin Jansa 2008-10-15 03:52:09 UTC 
I have the same problem with similar BT dongle with different headset.

jama ~ # hciconfig  -a
hci0:   Type: USB
        BD Address: 00:11:09:E6:3C:EA ACL MTU: 192:8 SCO MTU: 64:8
        UP RUNNING PSCAN ISCAN
        RX bytes:1313 acl:0 sco:0 events:39 errors:0
        TX bytes:418 acl:0 sco:0 commands:39 errors:0
        Features: 0xff 0xff 0x8f 0x78 0x18 0x18 0x00 0x80
        Packet type: DM1 DM3 DM5 DH1 DH3 DH5 HV1 HV2 HV3
        Link policy: RSWITCH HOLD SNIFF PARK
        Link mode: SLAVE ACCEPT
        Name: 'jama-0'
        Class: 0x0a0104
        Service Classes: Networking, Capturing
        Device Class: Computer, Desktop workstation
        HCI Ver: 1.2 (0x2) HCI Rev: 0x570 LMP Ver: 1.2 (0x2) LMP Subver: 0x570
        Manufacturer: Cambridge Silicon Radio (10)

I'll attach headset identification later from home. Also if you need more information like hcidumps from Stuart, let me know.

Kernel versions 2.6.27-rc* and its the same in final 2.6.27.
Comment 13 Alan 2012-05-22 13:54:17 UTC 
Is this still present in modern kernels ?
Note You need to log in before you can comment on or make changes to this bug.