On Sun, 2011-08-07 at 11:34 -0400, Ilia, Kolominsky wrote: > Hello! > Can anybody help me to understand the process of handling avdtp > SET_CONFIGURATION command in scenario when a2dp headset initializes > connection to linux machine? I see that the headset sends > SET_CONFIGURATION avdtp command (with appropriate SBC params), > but i cant find out how this ultimately translates to actual > configuration of a player (totem in my case). > > What layers are involved in general? > > I see that handling of the command follows the following path (approx.): > avdtp.c::sbc_setconf_ind() > a2dp.c::auto_config() > avdtp.c::avdtp_sep_set_state() > a2dp.c::stream_state_changed() > sink.c::stream_state_changed() > At no stage I am able to spot the actual configuration of the sbc... > (there should be probably some sort of d-bus messages, but, again, > I don’t see that neither SelectConfiguration nor SetConfiguration > from the media-api are used). > > In addition, there is BT_SET_CONFIGURATION command that is handled > in unix.c (after SET_CONFIGURATION is handled); how does it fits > in the configuration picture? > > Any info (or reference where it can be found) will be much > appreciated. > > Thanks and regards. Hi Ilia, I have no idea how totem interfaces to Bluez but I've attached a syslog of a bt headset a2dp connect to PulseAudio (with debug output enabled for both bluetoothd and pulseaudio). As you can ascertain from the log, one of the subtleties of SEP handling is that a previously established SEP configuration (selected by the headset) is "magically found" much later by the client of the Audio API. Look at the section of the log that starts with line 86, module-bluetooth-device.c: Connected to the bluetooth audio service then further down @ line 124 audio/a2dp.c:a2dp_config() a2dp_config: selected SEP 0x7fb87a885780 This is where the bluez a2dp code matches the client BT_SET_CONFIGURATION request with the existing SEP. Of course, this isn't the only establishment sequence but I think it will help you get started. Regards, Peter Hurley
Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() hci0 dba 00:0D:FD:1E:99:30 Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:get_auth_info() hci0 dba 00:0D:FD:1E:99:30 Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() kernel auth requirements = 0x04 Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() Matching key found Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() link key type 0x00 Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:conn_complete() status 0x00 Aug 8 16:16:59 THOR bluetoothd[1254]: src/adapter.c:adapter_get_device() 00:0D:FD:1E:99:30 Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:bonding_complete() status 0x00 Aug 8 16:16:59 THOR bluetoothd[1254]: src/event.c:btd_event_bonding_complete() status 0x00 Aug 8 16:16:59 THOR bluetoothd[1254]: src/adapter.c:adapter_get_device() 00:0D:FD:1E:99:30 Aug 8 16:16:59 THOR bluetoothd[1254]: src/device.c:device_bonding_complete() bonding (nil) status 0x00 Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:remote_features_information() hci0 status 0 Aug 8 16:16:59 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.Device, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:16:59 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.Device, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:16:59 THOR bluetoothd[1254]: plugins/hciops.c:remote_name_information() hci0 status 0 Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() hci0 dba 00:0D:FD:1E:99:30 Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:get_auth_info() hci0 dba 00:0D:FD:1E:99:30 Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() kernel auth requirements = 0x04 Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() Matching key found Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:link_key_request() link key type 0x00 Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:auth_complete() hci0 status 0 Aug 8 16:17:00 THOR bluetoothd[1254]: plugins/hciops.c:bonding_complete() status 0x00 Aug 8 16:17:00 THOR bluetoothd[1254]: src/event.c:btd_event_bonding_complete() status 0x00 Aug 8 16:17:00 THOR bluetoothd[1254]: src/adapter.c:adapter_get_device() 00:0D:FD:1E:99:30 Aug 8 16:17:00 THOR bluetoothd[1254]: src/device.c:device_bonding_complete() bonding (nil) status 0x00 Aug 8 16:17:00 THOR bluetoothd[1254]: audio/headset.c:headset_set_state() State changed /org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30: HEADSET_STATE_DISCONNECTED -> HEADSET_STATE_CONNECTING Aug 8 16:17:00 THOR bluetoothd[1254]: audio/headset.c:headset_connect_cb() /org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30: Connected to 00:0D:FD:1E:99:30 Aug 8 16:17:00 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.Headset, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:00 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.Headset, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:00 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.Audio, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:00 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.Audio, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:01 THOR bluetoothd[1254]: audio/headset.c:handle_event() Received AT+BRSF=27 Aug 8 16:17:01 THOR bluetoothd[1254]: audio/headset.c:print_hf_features() HFP HF features: "EC and/or NR function" "Call waiting and 3-way calling" "Voice recognition activation" "Remote volume control" Aug 8 16:17:01 THOR CRON[3204]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Aug 8 16:17:01 THOR bluetoothd[1254]: audio/headset.c:handle_event() Received AT+CIND=? Aug 8 16:17:01 THOR bluetoothd[1254]: audio/headset.c:handle_event() Received AT+CIND? Aug 8 16:17:02 THOR bluetoothd[1254]: audio/headset.c:handle_event() Received AT+CMER=3, 0, 0, 1 Aug 8 16:17:02 THOR bluetoothd[1254]: audio/headset.c:event_reporting() Event reporting (CMER): mode=3, ind=1 Aug 8 16:17:02 THOR bluetoothd[1254]: audio/headset.c:hfp_slc_complete() HFP Service Level Connection established Aug 8 16:17:02 THOR bluetoothd[1254]: audio/telephony.c:telephony_device_connected() telephony-dummy: device 0x7fb87a88e250 connected Aug 8 16:17:02 THOR bluetoothd[1254]: audio/headset.c:headset_set_state() State changed /org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30: HEADSET_STATE_CONNECTING -> HEADSET_STATE_CONNECTED Aug 8 16:17:02 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.Headset, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:02 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.Headset, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:02 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.Headset, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:02 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.Headset, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:03 THOR bluetoothd[1254]: audio/headset.c:handle_event() Received AT+VGS=15 Aug 8 16:17:03 THOR bluetoothd[1254]: audio/headset.c:headset_set_gain() Ignoring no-change in speaker gain Aug 8 16:17:03 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_confirm_cb() AVDTP: incoming connect from 00:0D:FD:1E:99:30 Aug 8 16:17:03 THOR bluetoothd[1254]: audio/sink.c:sink_set_state() State changed /org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30: SINK_STATE_DISCONNECTED -> SINK_STATE_CONNECTING Aug 8 16:17:03 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:03 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_connect_cb() AVDTP: connected signaling channel to 00:0D:FD:1E:99:30 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_connect_cb() AVDTP imtu=672, omtu=895 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_cmd() Received DISCOVER_CMD Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_cmd() Received GET_CAPABILITIES_CMD Aug 8 16:17:04 THOR bluetoothd[1254]: audio/a2dp.c:sbc_getcap_ind() Source 0x7fb87a885780: Get_Capability_Ind Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_cmd() Received SET_CONFIGURATION_CMD Aug 8 16:17:04 THOR bluetoothd[1254]: audio/a2dp.c:sbc_setconf_ind() Source 0x7fb87a885780: Set_Configuration_Ind Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_ref() 0x7fb87a88edd0: ref=2 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/a2dp.c:setup_ref() 0x7fb87a894cb0: ref=1 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_ref() 0x7fb87a88edd0: ref=3 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_sep_set_state() stream state changed: IDLE -> CONFIGURED Aug 8 16:17:04 THOR bluetoothd[1254]: audio/a2dp.c:setup_unref() 0x7fb87a894cb0: ref=0 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/a2dp.c:setup_free() 0x7fb87a894cb0 Aug 8 16:17:04 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_unref() 0x7fb87a88edd0: ref=2 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_cmd() Received OPEN_CMD Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:open_ind() Source 0x7fb87a885780: Open_Ind Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_confirm_cb() AVDTP: incoming connect from 00:0D:FD:1E:99:30 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_connect_cb() AVDTP: connected transport channel to 00:0D:FD:1E:99:30 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:handle_transport_connect() Flushable packets enabled Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:handle_transport_connect() sk 38, omtu 672, send buffer size 63488 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_sep_set_state() stream state changed: CONFIGURED -> OPEN Aug 8 16:17:05 THOR bluetoothd[1254]: audio/sink.c:sink_set_state() State changed /org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30: SINK_STATE_CONNECTING -> SINK_STATE_CONNECTED Aug 8 16:17:05 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:05 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:05 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:05 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:05 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.Audio, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-discover.c: Loading module-bluetooth-device address="00:0D:FD:1E:99:30" path="/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30" Aug 8 16:17:05 THOR pulseaudio[1762]: module-card-restore.c: Restoring profile for card bluez_card.00_0D_FD_1E_99_30. Aug 8 16:17:05 THOR pulseaudio[1762]: card.c: Created 3 "bluez_card.00_0D_FD_1E_99_30" Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Connected to the bluetooth audio service Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Sending BT_REQUEST -> BT_GET_CAPABILITIES Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Trying to receive message from audio service... Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:server_cb() Accepted new client connection on unix socket (fd=39) Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:client_cb() Audio API: BT_REQUEST <- BT_GET_CAPABILITIES Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_ref() 0x7fb87a88edd0: ref=3 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_resp() DISCOVER request succeeded Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_discover_resp() seid 1 type 1 media 0 in use 1 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_discover_resp() seid 2 type 1 media 0 in use 1 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_resp() GET_CAPABILITIES request succeeded Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_get_capabilities_resp() seid 1 type 1 media 0 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:print_sbc() Media Codec: SBC Channel Modes: Mono DualChannel Stereo JointStereo Frequencies: 16Khz 32Khz 44.1Khz 48Khz Subbands: 4 8 Blocks: 4 8 12 16 Bitpool: 2-44 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:a2dp_append_codec() Append configured seid 1 - length 13 - total 181 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:unix_ipc_sendmsg() Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Received BT_RESPONSE <- BT_GET_CAPABILITIES Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Payload size is 13 6 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Sending BT_REQUEST -> BT_GET_CAPABILITIES Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Trying to receive message from audio service... Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:client_cb() Audio API: BT_REQUEST <- BT_GET_CAPABILITIES Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:print_sbc() Media Codec: SBC Channel Modes: JointStereo Frequencies: 44.1Khz Subbands: 8 Blocks: 16 Bitpool: 2-44 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:a2dp_append_codec() Append configured seid 1 - length 13 - total 181 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:unix_ipc_sendmsg() Audio API: BT_RESPONSE -> BT_GET_CAPABILITIES Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Received BT_RESPONSE <- BT_GET_CAPABILITIES Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Payload size is 13 6 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Got device capabilities Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Sending BT_REQUEST -> BT_OPEN Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Trying to receive message from audio service... Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:client_cb() Audio API: BT_REQUEST <- BT_OPEN Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:handle_a2dp_open() open a2dp - object=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30 source=ANY destination=ANY lock=write Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:a2dp_sep_lock() SEP 0x7fb87a885780 locked Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:unix_ipc_sendmsg() Audio API: BT_RESPONSE -> BT_OPEN Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Received BT_RESPONSE <- BT_OPEN Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Sending BT_REQUEST -> BT_SET_CONFIGURATION Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Trying to receive message from audio service... Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:client_cb() Audio API: BT_REQUEST <- BT_SET_CONFIGURATION Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:print_sbc() Media Codec: SBC Channel Modes: JointStereo Frequencies: 44.1Khz Subbands: 8 Blocks: 16 Bitpool: 2-44 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:a2dp_config() a2dp_config: selected SEP 0x7fb87a885780 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_ref() 0x7fb87a88edd0: ref=4 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:setup_ref() 0x7fb87a894cb0: ref=1 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:a2dp_config() Configuration match: resuming Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:unix_ipc_sendmsg() Audio API: BT_RESPONSE -> BT_SET_CONFIGURATION Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:setup_unref() 0x7fb87a894cb0: ref=0 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:setup_free() 0x7fb87a894cb0 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_unref() 0x7fb87a88edd0: ref=3 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Received BT_RESPONSE <- BT_SET_CONFIGURATION Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: SBC parameters: Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: #011allocation=0 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: #011subbands=1 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: #011blocks=3 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: #011bitpool=44 Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Connection to the device configured Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Got the stream socket Aug 8 16:17:05 THOR pulseaudio[1762]: module-device-restore.c: Restoring volume for sink bluez_sink.00_0D_FD_1E_99_30. Aug 8 16:17:05 THOR pulseaudio[1762]: module-device-restore.c: Restoring mute state for sink bluez_sink.00_0D_FD_1E_99_30. Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: Created sink 3 "bluez_sink.00_0D_FD_1E_99_30" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: bluetooth.protocol = "a2dp" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.description = "Motorola S9-HD" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.string = "00:0D:FD:1E:99:30" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.api = "bluez" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.class = "sound" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.bus = "bluetooth" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.form_factor = "headset" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: bluez.path = "/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: bluez.class = "0x240404" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: bluez.name = "Motorola S9-HD" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.icon_name = "audio-headset-bluetooth" Aug 8 16:17:05 THOR pulseaudio[1762]: sink.c: device.intended_roles = "phone" Aug 8 16:17:05 THOR pulseaudio[1762]: module-device-restore.c: Restoring mute state for source bluez_sink.00_0D_FD_1E_99_30.monitor. Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: Created source 4 "bluez_sink.00_0D_FD_1E_99_30.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.description = "Monitor of Motorola S9-HD" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.class = "monitor" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.string = "00:0D:FD:1E:99:30" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.api = "bluez" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.bus = "bluetooth" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.form_factor = "headset" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: bluez.path = "/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: bluez.class = "0x240404" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: bluez.name = "Motorola S9-HD" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.icon_name = "audio-headset-bluetooth" Aug 8 16:17:05 THOR pulseaudio[1762]: source.c: device.intended_roles = "phone" Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: IO Thread starting up Aug 8 16:17:05 THOR rtkit-daemon[1766]: Successfully made thread 3206 of process 1762 (n/a) owned by '1000' RT at priority 5. Aug 8 16:17:05 THOR rtkit-daemon[1766]: Supervising 4 threads of 1 processes of 1 users. Aug 8 16:17:05 THOR pulseaudio[1762]: core-util.c: RealtimeKit worked. Aug 8 16:17:05 THOR pulseaudio[1762]: core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 5. Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Sending BT_REQUEST -> BT_START_STREAM Aug 8 16:17:05 THOR pulseaudio[1762]: module-bluetooth-device.c: Trying to receive message from audio service... Aug 8 16:17:05 THOR bluetoothd[1254]: audio/unix.c:client_cb() Audio API: BT_REQUEST <- BT_START_STREAM Aug 8 16:17:05 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_ref() 0x7fb87a88edd0: ref=4 Aug 8 16:17:05 THOR bluetoothd[1254]: audio/a2dp.c:setup_ref() 0x7fb87a89c590: ref=1 Aug 8 16:17:06 THOR bluetoothd[1254]: audio/avdtp.c:session_cb() Aug 8 16:17:06 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_parse_resp() START request succeeded Aug 8 16:17:06 THOR bluetoothd[1254]: audio/a2dp.c:start_cfm() Source 0x7fb87a885780: Start_Cfm Aug 8 16:17:06 THOR bluetoothd[1254]: audio/unix.c:unix_ipc_sendmsg() Audio API: BT_RESPONSE -> BT_START_STREAM Aug 8 16:17:06 THOR bluetoothd[1254]: audio/unix.c:unix_ipc_sendmsg() Audio API: BT_RESPONSE -> BT_NEW_STREAM Aug 8 16:17:06 THOR bluetoothd[1254]: audio/a2dp.c:setup_unref() 0x7fb87a89c590: ref=0 Aug 8 16:17:06 THOR bluetoothd[1254]: audio/a2dp.c:setup_free() 0x7fb87a89c590 Aug 8 16:17:06 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_unref() 0x7fb87a88edd0: ref=3 Aug 8 16:17:06 THOR bluetoothd[1254]: audio/avdtp.c:avdtp_sep_set_state() stream state changed: OPEN -> STREAMING Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: Received BT_RESPONSE <- BT_START_STREAM Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: Trying to receive message from audio service... Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: Received BT_RESPONSE <- BT_NEW_STREAM Aug 8 16:17:06 THOR bluetoothd[1254]: audio/sink.c:sink_set_state() State changed /org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30: SINK_STATE_CONNECTED -> SINK_STATE_PLAYING Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: Stream properly set up, we're ready to roll! Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: u->sink = 0x162a360 Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: u->source = (nil) Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: pollfd = 0x15b4990 Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: pollfd->revents = 0 Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: sink_is_linked = 0 Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: **** started_at not initialized **** Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: Using SBC encoder implementation: MMX Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: block_size=3072 frame_length=101 codesize=512 Aug 8 16:17:06 THOR pulseaudio[1762]: module-suspend-on-idle.c: Sink bluez_sink.00_0D_FD_1E_99_30 becomes idle, timeout in 5 seconds. Aug 8 16:17:06 THOR pulseaudio[1762]: module.c: Loaded "module-bluetooth-device" (index: #23; argument: "address="00:0D:FD:1E:99:30" path="/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30""). Aug 8 16:17:06 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.Audio, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:06 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:06 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:06 THOR pulseaudio[1762]: bluetooth-util.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:06 THOR pulseaudio[1762]: module-console-kit.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged Aug 8 16:17:06 THOR pulseaudio[1762]: module-bluetooth-device.c: dbus: interface=org.bluez.AudioSink, path=/org/bluez/1249/hci0/dev_00_0D_FD_1E_99_30, member=PropertyChanged
