* HBH-PV270 headset get locked
@ 2008-11-25 4:10 Sam Lin
2008-11-25 8:14 ` Sam Lin
0 siblings, 1 reply; 7+ messages in thread
From: Sam Lin @ 2008-11-25 4:10 UTC (permalink / raw)
To: linux-bluetooth
[-- Attachment #1: Type: text/plain, Size: 565 bytes --]
Hi All,
I tried Sony Ericsson HBH-PV720 with aplay and found something wrong.
Log as attachment.
from first try (timestamp in log 11:24:23 - 11:24:31 ) it works fine.
sound played.
but since 2nd try (timestamp in log 11:25:21 - 11:25:26) SCO packets
flow but no sound played.
something outstanding is:
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Unable to lock headset
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: config failed
then headset works no more, SCO packets keep flow until powerdown headset.
would you please give any hint on this ?
Sam Lin
[-- Attachment #2: bluez-debug.log --]
[-- Type: text/x-log, Size: 17226 bytes --]
Nov 25 11:24:01 itrs-ubuntu bluetoothd[10399]: Discovery session 0xb950df70 with :1.52 activated
Nov 25 11:24:01 itrs-ubuntu bluetoothd[10399]: session_ref(0xb950df70): ref=1
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: session_unref(0xb950df70): ref=0
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: Discovery session 0xb950df70 with :1.52 deactivated
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: Stopping discovery
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: bonding_request_new(00:1E:DC:AB:6D:3F)
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: adapter_create_device(00:1E:DC:AB:6D:3F)
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: Creating device /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:05 itrs-ubuntu bluetoothd[10399]: Temporary agent registered for hci0/00:1E:DC:AB:6D:3F at :1.52:/org/bluez/agent/wizard
Nov 25 11:24:06 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:24:06 itrs-ubuntu bluetoothd[10399]: link_key_request (sba=00:02:5B:00:A5:A5, dba=00:1E:DC:AB:6D:3F)
Nov 25 11:24:06 itrs-ubuntu bluetoothd[10399]: kernel auth requirements = 0x04
Nov 25 11:24:06 itrs-ubuntu bluetoothd[10399]: pin_code_request (sba=00:02:5B:00:A5:A5, dba=00:1E:DC:AB:6D:3F)
Nov 25 11:24:06 itrs-ubuntu bluetoothd[10399]: hcid_dbus_new_auth_request
Nov 25 11:24:07 itrs-ubuntu bluetoothd[10399]: link_key_notify (sba=00:02:5B:00:A5:A5, dba=00:1E:DC:AB:6D:3F)
Nov 25 11:24:07 itrs-ubuntu bluetoothd[10399]: hcid_dbus_bonding_process_complete: status=00
Nov 25 11:24:07 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:24:07 itrs-ubuntu bluetoothd[10399]: Releasing agent :1.52, /org/bluez/agent/wizard
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: Probe drivers for /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: Found Headset record
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: Discovered Headset service on RFCOMM channel 1
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: Registered interface org.bluez.Headset on path /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: audio handle_uuid: server not enabled for 0000111e-0000-1000-8000-00805f9b34fb (0x111e)
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: headset_probe: path /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: Registered interface org.bluez.Input on path /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: serial_probe: path /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: 00001108-0000-1000-8000-00805f9b34fb
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: Registered interface org.bluez.Serial on path /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:08 itrs-ubuntu bluetoothd[10399]: serial_probe: path /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: 0000111e-0000-1000-8000-00805f9b34fb
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: Accepted new client connection on unix socket (fd=24)
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_GETCAPABILITIES_REQ
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_GETCAPABILITIES_RSP
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_SETCONFIGURATION_REQ
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: config sco - device = 00:1E:DC:AB:6D:3F access_mode = 2
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connecting to 00:1E:DC:AB:6D:3F channel 1
Nov 25 11:24:23 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
Nov 25 11:24:24 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:24:24 itrs-ubuntu bluetoothd[10399]: link_key_request (sba=00:02:5B:00:A5:A5, dba=00:1E:DC:AB:6D:3F)
Nov 25 11:24:24 itrs-ubuntu bluetoothd[10399]: kernel auth requirements = 0x04
Nov 25 11:24:24 itrs-ubuntu bluetoothd[10399]: stored link key type = 0x00
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connected to 00:1E:DC:AB:6D:3F
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 connected
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT+CLIP=1
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: SCO socket opened for headset /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: SCO fd=26
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_SETCONFIGURATION_RSP
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_STREAMSTART_REQ
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_STREAMSTART_RSP
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_STREAMFD_IND
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT+VGS=7
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT+CSCS="UTF-8"
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CSCS="UTF-8"
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT*SEAM="HBH-PV720",13
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT*SEAM="HBH-PV720",13
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT+CLAN?
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CLAN?
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT*EIPS=2,1
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT*EIPS=2,1
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT+COLP=1
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+COLP=1
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Received AT+CCLK?
Nov 25 11:24:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CCLK?
Nov 25 11:24:27 itrs-ubuntu bluetoothd[10399]: Unix client disconnected (fd=24)
Nov 25 11:24:27 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
Nov 25 11:24:27 itrs-ubuntu bluetoothd[10399]: No matching connection for handle 46
Nov 25 11:24:31 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 disconnected
Nov 25 11:24:31 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
-----------------------------------------
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: Accepted new client connection on unix socket (fd=24)
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_GETCAPABILITIES_REQ
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_GETCAPABILITIES_RSP
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_SETCONFIGURATION_REQ
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: config sco - device = 00:1E:DC:AB:6D:3F access_mode = 2
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connecting to 00:1E:DC:AB:6D:3F channel 1
Nov 25 11:24:55 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: connect(): Host is down (112)
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_SETCONFIGURATION_RSP
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 disconnected
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_DISCONNECTED
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_STREAMSTART_REQ
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_STREAMSTART_RSP
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_STREAMFD_IND
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: unix_sendmsg_fd: Bad file descriptor(9)
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: resume failed
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_STREAMSTART_RSP
Nov 25 11:25:00 itrs-ubuntu bluetoothd[10399]: Unix client disconnected (fd=24)
-----------------------------------------
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: Accepted new client connection on unix socket (fd=24)
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_GETCAPABILITIES_REQ
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_GETCAPABILITIES_RSP
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_SETCONFIGURATION_REQ
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: config sco - device = 00:1E:DC:AB:6D:3F access_mode = 2
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connecting to 00:1E:DC:AB:6D:3F channel 1
Nov 25 11:25:21 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
Nov 25 11:25:24 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: link_key_request (sba=00:02:5B:00:A5:A5, dba=00:1E:DC:AB:6D:3F)
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: kernel auth requirements = 0x04
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: stored link key type = 0x00
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connected to 00:1E:DC:AB:6D:3F
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 connected
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT+CLIP=1
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: SCO socket opened for headset /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: SCO fd=26
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Unable to lock headset
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: config failed
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_SETCONFIGURATION_RSP
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Unix client disconnected (fd=24)
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT+VGS=7
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT+CSCS="UTF-8"
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CSCS="UTF-8"
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT*SEAM="HBH-PV720",13
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT*SEAM="HBH-PV720",13
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT+CLAN?
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CLAN?
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT*EIPS=2,1
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT*EIPS=2,1
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Received AT+COLP=1
Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+COLP=1
Nov 25 11:25:26 itrs-ubuntu bluetoothd[10399]: Received AT+CCLK?
Nov 25 11:25:26 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CCLK?
Nov 25 11:26:07 itrs-ubuntu bluetoothd[10399]: No matching connection for handle 45
Nov 25 11:26:07 itrs-ubuntu bluetoothd[10399]: Audio connection got disconnected
Nov 25 11:26:07 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
Nov 25 11:26:30 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 disconnected
Nov 25 11:26:30 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
-----------------------------------------
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: Accepted new client connection on unix socket (fd=24)
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_GETCAPABILITIES_REQ
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_GETCAPABILITIES_RSP
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: Audio API: received BT_SETCONFIGURATION_REQ
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: config sco - device = 00:1E:DC:AB:6D:3F access_mode = 2
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connecting to 00:1E:DC:AB:6D:3F channel 1
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECT_IN_PROGRESS
Nov 25 11:28:45 itrs-ubuntu bluetoothd[10399]: adapter_get_device(00:1E:DC:AB:6D:3F)
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: link_key_request (sba=00:02:5B:00:A5:A5, dba=00:1E:DC:AB:6D:3F)
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: kernel auth requirements = 0x04
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: stored link key type = 0x00
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: Connected to 00:1E:DC:AB:6D:3F
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 connected
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECT_IN_PROGRESS -> HEADSET_STATE_CONNECTED
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED -> HEADSET_STATE_PLAY_IN_PROGRESS
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT+CLIP=1
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: SCO socket opened for headset /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: SCO fd=26
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Unable to lock headset
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: config failed
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Audio API: sending BT_SETCONFIGURATION_RSP
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAY_IN_PROGRESS -> HEADSET_STATE_PLAYING
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Unix client disconnected (fd=24)
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT+VGS=7
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT+CSCS="UTF-8"
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CSCS="UTF-8"
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT*SEAM="HBH-PV720",13
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT*SEAM="HBH-PV720",13
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT+CLAN?
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CLAN?
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT*EIPS=2,1
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT*EIPS=2,1
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT+COLP=1
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+COLP=1
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Received AT+CCLK?
Nov 25 11:28:46 itrs-ubuntu bluetoothd[10399]: Badly formated or unrecognized command: AT+CCLK?
Nov 25 11:29:08 itrs-ubuntu bluetoothd[10399]: No matching connection for handle 45
Nov 25 11:29:08 itrs-ubuntu bluetoothd[10399]: Audio connection got disconnected
Nov 25 11:29:08 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAYING -> HEADSET_STATE_CONNECTED
Nov 25 11:29:10 itrs-ubuntu bluetoothd[10399]: telephony-dummy: device 0xb950ba28 disconnected
Nov 25 11:29:10 itrs-ubuntu bluetoothd[10399]: State changed /org/bluez/10399/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED -> HEADSET_STATE_DISCONNECTED
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: HBH-PV270 headset get locked
2008-11-25 4:10 HBH-PV270 headset get locked Sam Lin
@ 2008-11-25 8:14 ` Sam Lin
2008-11-25 9:15 ` Johan Hedberg
0 siblings, 1 reply; 7+ messages in thread
From: Sam Lin @ 2008-11-25 8:14 UTC (permalink / raw)
To: linux-bluetooth
Hi All,
I traced code and found in some case headset is not unlocked well.
for example when something goes wrong in headset_resume_complete(),
client->dev = NULL
so client_cb() will skip headset_unlock()
then headset will be locked forever until restart bluetoothd.
I have no idea what's the lock idea behind, BTW still unclear how the
problem happens to cause this.
Please help to provide idea.
log:
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]: Accepted new client
connection on unix socket (fd=22)
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]: Audio API: received
BT_GETCAPABILITIES_REQ
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]: Audio API: sending
BT_GETCAPABILITIES_RSP
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]: Audio API: received
BT_SETCONFIGURATION_REQ
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]: config sco - device =
00:1E:DC:AB:6D:3F access_mode = 2
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]:
/org/bluez/hci0/dev_00_1E_DC_AB_6D_3F: Connecting to 00:1E:DC:AB:6D:3F
channel 1
Nov 25 15:55:50 itrs-ubuntu bluetoothd[26202]: State changed
/org/bluez/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_DISCONNECTED ->
HEADSET_STATE_CONNECT_IN_PROGRESS
Nov 25 15:56:09 itrs-ubuntu bluetoothd[26202]:
/org/bluez/hci0/dev_00_1E_DC_AB_6D_3F: Connected to 00:1E:DC:AB:6D:3F
Nov 25 15:56:09 itrs-ubuntu bluetoothd[26202]: telephony-dummy: device
0xb8486ba8 connected
Nov 25 15:56:09 itrs-ubuntu bluetoothd[26202]: State changed
/org/bluez/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECT_IN_PROGRESS
-> HEADSET_STATE_CONNECTED
Nov 25 15:56:09 itrs-ubuntu bluetoothd[26202]: State changed
/org/bluez/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_CONNECTED ->
HEADSET_STATE_PLAY_IN_PROGRESS
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: connect(): Connection
refused (111)
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: headset_lock(before):
hs->lock:0, lock:2, state:3
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: headset_lock: pass lock check
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: headset_lock(after):
hs->lock:2, lock:2, state:3
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: Audio API: sending
BT_SETCONFIGURATION_RSP
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: State changed
/org/bluez/hci0/dev_00_1E_DC_AB_6D_3F: HEADSET_STATE_PLAY_IN_PROGRESS ->
HEADSET_STATE_CONNECTED
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: Audio API: received
BT_STREAMSTART_REQ
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: Audio API: sending
BT_STREAMSTART_RSP
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: Audio API: sending
BT_STREAMFD_IND
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: unix_sendmsg_fd: Bad file
descriptor(9)
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: resume failed
(headset_resume_complete)
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: Audio API: sending
BT_STREAMSTART_RSP
Nov 25 15:56:12 itrs-ubuntu bluetoothd[26202]: Unix client disconnected
(fd=22), type:1, dev:
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Received AT+CLIP=1
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Received AT+CSCS="UTF-8"
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Badly formated or
unrecognized command: AT+CSCS="UTF-8"
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Received
AT*SEAM="HBH-PV720",13
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Badly formated or
unrecognized command: AT*SEAM="HBH-PV720",13
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Received AT+CLAN?
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Badly formated or
unrecognized command: AT+CLAN?
Nov 25 15:56:17 itrs-ubuntu bluetoothd[26202]: Received AT*EIPS=2,1
321,48 77%
......
Sam Lin
Sam Lin 提到:
> Hi All,
>
> I tried Sony Ericsson HBH-PV720 with aplay and found something wrong.
> Log as attachment.
>
> from first try (timestamp in log 11:24:23 - 11:24:31 ) it works fine.
> sound played.
>
> but since 2nd try (timestamp in log 11:25:21 - 11:25:26) SCO packets
> flow but no sound played.
> something outstanding is:
>
> Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: Unable to lock headset
> Nov 25 11:25:25 itrs-ubuntu bluetoothd[10399]: config failed
>
> then headset works no more, SCO packets keep flow until powerdown headset.
>
> would you please give any hint on this ?
>
> Sam Lin
>
>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: HBH-PV270 headset get locked
2008-11-25 8:14 ` Sam Lin
@ 2008-11-25 9:15 ` Johan Hedberg
2008-11-25 14:34 ` Luiz Augusto von Dentz
0 siblings, 1 reply; 7+ messages in thread
From: Johan Hedberg @ 2008-11-25 9:15 UTC (permalink / raw)
To: BlueZ development
Hi,
Thanks for taking the time to investigate this.
On Nov 25, 2008, at 10:14, Sam Lin wrote:
> I traced code and found in some case headset is not unlocked well.
> for example when something goes wrong in headset_resume_complete(),
> client->dev = NULL
>
> so client_cb() will skip headset_unlock()
>
> then headset will be locked forever until restart bluetoothd.
>
> I have no idea what's the lock idea behind, BTW still unclear how the
> problem happens to cause this.
The lock part is used for making sure that only one unix socket client
can have read or write access to a remote device at a time. The part
that's setting client->dev to NULL seems definitely wrong to me but
I'll let Luiz comment on it before making any changes (since according
to git blame he was the last one to touch this part of the code). The
A2DP resume function has similar logic so it probably needs fixing too.
Johan
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: HBH-PV270 headset get locked
2008-11-25 9:15 ` Johan Hedberg
@ 2008-11-25 14:34 ` Luiz Augusto von Dentz
2008-11-26 0:09 ` Sam Lin
2008-11-26 10:06 ` Sam Lin
0 siblings, 2 replies; 7+ messages in thread
From: Luiz Augusto von Dentz @ 2008-11-25 14:34 UTC (permalink / raw)
To: Johan Hedberg; +Cc: BlueZ development
yep, client->dev = NULL seems to be a bug, although by looking the log
it seems there is another problem, the sco connection doesn't succeed
but it still attempt to send the file descriptor. The logic on a2dp is
a little different, since it doesn't start the stream on
BT_SETCONFIGURATION_REQ and unlock the sep in any possible error.
Btw, I couldn't reproduce the problem here by using aplay, arecord or
even both together.
--
Luiz Augusto von Dentz
Engenheiro de Computação
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: HBH-PV270 headset get locked
2008-11-25 14:34 ` Luiz Augusto von Dentz
@ 2008-11-26 0:09 ` Sam Lin
2008-11-26 10:06 ` Sam Lin
1 sibling, 0 replies; 7+ messages in thread
From: Sam Lin @ 2008-11-26 0:09 UTC (permalink / raw)
To: Luiz Augusto von Dentz; +Cc: Johan Hedberg, BlueZ development
I have several headset to try and only HBH-PV270 has this problem.
So it seems to be device dependant and causes compatibility problem.
Sam Lin
Luiz Augusto von Dentz 提到:
> yep, client->dev = NULL seems to be a bug, although by looking the log
> it seems there is another problem, the sco connection doesn't succeed
> but it still attempt to send the file descriptor. The logic on a2dp is
> a little different, since it doesn't start the stream on
> BT_SETCONFIGURATION_REQ and unlock the sep in any possible error.
>
> Btw, I couldn't reproduce the problem here by using aplay, arecord or
> even both together.
>
>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: HBH-PV270 headset get locked
2008-11-25 14:34 ` Luiz Augusto von Dentz
2008-11-26 0:09 ` Sam Lin
@ 2008-11-26 10:06 ` Sam Lin
2008-11-26 13:05 ` Johan Hedberg
1 sibling, 1 reply; 7+ messages in thread
From: Sam Lin @ 2008-11-26 10:06 UTC (permalink / raw)
To: Luiz Augusto von Dentz; +Cc: Johan Hedberg, BlueZ development
1. so do you suggest to just remove the client->dev = NULL statement in
headset_setup_complete() and headset_resume_complete() ?
2. for the file descriptor sending issue have you any suggestion ?
(a hint to trigger this is repeatly run aplay, what i found is while
finishing aplay the hcidump still takes some time to make traffics
settle down (about 3-7 secs), if i repeat aplay in this period it's easy
to trigger the problem)
Thanks,
Sam Lin
Luiz Augusto von Dentz 提到:
> yep, client->dev = NULL seems to be a bug, although by looking the log
> it seems there is another problem, the sco connection doesn't succeed
> but it still attempt to send the file descriptor. The logic on a2dp is
> a little different, since it doesn't start the stream on
> BT_SETCONFIGURATION_REQ and unlock the sep in any possible error.
>
> Btw, I couldn't reproduce the problem here by using aplay, arecord or
> even both together.
>
>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: HBH-PV270 headset get locked
2008-11-26 10:06 ` Sam Lin
@ 2008-11-26 13:05 ` Johan Hedberg
0 siblings, 0 replies; 7+ messages in thread
From: Johan Hedberg @ 2008-11-26 13:05 UTC (permalink / raw)
To: BlueZ development
Hi,
On Nov 26, 2008, at 12:06, Sam Lin wrote:
> 1. so do you suggest to just remove the client->dev = NULL statement
> in headset_setup_complete() and headset_resume_complete() ?
There were already fixes pushed to the git for this. Please test them
and let us know if they help.
Johan
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2008-11-26 13:05 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2008-11-25 4:10 HBH-PV270 headset get locked Sam Lin
2008-11-25 8:14 ` Sam Lin
2008-11-25 9:15 ` Johan Hedberg
2008-11-25 14:34 ` Luiz Augusto von Dentz
2008-11-26 0:09 ` Sam Lin
2008-11-26 10:06 ` Sam Lin
2008-11-26 13:05 ` Johan Hedberg
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox