mbox series

[BlueZ,v2,0/2] transport: don't disconnect A2DP if canceling Acquire() with Release()

Message ID cover.1730579026.git.pav@iki.fi (mailing list archive)
Headers show
Series transport: don't disconnect A2DP if canceling Acquire() with Release() | expand

Message

Pauli Virtanen Nov. 2, 2024, 8:29 p.m. UTC 
User can cancel transport acquire by calling Release() while Acquire()
is in progress. This calls a2dp_cancel() which sends AVDTP_ABORT_CMD,
forcing AVDTP state transition to IDLE, and A2DP profile disconnects.

However, Release()/Acquire() should only result to transitions between
STREAMING/OPEN.  The expected behavior is that either these calls return
error, or they block until the target state is reached.

This corner case probably was untested previously.

Fix by: Release() during pending Acquire() first sends error reply to
the Acquire. Then it waits for START to complete, then sends SUSPEND,
and after that completes, then it replies.

v2:
- handle possible suspend failures after START completes
- fix busy return from transport_a2dp_resume
- fix a2dp_resume/suspend messing reconfiguration state

***

In the end I did not make Acquire() to be able to cancel pending
Release(), since that's more of an enhancement request than bug, as
Acquire() has always just returned error immediately if there is another
pending operation.

SetConfiguration() also works sensibly here, it will queue CLOSE, and
wait for pending START/SUSPEND to complete.  This is how it also worked
previously when there were pending requests --- the difference is just
that now it doesn't fail any more if the Acquire() was canceled by a
Release().

This also runs into a bug where a2dp_resume/suspend mess up the
reconfiguration, if they get called while we are waiting for CLOSE_RSP.
It looks like this was possible to trigger also before, if Release() or
Acquire() is called just after SetConfiguration() without waiting it to
complete. The second patch fixes this.

It's possible to make SetConfiguration() to send ABORT immediately,
change FALSE to TRUE in avdtp_close in a2dp_reconfig, but that probably
would be for a different patch.

Some logs can be found below, showing the behavior in different cases.

Log: Acquire() -> canceled by Release()
----------------------------------------------------------
22:12:25.019782: [:1.712:method_call] > org.bluez.MediaTransport1.Acquire [#37]
22:12:25.019822: profiles/audio/transport.c:media_owner_create() Owner created: sender=:1.712
22:12:25.019844: profiles/audio/transport.c:media_transport_resume() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0 Owner :1.712
22:12:25.019867: profiles/audio/avdtp.c:avdtp_ref() 0x51d00001e080: ref=2
22:12:25.019887: profiles/audio/a2dp.c:a2dp_sep_lock() SEP 0x506000047f60 locked
22:12:25.019913: profiles/audio/avdtp.c:avdtp_ref() 0x51d00001e080: ref=3
22:12:25.019931: profiles/audio/a2dp.c:setup_ref() 0x50b00000c4e0: ref=1
22:12:25.019963: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0: TRANSPORT_STATE_IDLE -> TRANSPORT_STATE_REQUESTING
22:12:25.019989: profiles/audio/transport.c:media_request_create() Request created: method=Acquire id=1
22:12:25.020006: profiles/audio/transport.c:media_owner_add() Owner :1.712 Request Acquire
22:12:25.020019: profiles/audio/transport.c:media_transport_set_owner() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0 Owner :1.712
22:12:25.119349: [:1.712:method_call] > org.bluez.BatteryProviderManager1.RegisterBatteryProvider [#38]
22:12:25.119384: src/battery.c:register_battery_provider() register battery provider path = /org/freedesktop/pipewire/battery
22:12:25.119889: [org.freedesktop.DBus:method_call] < org.freedesktop.DBus.AddMatch
22:12:25.119922: [:1.712:method_return] < [#38]
22:12:25.119993: [:1.712:method_call] < org.freedesktop.DBus.ObjectManager.GetManagedObjects
22:12:25.134083: src/battery.c:btd_battery_register() path = /org/bluez/hci1/dev_B8_7B_D4_07_04_65
22:12:25.134144: src/battery.c:btd_battery_register() registered Battery object: /org/bluez/hci1/dev_B8_7B_D4_07_04_65
22:12:25.134161: src/battery.c:provided_battery_added_cb() provided battery added /org/freedesktop/pipewire/battery/org/bluez/hci1/dev_B8_7B_D4_07_04_65
22:12:25.134177: src/battery.c:btd_battery_update() path = /org/bluez/hci1/dev_B8_7B_D4_07_04_65
22:12:25.134341: [signal] org.freedesktop.DBus.ObjectManager.InterfacesAdded
22:12:25.135316: [:1.25:method_call] > org.freedesktop.DBus.Properties.GetAll [#556]
22:12:25.135391: [:1.25:method_return] < [#556]
22:12:25.136316: [:1.25:method_call] > org.freedesktop.DBus.Properties.GetAll [#563]
22:12:25.136348: [:1.25:method_return] < [#563]
22:12:25.345298: [:1.712:method_call] > org.bluez.MediaTransport1.Release [#41]
22:12:25.345341: profiles/audio/transport.c:release() Owner :1.712
22:12:25.345369: profiles/audio/transport.c:media_request_reply() Request Acquire Reply Operation canceled
22:12:25.345429: [:1.712:error] < org.bluez.Error.Failed [#37]
22:12:25.345472: profiles/audio/transport.c:media_owner_remove() Owner :1.712 Request Acquire
22:12:25.345511: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0: TRANSPORT_STATE_REQUESTING -> TRANSPORT_STATE_SUSPENDING
22:12:25.345562: profiles/audio/transport.c:media_transport_suspend() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0 Owner :1.712
22:12:25.345582: profiles/audio/transport.c:media_request_create() Request created: method=Release id=1
22:12:25.345617: profiles/audio/transport.c:media_owner_add() Owner :1.712 Request Release
22:12:25.345875: [signal] org.freedesktop.DBus.Properties.PropertiesChanged
22:12:26.921547: profiles/audio/avdtp.c:session_cb()
22:12:26.921609: profiles/audio/avdtp.c:avdtp_parse_resp() START request succeeded
22:12:26.921631: profiles/audio/a2dp.c:start_cfm() Source 0x506000047f60: Start_Cfm
22:12:26.921650: profiles/audio/transport.c:a2dp_resume_complete() cancel resume
22:12:26.921687: profiles/audio/a2dp.c:setup_unref() 0x50b00000c4e0: ref=0
22:12:26.921703: profiles/audio/a2dp.c:setup_free() 0x50b00000c4e0
22:12:26.921721: profiles/audio/avdtp.c:avdtp_unref() 0x51d00001e080: ref=2
22:12:26.921745: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: OPEN -> STREAMING
22:12:26.921768: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65: SINK_STATE_CONNECTED -> SINK_STATE_PLAYING
22:12:26.921787: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0 State=TRANSPORT_STATE_SUSPENDING Playing=1
22:12:26.921856: profiles/audio/avdtp.c:avdtp_ref() 0x51d00001e080: ref=3
22:12:26.921876: profiles/audio/a2dp.c:setup_ref() 0x50b000041280: ref=1
22:12:27.005487: profiles/audio/avdtp.c:session_cb()
22:12:27.005555: profiles/audio/avdtp.c:avdtp_parse_resp() SUSPEND request succeeded
22:12:27.005592: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: STREAMING -> OPEN
22:12:27.005643: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65: SINK_STATE_PLAYING -> SINK_STATE_CONNECTED
22:12:27.005678: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0 State=TRANSPORT_STATE_SUSPENDING Playing=0
22:12:27.005717: profiles/audio/a2dp.c:suspend_cfm() Source 0x506000047f60: Suspend_Cfm
22:12:27.005760: profiles/audio/transport.c:media_request_reply() Request Release Reply Success
22:12:27.005836: [:1.712:method_return] < [#41]
22:12:27.005903: profiles/audio/transport.c:media_owner_remove() Owner :1.712 Request Release
22:12:27.005950: profiles/audio/a2dp.c:a2dp_sep_unlock() SEP 0x506000047f60 unlocked
22:12:27.005987: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0: TRANSPORT_STATE_SUSPENDING -> TRANSPORT_STATE_IDLE
22:12:27.006079: profiles/audio/transport.c:media_transport_remove_owner() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/fd0 Owner :1.712
22:12:27.006142: profiles/audio/transport.c:media_owner_free() Owner :1.712
22:12:27.006184: profiles/audio/a2dp.c:setup_unref() 0x50b000041280: ref=0
22:12:27.006215: profiles/audio/a2dp.c:setup_free() 0x50b000041280
22:12:27.006271: profiles/audio/avdtp.c:avdtp_unref() 0x51d00001e080: ref=2
----------------------------------------------------------

Log: Acquire() -> canceled by Release() -> Acquire()
----------------------------------------------------------
The second Acquire is rejected, and transport is suspended.
The behavior of rejecting Acquire() while there is another ongoing
operation is same as before this patch.

21:35:25.437755: [:1.635:method_call] > org.bluez.MediaTransport1.Acquire [#49]
21:35:25.437786: profiles/audio/transport.c:media_owner_create() Owner created: sender=:1.635
21:35:25.437804: profiles/audio/transport.c:media_transport_resume() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0 Owner :1.635
21:35:25.437820: profiles/audio/a2dp.c:a2dp_sep_lock() SEP 0x506000048020 locked
21:35:25.437838: profiles/audio/avdtp.c:avdtp_ref() 0x51d00001ea80: ref=3
21:35:25.437855: profiles/audio/a2dp.c:setup_ref() 0x50b000040af0: ref=1
21:35:30.438045: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0: TRANSPORT_STATE_IDLE -> TRANSPORT_STATE_REQUESTING
21:35:30.438114: profiles/audio/transport.c:media_request_create() Request created: method=Acquire id=13
21:35:30.438150: profiles/audio/transport.c:media_owner_add() Owner :1.635 Request Acquire
21:35:30.438182: profiles/audio/transport.c:media_transport_set_owner() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0 Owner :1.635
21:35:30.438622: [:1.635:method_call] > org.bluez.MediaTransport1.Release [#50]
21:35:30.438667: profiles/audio/transport.c:release() Owner :1.635
21:35:30.438703: profiles/audio/transport.c:media_request_reply() Request Acquire Reply Operation canceled
21:35:30.438823: [:1.635:error] < org.bluez.Error.Failed [#49]
21:35:30.438885: profiles/audio/transport.c:media_owner_remove() Owner :1.635 Request Acquire
21:35:30.438929: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0: TRANSPORT_STATE_REQUESTING -> TRANSPORT_STATE_SUSPENDING
21:35:30.439042: profiles/audio/transport.c:media_transport_suspend() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0 Owner :1.635
21:35:30.439082: profiles/audio/transport.c:media_request_create() Request created: method=Release id=13
21:35:30.439115: profiles/audio/transport.c:media_owner_add() Owner :1.635 Request Release
21:35:30.439178: [:1.635:method_call] > org.bluez.MediaTransport1.Acquire [#51]
21:35:30.439436: [signal] org.freedesktop.DBus.Properties.PropertiesChanged
21:35:30.439509: [:1.635:error] < org.bluez.Error.NotAuthorized [#51]
21:35:30.580542: profiles/audio/avdtp.c:session_cb()
21:35:30.580637: profiles/audio/avdtp.c:avdtp_parse_resp() START request succeeded
21:35:30.580691: profiles/audio/a2dp.c:start_cfm() Source 0x506000048020: Start_Cfm
21:35:30.580723: profiles/audio/transport.c:a2dp_resume_complete() cancel resume
21:35:30.580772: profiles/audio/a2dp.c:setup_unref() 0x50b000040af0: ref=0
21:35:30.580801: profiles/audio/a2dp.c:setup_free() 0x50b000040af0
21:35:30.580832: profiles/audio/avdtp.c:avdtp_unref() 0x51d00001ea80: ref=2
21:35:30.580866: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: OPEN -> STREAMING
21:35:30.580902: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65: SINK_STATE_CONNECTED -> SINK_STATE_PLAYING
21:35:30.580935: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0 State=TRANSPORT_STATE_SUSPENDING Playing=1
21:35:30.581091: profiles/audio/avdtp.c:avdtp_ref() 0x51d00001ea80: ref=3
21:35:30.581142: profiles/audio/a2dp.c:setup_ref() 0x50b0000413e0: ref=1
21:35:30.656521: profiles/audio/avdtp.c:session_cb()
21:35:30.656583: profiles/audio/avdtp.c:avdtp_parse_resp() SUSPEND request succeeded
21:35:30.656617: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: STREAMING -> OPEN
21:35:30.656652: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65: SINK_STATE_PLAYING -> SINK_STATE_CONNECTED
21:35:30.656684: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0 State=TRANSPORT_STATE_SUSPENDING Playing=0
21:35:30.656717: profiles/audio/a2dp.c:suspend_cfm() Source 0x506000048020: Suspend_Cfm
21:35:30.656756: profiles/audio/transport.c:media_request_reply() Request Release Reply Success
21:35:30.656819: [:1.635:method_return] < [#50]
21:35:30.656878: profiles/audio/transport.c:media_owner_remove() Owner :1.635 Request Release
21:35:30.656915: profiles/audio/a2dp.c:a2dp_sep_unlock() SEP 0x506000048020 unlocked
21:35:30.656949: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0: TRANSPORT_STATE_SUSPENDING -> TRANSPORT_STATE_IDLE
21:35:30.657024: profiles/audio/transport.c:media_transport_remove_owner() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd0 Owner :1.635
21:35:30.657076: profiles/audio/transport.c:media_owner_free() Owner :1.635
21:35:30.657110: profiles/audio/a2dp.c:setup_unref() 0x50b0000413e0: ref=0
21:35:30.657139: profiles/audio/a2dp.c:setup_free() 0x50b0000413e0
21:35:30.657169: profiles/audio/avdtp.c:avdtp_unref() 0x51d00001ea80: ref=2
----------------------------------------------------------

Log: Acquire() -> canceled by Release() -> canceled by SetConfiguration()
----------------------------------------------------------
This works, and results to transport being configured successfully.

In this log, the timing to hit the races was achieved by adding sleep(5)
in avdtp_start() + making Pipewire not wait for Release().

21:07:38.716895: [:1.607:method_call] > org.bluez.MediaTransport1.Acquire [#36]
21:07:38.716930: profiles/audio/transport.c:media_owner_create() Owner created: sender=:1.607
21:07:38.716947: profiles/audio/transport.c:media_transport_resume() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2 Owner :1.607
21:07:38.716974: profiles/audio/avdtp.c:avdtp_ref() 0x51d000020880: ref=2
21:07:38.716990: profiles/audio/a2dp.c:a2dp_sep_lock() SEP 0x506000040580 locked
21:07:38.717005: profiles/audio/avdtp.c:avdtp_ref() 0x51d000020880: ref=3
21:07:38.717033: profiles/audio/a2dp.c:setup_ref() 0x50b000041f90: ref=1
21:07:43.717234: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2: TRANSPORT_STATE_IDLE -> TRANSPORT_STATE_REQUESTING
21:07:43.717301: profiles/audio/transport.c:media_request_create() Request created: method=Acquire id=5
21:07:43.717333: profiles/audio/transport.c:media_owner_add() Owner :1.607 Request Acquire
21:07:43.717369: profiles/audio/transport.c:media_transport_set_owner() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2 Owner :1.607
21:07:43.717770: [:1.607:method_call] > org.bluez.MediaTransport1.Release [#37]
21:07:43.717800: profiles/audio/transport.c:release() Owner :1.607
21:07:43.717825: profiles/audio/transport.c:media_request_reply() Request Acquire Reply Operation canceled
21:07:43.717898: [:1.607:error] < org.bluez.Error.Failed [#36]
21:07:43.717937: profiles/audio/transport.c:media_owner_remove() Owner :1.607 Request Acquire
21:07:43.717977: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2: TRANSPORT_STATE_REQUESTING -> TRANSPORT_STATE_SUSPENDING
21:07:43.718012: profiles/audio/transport.c:media_transport_suspend() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2 Owner :1.607
21:07:43.718027: profiles/audio/transport.c:media_request_create() Request created: method=Release id=5
21:07:43.718038: profiles/audio/transport.c:media_owner_add() Owner :1.607 Request Release
21:07:43.718076: [:1.607:method_call] > org.bluez.MediaEndpoint1.SetConfiguration [#38]
21:07:43.718118: profiles/audio/a2dp.c:setup_ref() 0x50b000041f90: ref=2
21:07:43.718316: [signal] org.freedesktop.DBus.Properties.PropertiesChanged
21:07:44.184499: profiles/audio/avdtp.c:session_cb()
21:07:44.184565: profiles/audio/avdtp.c:avdtp_parse_resp() START request succeeded
21:07:44.184603: profiles/audio/a2dp.c:start_cfm() Source 0x506000040580: Start_Cfm
21:07:44.184624: profiles/audio/transport.c:a2dp_resume_complete() cancel resume
21:07:44.184659: profiles/audio/a2dp.c:setup_unref() 0x50b000041f90: ref=1
21:07:44.184681: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: OPEN -> STREAMING
21:07:44.184705: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65: SINK_STATE_CONNECTED -> SINK_STATE_PLAYING
21:07:44.184725: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2 State=TRANSPORT_STATE_SUSPENDING Playing=1
21:07:44.184854: profiles/audio/a2dp.c:setup_ref() 0x50b000041f90: ref=2
21:07:44.184909: profiles/audio/a2dp.c:setup_unref() 0x50b000041f90: ref=1
21:07:44.184930: profiles/audio/transport.c:media_transport_remove_owner() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2 Owner :1.607
21:07:44.184956: profiles/audio/transport.c:media_request_reply() Request Release Reply Input/output error
21:07:44.185019: [:1.607:error] < org.bluez.Error.Failed [#37]
21:07:44.185088: profiles/audio/transport.c:media_owner_free() Owner :1.607
21:07:44.185106: profiles/audio/transport.c:media_owner_remove() Owner :1.607 Request Release
21:07:44.185134: profiles/audio/transport.c:media_transport_suspend() Transport /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2 Owner
21:07:44.185152: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep2/fd2: TRANSPORT_STATE_SUSPENDING -> TRANSPORT_STATE_IDLE
21:07:44.185213: profiles/audio/a2dp.c:a2dp_sep_unlock() SEP 0x506000040580 unlocked
21:07:44.185409: [signal] org.freedesktop.DBus.Properties.PropertiesChanged
21:07:44.228552: profiles/audio/avdtp.c:session_cb()
21:07:44.228612: profiles/audio/avdtp.c:avdtp_parse_resp() CLOSE request succeeded
21:07:44.228631: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: STREAMING -> CLOSING
21:07:44.228737: profiles/audio/a2dp.c:close_cfm() Source 0x506000040580: Close_Cfm
21:07:44.228758: profiles/audio/a2dp.c:setup_reconfigure() 0x50b000041f90
21:07:44.228780: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: CLOSING -> IDLE
21:07:44.228848: [:1.607:method_call] < org.bluez.MediaEndpoint1.ClearConfiguration
21:07:44.228944: profiles/audio/avdtp.c:avdtp_unref() 0x51d000020880: ref=2
21:07:44.229227: [signal] org.freedesktop.DBus.ObjectManager.InterfacesRemoved
21:07:44.229318: src/service.c:change_state() 0x504000036550: device B8:7B:D4:07:04:65 profile a2dp-sink state changed: connected -> disconnected (0)
21:07:44.229349: plugins/policy.c:policy_disconnect() /org/bluez/hci1/dev_B8_7B_D4_07_04_65 profile avrcp-controller
21:07:44.229370: src/service.c:change_state() 0x504000036590: device B8:7B:D4:07:04:65 profile avrcp-controller state changed: connected -> disconnecting (0)
21:07:44.229390: profiles/audio/avrcp.c:avrcp_disconnect() path /org/bluez/hci1/dev_B8_7B_D4_07_04_65
21:07:44.229433: src/service.c:change_state() 0x504000036690: device B8:7B:D4:07:04:65 profile audio-avrcp-target state changed: connected -> disconnected (0)
21:07:44.229472: src/service.c:change_state() 0x504000036590: device B8:7B:D4:07:04:65 profile avrcp-controller state changed: disconnecting -> disconnected (0)
21:07:44.229504: profiles/audio/avrcp.c:controller_destroy() 0x503000096220
21:07:44.229532: profiles/audio/avrcp.c:target_destroy() 0x5030000963a0
21:07:44.229623: profiles/audio/avctp.c:avctp_set_state() AVCTP Disconnected
21:07:44.229711: profiles/audio/avctp.c:avctp_disconnected() AVCTP: closing uinput for B8:7B:D4:07:04:65
21:07:44.253516: profiles/audio/avdtp.c:avdtp_unref() 0x51d000020880: ref=1
21:07:44.253781: [signal] org.freedesktop.DBus.Properties.PropertiesChanged
21:07:44.729455: profiles/audio/avdtp.c:avdtp_set_configuration() 0x51d000020880: int_seid=13, acp_seid=1
21:07:44.855438: profiles/audio/avdtp.c:session_cb()
21:07:44.855495: profiles/audio/avdtp.c:avdtp_parse_resp() SET_CONFIGURATION request succeeded
21:07:44.855516: profiles/audio/a2dp.c:setconf_cfm() Source 0x506000041300: Set_Configuration_Cfm
21:07:44.855544: profiles/audio/avdtp.c:avdtp_ref() 0x51d000020880: ref=2
21:07:44.855566: profiles/audio/a2dp.c:setup_ref() 0x50b000041f90: ref=2
21:07:44.855921: [signal] org.freedesktop.DBus.ObjectManager.InterfacesAdded
21:07:44.856004: [:1.607:method_call] < org.bluez.MediaEndpoint1.SetConfiguration
21:07:44.856045: profiles/audio/media.c:media_endpoint_async_call() Calling SetConfiguration: name = :1.607 path = /MediaEndpoint/A2DPSource/sbc
21:07:44.856067: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: IDLE -> CONFIGURED
21:07:44.857056: profiles/audio/a2dp.c:setup_unref() 0x50b000041f90: ref=1
21:07:44.860524: profiles/audio/avdtp.c:session_cb()
21:07:44.860643: profiles/audio/avdtp.c:avdtp_parse_cmd() Received DELAY_REPORT_CMD
21:07:44.860730: profiles/audio/a2dp.c:endpoint_delayreport_ind() Source 0x506000041300: DelayReport_Ind
21:07:44.861171: [signal] org.freedesktop.DBus.Properties.PropertiesChanged
21:07:44.950548: profiles/audio/avdtp.c:session_cb()
21:07:44.950612: profiles/audio/avdtp.c:avdtp_parse_resp() OPEN request succeeded
21:07:45.175581: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP: connected transport channel to B8:7B:D4:07:04:65
21:07:45.175639: profiles/audio/avdtp.c:handle_transport_connect() Flushable packets enabled
21:07:45.175661: profiles/audio/avdtp.c:handle_transport_connect() sk 60, omtu 679, send buffer size 106496
21:07:45.175681: profiles/audio/a2dp.c:open_cfm() Source 0x506000041300: Open_Cfm
21:07:45.183071: [:1.607:method_return] < [#38]
21:07:45.183123: profiles/audio/a2dp.c:setup_unref() 0x50b000041f90: ref=0
21:07:45.183143: profiles/audio/a2dp.c:setup_free() 0x50b000041f90
21:07:45.183162: profiles/audio/avdtp.c:avdtp_unref() 0x51d000020880: ref=1
21:07:45.183184: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: CONFIGURED -> OPEN
21:07:45.183212: src/service.c:change_state() 0x504000036550: device B8:7B:D4:07:04:65 profile a2dp-sink state changed: disconnected -> connected (0)
21:07:45.183251: plugins/policy.c:service_cb() Added a2dp-sink reconnect 1
21:07:45.183271: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci1/dev_B8_7B_D4_07_04_65: SINK_STATE_PLAYING -> SINK_STATE_CONNECTED
21:07:45.183301: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci1/dev_B8_7B_D4_07_04_65/sep1/fd3 State=TRANSPORT_STATE_IDLE Playing=0
----------------------------------------------------------

Pauli Virtanen (2):
  transport: don't disconnect A2DP if canceling Acquire() with Release()
  a2dp: don't change setup sep when it is reconfiguring

 profiles/audio/a2dp.c      |   6 ++
 profiles/audio/transport.c | 179 ++++++++++++++++++++++++++++---------
 2 files changed, 143 insertions(+), 42 deletions(-)

Comments

patchwork-bot+bluetooth@kernel.org Nov. 4, 2024, 6:30 p.m. UTC | #1 
Hello:

This series was applied to bluetooth/bluez.git (master)
by Luiz Augusto von Dentz <luiz.von.dentz@intel.com>:

On Sat,  2 Nov 2024 22:29:44 +0200 you wrote:
> User can cancel transport acquire by calling Release() while Acquire()
> is in progress. This calls a2dp_cancel() which sends AVDTP_ABORT_CMD,
> forcing AVDTP state transition to IDLE, and A2DP profile disconnects.
> 
> However, Release()/Acquire() should only result to transitions between
> STREAMING/OPEN.  The expected behavior is that either these calls return
> error, or they block until the target state is reached.
> 
> [...]

Here is the summary with links:
  - [BlueZ,v2,1/2] transport: don't disconnect A2DP if canceling Acquire() with Release()
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=a14d59725ef3
  - [BlueZ,v2,2/2] a2dp: don't change setup sep when it is reconfiguring
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=664a5d3785a1

You are awesome, thank you!