Discussion:
[pulseaudio-discuss] Failure to connect Sony headsets
João Paulo Rechi Vita
2018-06-14 07:05:06 UTC
Permalink
Hello Luiz and Tanuk,

I have been trying to understand a problem when trying to establish a
connection between my Sony MW-600 headset and my laptop (PulseAudio
11.1 + a backport that gives higher priority to A2DP, BlueZ 5.47,
Linux 4.16.9). When the connection is initiated by the peripheral,
after it has already been paired on a previous connection, the
peripheral does not remain connected. When the computer initiates the
connection everything works fine. The problem seems to be that when we
create the card in PulseAudio is created before the AVDTP connection
reaches the OPEN state, the headset decides to abort the AVDTP
connection. In this case the card was created before the transport for
the card profile a2dp_sink is available and headset_head_unit was the
active profile, because WAIT_FOR_PROFILES_TIMEOUT_USEC was reached.

Increasing the timeout to 60s makes the problem go away. The AVDTP
channel becomes connected about 50s after the HSP connection has
started and the card is created with a2dp_sink as the active profile.
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.

I have collected btmon dumps with a slightly modified version of btmon
to avoid flooding the logs with SCO data and uploaded to
https://gist.github.com/jprvita/a7482db4601d099788c4f820ea984ba9.

Similar symptoms have been reported by our QA team with another Sony
model (MDR-XB950N1) and with a few Chinese headsets, but the MW-600 is
the only one I have access to where I can reproduce the problem
consistently (works fine on a Sennheiser MM-450 and a JBL Flip 2).

Also, the involvement of module-card-restore in this problem made me
think whether it actually makes sense to restore the active profile
from the previous connection on bluetooth cards, since we already have
module-bluetooth-policy to automatically select the right profile
depending on the stream type.

Please let me know if you can help me understand what is making the
headset decide to disconnect AVDTP in these cases, and what is the
best way to fix this, or any ideas that may help investigating this
further.

Thanks!

--
João Paulo Rechi Vita
http://about.me/jprvita
Tanu Kaskinen
2018-06-14 11:57:48 UTC
Permalink
Post by João Paulo Rechi Vita
Hello Luiz and Tanuk,
I have been trying to understand a problem when trying to establish a
connection between my Sony MW-600 headset and my laptop (PulseAudio
11.1 + a backport that gives higher priority to A2DP, BlueZ 5.47,
Linux 4.16.9). When the connection is initiated by the peripheral,
after it has already been paired on a previous connection, the
peripheral does not remain connected. When the computer initiates the
connection everything works fine. The problem seems to be that when we
create the card in PulseAudio is created before the AVDTP connection
reaches the OPEN state, the headset decides to abort the AVDTP
connection. In this case the card was created before the transport for
the card profile a2dp_sink is available and headset_head_unit was the
active profile, because WAIT_FOR_PROFILES_TIMEOUT_USEC was reached.
Increasing the timeout to 60s makes the problem go away. The AVDTP
channel becomes connected about 50s after the HSP connection has
started and the card is created with a2dp_sink as the active profile.
Maybe we could increase the timeout. A long timeout doesn't matter with
properly working hardware, because the wait is terminated as soon as
all advertised profiles have become connected.
Post by João Paulo Rechi Vita
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.
This is without increasing the timeout, right, so the problem is that
module-card-restore is trying to restore a2dp_sink before it's
available? module-card-restore has been fixed to not to try to restore
unavailable profiles:
https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=d65974d8501052bafb03e65f5df954511e9949a2
Post by João Paulo Rechi Vita
I have collected btmon dumps with a slightly modified version of btmon
to avoid flooding the logs with SCO data and uploaded to
https://gist.github.com/jprvita/a7482db4601d099788c4f820ea984ba9.
Similar symptoms have been reported by our QA team with another Sony
model (MDR-XB950N1) and with a few Chinese headsets, but the MW-600 is
the only one I have access to where I can reproduce the problem
consistently (works fine on a Sennheiser MM-450 and a JBL Flip 2).
Also, the involvement of module-card-restore in this problem made me
think whether it actually makes sense to restore the active profile
from the previous connection on bluetooth cards, since we already have
module-bluetooth-policy to automatically select the right profile
depending on the stream type.
If module-bluetooth-policy is sufficient, then module-card-restore
won't do anything anyway, because you never set the profile manually.
If you ever set the profile manually, that's an indication that module-
bluetooth-policy isn't always good enough.
Post by João Paulo Rechi Vita
Please let me know if you can help me understand what is making the
headset decide to disconnect AVDTP in these cases, and what is the
best way to fix this, or any ideas that may help investigating this
further.
This is outside of my area of expertise. Could you just clarify one
thing: did I understand correctly that if you increase the profile
waiting timeout, then the headset doesn't disconnect AVDTP? So
everything works perfectly, except that the connection takes a very
long time?
--
Tanu

https://liberapay.com/tanuk
https://www.patreon.com/tanuk
João Paulo Rechi Vita
2018-06-14 15:05:21 UTC
Permalink
Hello Tanu!
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
Hello Luiz and Tanuk,
I have been trying to understand a problem when trying to establish a
connection between my Sony MW-600 headset and my laptop (PulseAudio
11.1 + a backport that gives higher priority to A2DP, BlueZ 5.47,
Linux 4.16.9). When the connection is initiated by the peripheral,
after it has already been paired on a previous connection, the
peripheral does not remain connected. When the computer initiates the
connection everything works fine. The problem seems to be that when we
create the card in PulseAudio is created before the AVDTP connection
reaches the OPEN state, the headset decides to abort the AVDTP
connection. In this case the card was created before the transport for
the card profile a2dp_sink is available and headset_head_unit was the
active profile, because WAIT_FOR_PROFILES_TIMEOUT_USEC was reached.
Increasing the timeout to 60s makes the problem go away. The AVDTP
channel becomes connected about 50s after the HSP connection has
started and the card is created with a2dp_sink as the active profile.
Maybe we could increase the timeout. A long timeout doesn't matter with
properly working hardware, because the wait is terminated as soon as
all advertised profiles have become connected.
Yes, I thought about it, but first I wanted to hear from Luiz (who
knows the audio specs inside out) if something in this flow might be
hitting the headset to terminate the connection, and if we could
improve it. I'm wondering iif the fact that creating the sink/source
right away, which leads to the SCO channel being established, is what
is making the headset decide it should disconnect A2DP. But I still
don't understand why the headset would also disconnect the RFCOMM link
(changing the transport in PulseAudio from idle to disconnected) after
we change the transport from playing to idle and release the SCO fd
when the sink/source get suspended (in my experience, this only
happens if A2DP is also not connected due to the failure mentioned
above).
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.
This is without increasing the timeout, right, so the problem is that
module-card-restore is trying to restore a2dp_sink before it's
available? module-card-restore has been fixed to not to try to restore
https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=d65974d8501052bafb03e65f5df954511e9949a2
No, this is in addition to increasing the timeout. To have things
working I need to increase the timeout AND disable
module-card-restore. Sorry for not being clear about it before.

I will try the commit you pointed, but I don't think it will help
since, if I'm following this right, the transport is already marked as
available at this point (I need to double-check on this point though
-- sorry, too many moving parts).
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
I have collected btmon dumps with a slightly modified version of btmon
to avoid flooding the logs with SCO data and uploaded to
https://gist.github.com/jprvita/a7482db4601d099788c4f820ea984ba9.
Similar symptoms have been reported by our QA team with another Sony
model (MDR-XB950N1) and with a few Chinese headsets, but the MW-600 is
the only one I have access to where I can reproduce the problem
consistently (works fine on a Sennheiser MM-450 and a JBL Flip 2).
Also, the involvement of module-card-restore in this problem made me
think whether it actually makes sense to restore the active profile
from the previous connection on bluetooth cards, since we already have
module-bluetooth-policy to automatically select the right profile
depending on the stream type.
If module-bluetooth-policy is sufficient, then module-card-restore
won't do anything anyway, because you never set the profile manually.
If you ever set the profile manually, that's an indication that module-
bluetooth-policy isn't always good enough.
I agree with the theory behind this argument, but in practice most
users will switch from HSP/HFP to A2DP after the first connection,
since it has higher priority until PulseAudio 11. So there will be an
entry for it in module-card-restore's DB, which I believe does not get
removed when the user "un-pairs" the headset and the computer.
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
Please let me know if you can help me understand what is making the
headset decide to disconnect AVDTP in these cases, and what is the
best way to fix this, or any ideas that may help investigating this
further.
This is outside of my area of expertise. Could you just clarify one
thing: did I understand correctly that if you increase the profile
waiting timeout, then the headset doesn't disconnect AVDTP? So
everything works perfectly, except that the connection takes a very
long time?
If I increase the timeout AND disable module-bluetooth-restore,
everything works as expected except that it takes 50-60s for the audio
card to appear after turning the headset on.

Thanks for the help!

--
João Paulo Rechi Vita
http://about.me/jprvita
Tanu Kaskinen
2018-06-14 15:27:49 UTC
Permalink
Post by João Paulo Rechi Vita
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.
This is without increasing the timeout, right, so the problem is that
module-card-restore is trying to restore a2dp_sink before it's
available? module-card-restore has been fixed to not to try to restore
https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=d65974d8501052bafb03e65f5df954511e9949a2
No, this is in addition to increasing the timeout. To have things
working I need to increase the timeout AND disable
module-card-restore. Sorry for not being clear about it before.
I will try the commit you pointed, but I don't think it will help
since, if I'm following this right, the transport is already marked as
available at this point (I need to double-check on this point though
-- sorry, too many moving parts).
If you confirm that module-card-restore indeed has to be disabled even
with the increased timeout, then it would be very interesting to know
what effect module-card-restore has in the card initialization. To me
it seems that it should make no difference, because the a2dp profile is
the default anyway, and all the module does is to choose the initial
profile.
--
Tanu

https://liberapay.com/tanuk
https://www.patreon.com/tanuk
João Paulo Rechi Vita
2018-06-14 23:33:48 UTC
Permalink
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.
This is without increasing the timeout, right, so the problem is that
module-card-restore is trying to restore a2dp_sink before it's
available? module-card-restore has been fixed to not to try to restore
https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=d65974d8501052bafb03e65f5df954511e9949a2
No, this is in addition to increasing the timeout. To have things
working I need to increase the timeout AND disable
module-card-restore. Sorry for not being clear about it before.
I will try the commit you pointed, but I don't think it will help
since, if I'm following this right, the transport is already marked as
available at this point (I need to double-check on this point though
-- sorry, too many moving parts).
If you confirm that module-card-restore indeed has to be disabled even
with the increased timeout, then it would be very interesting to know
what effect module-card-restore has in the card initialization. To me
it seems that it should make no difference, because the a2dp profile is
the default anyway, and all the module does is to choose the initial
profile.
Ok, I have done more testing focusing on this specific point and
confirmed we indeed don't need to disable module-card-restore. With
the 60s timeout the headset was able to connect successfully 6 times
in a row. So for now the only open point is if there is any better fix
for these headsets than increasing the timeout.

--
João Paulo Rechi Vita
http://about.me/jprvita
Luiz Augusto von Dentz
2018-06-20 14:47:46 UTC
Permalink
Hi Joao,

On Fri, Jun 15, 2018 at 2:33 AM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.
This is without increasing the timeout, right, so the problem is that
module-card-restore is trying to restore a2dp_sink before it's
available? module-card-restore has been fixed to not to try to restore
https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=d65974d8501052bafb03e65f5df954511e9949a2
No, this is in addition to increasing the timeout. To have things
working I need to increase the timeout AND disable
module-card-restore. Sorry for not being clear about it before.
I will try the commit you pointed, but I don't think it will help
since, if I'm following this right, the transport is already marked as
available at this point (I need to double-check on this point though
-- sorry, too many moving parts).
If you confirm that module-card-restore indeed has to be disabled even
with the increased timeout, then it would be very interesting to know
what effect module-card-restore has in the card initialization. To me
it seems that it should make no difference, because the a2dp profile is
the default anyway, and all the module does is to choose the initial
profile.
Ok, I have done more testing focusing on this specific point and
confirmed we indeed don't need to disable module-card-restore. With
the 60s timeout the headset was able to connect successfully 6 times
in a row. So for now the only open point is if there is any better fix
for these headsets than increasing the timeout.
Im trying to reproduce this with sony sbh50 but apparently it doesn't
have the same problem as it worked just fine, one thing I notice
though is that HFP does not connect:

https://gist.github.com/Vudentz/6f385ededcb00d1d0f4403f06923fd1a

As you can see locally we only support HSP which means there is no
match for MFP, but perhaps you are running with oFono? Anyway I should
have an mw600 somewhere but that is quite old already, but you
mentioned it did not work with MDR-XB950N1 which is quite new model?
Anyway if you can gather some logs of bluetoothd that would be useful
to identify where is the problem.
Post by João Paulo Rechi Vita
--
João Paulo Rechi Vita
http://about.me/jprvita
--
Luiz Augusto von Dentz
Luiz Augusto von Dentz
2018-06-21 10:27:59 UTC
Permalink
Hi Joao,

On Wed, Jun 20, 2018 at 5:47 PM, Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Hi Joao,
On Fri, Jun 15, 2018 at 2:33 AM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
Post by Tanu Kaskinen
Post by João Paulo Rechi Vita
I also had to disable module-card-restore, otherwise it tries to
switch to the saved a2dp_sink profile right when the card is created,
which also makes the device abort the AVDTP connection for some
reason.
This is without increasing the timeout, right, so the problem is that
module-card-restore is trying to restore a2dp_sink before it's
available? module-card-restore has been fixed to not to try to restore
https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=d65974d8501052bafb03e65f5df954511e9949a2
No, this is in addition to increasing the timeout. To have things
working I need to increase the timeout AND disable
module-card-restore. Sorry for not being clear about it before.
I will try the commit you pointed, but I don't think it will help
since, if I'm following this right, the transport is already marked as
available at this point (I need to double-check on this point though
-- sorry, too many moving parts).
If you confirm that module-card-restore indeed has to be disabled even
with the increased timeout, then it would be very interesting to know
what effect module-card-restore has in the card initialization. To me
it seems that it should make no difference, because the a2dp profile is
the default anyway, and all the module does is to choose the initial
profile.
Ok, I have done more testing focusing on this specific point and
confirmed we indeed don't need to disable module-card-restore. With
the 60s timeout the headset was able to connect successfully 6 times
in a row. So for now the only open point is if there is any better fix
for these headsets than increasing the timeout.
Im trying to reproduce this with sony sbh50 but apparently it doesn't
have the same problem as it worked just fine, one thing I notice
https://gist.github.com/Vudentz/6f385ededcb00d1d0f4403f06923fd1a
As you can see locally we only support HSP which means there is no
match for MFP, but perhaps you are running with oFono? Anyway I should
have an mw600 somewhere but that is quite old already, but you
mentioned it did not work with MDR-XB950N1 which is quite new model?
Anyway if you can gather some logs of bluetoothd that would be useful
to identify where is the problem.
Managed to reproduce the issue, if I recall correctly MW600 don't like
that SCO is open before A2DP is configured which is caused by:


/* Ignore card if has already set other initial profile than a2dp */
if (card->active_profile &&
!pa_streq(card->active_profile->name, "a2dp") &&
!pa_streq(card->active_profile->name, "a2dp_sink"))
return PA_HOOK_OK;

/* Set initial profile to hsp */
card_set_profile(u, card, false);

If I get it correctly the first if statement will not return in case
of A2DP, which basically negates restored profile?, and then it sets
HSP which I find to be the opposite of what we should be doing except
if there already an stream tagged with voice otherwise we shall really
prefer A2DP.
--
Luiz Augusto von Dentz
João Paulo Rechi Vita
2018-06-21 19:21:27 UTC
Permalink
Hello Luiz,

On Thu, Jun 21, 2018 at 3:27 AM, Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Im trying to reproduce this with sony sbh50 but apparently it doesn't
have the same problem as it worked just fine, one thing I notice
https://gist.github.com/Vudentz/6f385ededcb00d1d0f4403f06923fd1a
As you can see locally we only support HSP which means there is no
match for MFP, but perhaps you are running with oFono? Anyway I should
have an mw600 somewhere but that is quite old already, but you
mentioned it did not work with MDR-XB950N1 which is quite new model?
Sorry, I forgot to mention: I was not running oFono, so only
PulseAudio's HSP implementation was registered with bluetoothd. I
personally have only been able to reproduce this problem on the Sony
MW-600, from the headsets I have access to. Our QA team at Endless
have seen similar symptoms on the Sony MDR-XB950N1, AMP Pulse BXH-300,
Intopic HM-BT001, and The Coopidea CP-TW-01. I have not able to
confirm 100% whether that is the exact same problem on all of them, as
I'm focusing on the MW-600 which is the one I have access to.
Post by Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Anyway if you can gather some logs of bluetoothd that would be useful
to identify where is the problem.
I've actually was not able to reproduce the exact same symptoms
yesterday: instead of the headset disconnecting A2DP and the card
being destroyed, the OFF profile ended up being selected. The
transport for HSP got available first, the card was created 3s
afterwards (due to WAIT_FOR_PROFILES_TIMEOUT_USEC being reached), but
a2dp actually got connected about 50s afterwards. Then after looking
into it for a while I realized a few extra things that I had not
noticed befofe. PulseAudio logs for this case can be seen right
bellow, and for the "disconnecting case" afterwards. I can still
collect bluetoothd logs if needed.

Notice that the "module-card-restore.c: Restoring profile X for card
Y" message is wrong, as this is from PulseAudio 11 plus some
backported patches, but it does not contain "card-restore: log the
correct profile name". I marked it on the logs bellow for attention.

1. OFF CASE

- org.bluez.Profile1.NewConnection() is called on PulseAudio's
HSPAGProfile object path:

Jun 20 17:09:11 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Properties changed in device /org/bluez/hci0/dev_58_17_0C_EA_02_89
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: dbus: path=/Profile/HSPAGProfile,
interface=org.bluez.Profile1, member=NewConnection
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: dbus: NewConnection
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89, fd=23, profile
headset_head_unit
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: doing listen
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 state:
disconnected -> idle
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
available for profile headset_head_unit
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLIP=1

- WAIT_FOR_PROFILES_TIMEOUT_USEC expires:

Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Timeout expired, and device /org/bluez/hci0/dev_58_17_0C_EA_02_89
still has disconnected profiles: a2dp_sink
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
module-bluez5-discover.c: Loading module-bluez5-device
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
module-card-restore.c: Restoring port latency offsets for card
bluez_card.58_17_0C_EA_02_89.
** wrong message here --> Jun 20 17:09:15 endless pulseaudio[899]:
[pulseaudio] module-card-restore.c: Restoring profile
'headset_head_unit' for card bluez_card.58_17_0C_EA_02_89.
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] card.c: Created
1 "bluez_card.58_17_0C_EA_02_89"
** and the following message indicates module-card-restore was trying
to restore a2dp_sink instead
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
module-bluez5-device.c: Profile a2dp_sink has no transport
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] card.c: Changed
profile of card 1 "bluez_card.58_17_0C_EA_02_89" to off
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] module.c: Loaded
"module-bluez5-device" (index: #25; argument:
"path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0").

- Now the card remains created and idle for a while, since its profile
has been set to OFF, except for some boring RFCOMM chat.

Jun 20 17:09:22 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CSCS="UTF-8"
Jun 20 17:09:32 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT*SEAM="MW600",13
Jun 20 17:09:42 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLAN?
Jun 20 17:09:52 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+COLP=1
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CCLK?

- Exact 50s after the NewConnection() call there is a
org.bluez.MediaTransport1.SetConfiguration() call on PulseAudio's
A2DPSource object path:

Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Unknown interface org.freedesktop.DBus.Introspectable found, skipping
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Unknown interface org.bluez.MediaTransport1 found, skippingJun 20
17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c: Unknown
interface org.freedesktop.DBus.Properties found, skipping
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
dbus: path=/MediaEndpoint/A2DPSource,
interface=org.bluez.MediaEndpoint1, member=SetConfiguration
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 state:
disconnected -> idle
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status unknown
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 available for
profile a2dp_sink
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Properties changed in transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 state: idle ->
playing
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status yes
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] device-port.c:
Setting port headset-output to status yes
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Properties changed in transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 state: playing ->
idle
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status unknown
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio] device-port.c:
Setting port headset-output to status unknown
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.

2. DISCONNECTING CASE (here I had WAIT_FOR_PROFILES_TIMEOUT_USEC=60s,
so it does not expire):

- org.bluez.Profile1.NewConnection() is called on PulseAudio's
HSPAGProfile object path:

Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Properties changed in device /org/bluez/hci0/dev_58_17_0C_EA_02_89
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: dbus: path=/Profile/HSPAGProfile,
interface=org.bluez.Profile1, member=NewConnection
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: dbus: NewConnection
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89, fd=23, profile
headset_head_unit
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: doing listen
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 state:
disconnected -> idle
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
available for profile headset_head_unit
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLIP=1
Jun 13 15:22:20 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CSCS="UTF-8"
Jun 13 15:22:30 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT*SEAM="MW600",13
Jun 13 15:22:40 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLAN?
Jun 13 15:22:50 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+COLP=1
Jun 13 15:23:00 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CCLK?

- Exact 51s after the NewConnection() call there is a
org.bluez.MediaTransport1.SetConfiguration() call on PulseAudio's
A2DPSource object path:

Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
dbus: path=/MediaEndpoint/A2DPSource,
interface=org.bluez.MediaEndpoint1, member=SetConfiguration
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 state:
disconnected -> idle
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluez5-discover.c: Loading module-bluez5-device
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-card-restore.c: Restoring port latency offsets for card
bluez_card.58_17_0C_EA_02_89.
** wrong message, it is restoring headset_head_unit --> Jun 13
15:23:01 endless pulseaudio[809]: [pulseaudio] module-card-restore.c:
Restoring profile 'a2dp_sink' for card bluez_card.58_17_0C_EA_02_89.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] card.c: Created
2 "bluez_card.58_17_0C_EA_02_89"

- SCO is established

Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluez5-device.c: Acquiring transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
backend-native.c: doing connect
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluez5-device.c: Transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 acquired: fd 13
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 state: idle ->
playing
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile headset_head_unit to
availability status yes
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] device-port.c:
Setting port headset-output to status yes
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] device-port.c:
Setting port headset-input to status yes
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c: Created
sink 2 "bluez_sink.58_17_0C_EA_02_89.headset_head_unit" with sample
spec s16le 1ch 8000Hz and channel map mono
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
bluetooth.protocol = "headset_head_unit"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.intended_roles = "phone"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.description = "MW600"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.string = "58:17:0C:EA:02:89"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.api = "bluez"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.class = "sound"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.bus = "bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.form_factor = "headset"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
bluez.path = "/org/bluez/hci0/dev_58_17_0C_EA_02_89"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
bluez.class = "0x240404"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
bluez.alias = "MW600"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c:
device.icon_name = "audio-headset-bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
Created source 3
"bluez_sink.58_17_0C_EA_02_89.headset_head_unit.monitor" with sample
spec s16le 1ch 8000Hz and channel map mono
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.description = "Monitor of MW600"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.class = "monitor"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.string = "58:17:0C:EA:02:89"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.api = "bluez"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.bus = "bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.form_factor = "headset"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluez.path = "/org/bluez/hci0/dev_58_17_0C_EA_02_89"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluez.class = "0x240404"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluez.alias = "MW600"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.icon_name = "audio-headset-bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.intended_roles = "phone"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
Created source 4 "bluez_source.58_17_0C_EA_02_89.headset_head_unit"
with sample spec s16le 1ch 8000Hz and channel map mono
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluetooth.protocol = "headset_head_unit"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.intended_roles = "phone"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.description = "MW600"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.string = "58:17:0C:EA:02:89"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.api = "bluez"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.class = "sound"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.bus = "bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.form_factor = "headset"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluez.path = "/org/bluez/hci0/dev_58_17_0C_EA_02_89"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluez.class = "0x240404"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
bluez.alias = "MW600"
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] source.c:
device.icon_name = "audio-headset-bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: IO Thread starting up
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth] core-util.c:
RealtimeKit worked.
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth] core-util.c:
Successfully enabled SCHED_RR scheduling for thread, with priority 5.
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 resuming
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Stream properly set up, we're ready to roll!
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-device-restore.c: Could not set format on sink
bluez_sink.58_17_0C_EA_02_89.headset_head_unit
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluetooth-policy.c: Profile headset_head_unit cannot be
selected for loopback
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Sink
bluez_sink.58_17_0C_EA_02_89.headset_head_unit becomes idle, timeout
in 5 seconds.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] core.c:
default_sink: alsa_output.pci-0000_00_1f.3.analog-stereo ->
bluez_sink.58_17_0C_EA_02_89.headset_head_unit
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM >> +VGS=15
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluetooth-policy.c: Profile headset_head_unit cannot be
selected for loopback
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Source
bluez_source.58_17_0C_EA_02_89.headset_head_unit becomes idle, timeout
in 5 seconds.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] core.c:
default_source: alsa_input.pci-0000_00_1f.3.analog-stereo ->
bluez_source.58_17_0C_EA_02_89.headset_head_unit
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM >> +VGM=15
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] module.c: Loaded
"module-bluez5-device" (index: #27; argument:
"path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0").

- org.bluez.MediaTransport1.ClearConfiguration() call on PulseAudio's
A2DPSource object path, makes a2dp_sink unavailable:

Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 available for
profile a2dp_sink
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
dbus: path=/MediaEndpoint/A2DPSource,
interface=org.bluez.MediaEndpoint1, member=ClearConfiguration
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Clearing transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 profile
a2dp_sink
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 state: idle ->
disconnected
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status no
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Source
bluez_source.58_17_0C_EA_02_89.headset_head_unit idle for too long,
suspending ...
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] source.c:
Suspend cause of source
bluez_source.58_17_0C_EA_02_89.headset_head_unit is 0x0004, suspending
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] core.c: Hmm, no
streams around, trying to vacuum.
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Sink
bluez_sink.58_17_0C_EA_02_89.headset_head_unit idle for too long,
suspending ...
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] sink.c: Suspend
cause of sink bluez_sink.58_17_0C_EA_02_89.headset_head_unit is
0x0004, suspending
Jun 13 15:23:06 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Releasing transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
Jun 13 15:23:06 endless pulseaudio[809]: [bluetooth] backend-native.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 released
Jun 13 15:23:06 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Audio stream torn down
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] core.c: Hmm, no
streams around, trying to vacuum.
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] bluez5-util.c:
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 state: playing ->
idle
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile headset_head_unit to
availability status unknown
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] device-port.c:
Setting port headset-output to status unknown
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] device-port.c:
Setting port headset-input to status unknown
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+VGS=15
Jun 13 15:23:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM >> OK

There was still another situation I've seen, which is the RFCOMM
getting disconnected at this point with
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s (which makes we create the card
without all profiles connected), but I don't have logs for it atm.
Post by Luiz Augusto von Dentz
Managed to reproduce the issue, if I recall correctly MW600 don't like
That is aligned with my observations when debugging this over the past
few days, and with I've seen on the logs above.
Post by Luiz Augusto von Dentz
/* Ignore card if has already set other initial profile than a2dp */
if (card->active_profile &&
!pa_streq(card->active_profile->name, "a2dp") &&
!pa_streq(card->active_profile->name, "a2dp_sink"))
return PA_HOOK_OK;
/* Set initial profile to hsp */
card_set_profile(u, card, false);
If I get it correctly the first if statement will not return in case
of A2DP, which basically negates restored profile?, and then it sets
HSP which I find to be the opposite of what we should be doing except
if there already an stream tagged with voice otherwise we shall really
prefer A2DP.
I'm reading this correctly, this code path is reached only when there
is a source-output which is tagged with media.role=phone (unless some
extra heuristic is enabled by passing "auto_switch=2" to
module-bluetooth-policy, which is not the case here), which is
controlled by the "if (source_output_count(c, userdata) == 0)" branch
about 8 lines above the ones you pasted.

I'm adding some extra debug around the initial profile selection to
have a clear picture of what is going on there and will keep analyzing
this further. I'll get back when I have something, now that I have a
better idea of what to look for, but any insights are welcome in the
meantime.

Thanks for the help!

--
João Paulo Rechi Vita
http://about.me/jprvita
Luiz Augusto von Dentz
2018-06-26 10:55:22 UTC
Permalink
Hi Joao,

On Thu, Jun 21, 2018 at 10:21 PM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
Hello Luiz,
On Thu, Jun 21, 2018 at 3:27 AM, Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Im trying to reproduce this with sony sbh50 but apparently it doesn't
have the same problem as it worked just fine, one thing I notice
https://gist.github.com/Vudentz/6f385ededcb00d1d0f4403f06923fd1a
As you can see locally we only support HSP which means there is no
match for MFP, but perhaps you are running with oFono? Anyway I should
have an mw600 somewhere but that is quite old already, but you
mentioned it did not work with MDR-XB950N1 which is quite new model?
Sorry, I forgot to mention: I was not running oFono, so only
PulseAudio's HSP implementation was registered with bluetoothd. I
personally have only been able to reproduce this problem on the Sony
MW-600, from the headsets I have access to. Our QA team at Endless
have seen similar symptoms on the Sony MDR-XB950N1, AMP Pulse BXH-300,
Intopic HM-BT001, and The Coopidea CP-TW-01. I have not able to
confirm 100% whether that is the exact same problem on all of them, as
I'm focusing on the MW-600 which is the one I have access to.
Post by Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Anyway if you can gather some logs of bluetoothd that would be useful
to identify where is the problem.
I've actually was not able to reproduce the exact same symptoms
yesterday: instead of the headset disconnecting A2DP and the card
being destroyed, the OFF profile ended up being selected. The
transport for HSP got available first, the card was created 3s
afterwards (due to WAIT_FOR_PROFILES_TIMEOUT_USEC being reached), but
a2dp actually got connected about 50s afterwards. Then after looking
into it for a while I realized a few extra things that I had not
noticed befofe. PulseAudio logs for this case can be seen right
bellow, and for the "disconnecting case" afterwards. I can still
collect bluetoothd logs if needed.
Notice that the "module-card-restore.c: Restoring profile X for card
Y" message is wrong, as this is from PulseAudio 11 plus some
backported patches, but it does not contain "card-restore: log the
correct profile name". I marked it on the logs bellow for attention.
1. OFF CASE
- org.bluez.Profile1.NewConnection() is called on PulseAudio's
Properties changed in device /org/bluez/hci0/dev_58_17_0C_EA_02_89
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: dbus: path=/Profile/HSPAGProfile,
interface=org.bluez.Profile1, member=NewConnection
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: dbus: NewConnection
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89, fd=23, profile
headset_head_unit
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: doing listen
disconnected -> idle
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
available for profile headset_head_unit
Jun 20 17:09:12 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLIP=1
Timeout expired, and device /org/bluez/hci0/dev_58_17_0C_EA_02_89
still has disconnected profiles: a2dp_sink
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
module-bluez5-discover.c: Loading module-bluez5-device
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
module-card-restore.c: Restoring port latency offsets for card
bluez_card.58_17_0C_EA_02_89.
[pulseaudio] module-card-restore.c: Restoring profile
'headset_head_unit' for card bluez_card.58_17_0C_EA_02_89.
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] card.c: Created
1 "bluez_card.58_17_0C_EA_02_89"
** and the following message indicates module-card-restore was trying
to restore a2dp_sink instead
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
module-bluez5-device.c: Profile a2dp_sink has no transport
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] card.c: Changed
profile of card 1 "bluez_card.58_17_0C_EA_02_89" to off
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 20 17:09:15 endless pulseaudio[899]: [pulseaudio] module.c: Loaded
"path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0").
- Now the card remains created and idle for a while, since its profile
has been set to OFF, except for some boring RFCOMM chat.
Jun 20 17:09:22 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CSCS="UTF-8"
Jun 20 17:09:32 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT*SEAM="MW600",13
Jun 20 17:09:42 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLAN?
Jun 20 17:09:52 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+COLP=1
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio]
backend-native.c: RFCOMM << AT+CCLK?
- Exact 50s after the NewConnection() call there is a
org.bluez.MediaTransport1.SetConfiguration() call on PulseAudio's
Unknown interface org.freedesktop.DBus.Introspectable found, skipping
Unknown interface org.bluez.MediaTransport1 found, skippingJun 20
17:10:02 endless pulseaudio[899]: [pulseaudio] bluez5-util.c: Unknown
interface org.freedesktop.DBus.Properties found, skipping
dbus: path=/MediaEndpoint/A2DPSource,
interface=org.bluez.MediaEndpoint1, member=SetConfiguration
disconnected -> idle
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status unknown
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 available for
profile a2dp_sink
Properties changed in transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 state: idle ->
playing
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status yes
Setting port headset-output to status yes
Jun 20 17:10:02 endless pulseaudio[899]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Properties changed in transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd0 state: playing ->
idle
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status unknown
Setting port headset-output to status unknown
Jun 20 17:10:08 endless pulseaudio[899]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
2. DISCONNECTING CASE (here I had WAIT_FOR_PROFILES_TIMEOUT_USEC=60s,
- org.bluez.Profile1.NewConnection() is called on PulseAudio's
Properties changed in device /org/bluez/hci0/dev_58_17_0C_EA_02_89
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: dbus: path=/Profile/HSPAGProfile,
interface=org.bluez.Profile1, member=NewConnection
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: dbus: NewConnection
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89, fd=23, profile
headset_head_unit
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: doing listen
disconnected -> idle
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
available for profile headset_head_unit
Jun 13 15:22:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLIP=1
Jun 13 15:22:20 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CSCS="UTF-8"
Jun 13 15:22:30 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT*SEAM="MW600",13
Jun 13 15:22:40 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CLAN?
Jun 13 15:22:50 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+COLP=1
Jun 13 15:23:00 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+CCLK?
- Exact 51s after the NewConnection() call there is a
org.bluez.MediaTransport1.SetConfiguration() call on PulseAudio's
dbus: path=/MediaEndpoint/A2DPSource,
interface=org.bluez.MediaEndpoint1, member=SetConfiguration
disconnected -> idle
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluez5-discover.c: Loading module-bluez5-device
path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-card-restore.c: Restoring port latency offsets for card
bluez_card.58_17_0C_EA_02_89.
** wrong message, it is restoring headset_head_unit --> Jun 13
Restoring profile 'a2dp_sink' for card bluez_card.58_17_0C_EA_02_89.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] card.c: Created
2 "bluez_card.58_17_0C_EA_02_89"
- SCO is established
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluez5-device.c: Acquiring transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
backend-native.c: doing connect
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluez5-device.c: Transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 acquired: fd 13
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 state: idle ->
playing
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile headset_head_unit to
availability status yes
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Setting port headset-output to status yes
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Setting port headset-input to status yes
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] sink.c: Created
sink 2 "bluez_sink.58_17_0C_EA_02_89.headset_head_unit" with sample
spec s16le 1ch 8000Hz and channel map mono
bluetooth.protocol = "headset_head_unit"
device.intended_roles = "phone"
device.description = "MW600"
device.string = "58:17:0C:EA:02:89"
device.api = "bluez"
device.class = "sound"
device.bus = "bluetooth"
device.form_factor = "headset"
bluez.path = "/org/bluez/hci0/dev_58_17_0C_EA_02_89"
bluez.class = "0x240404"
bluez.alias = "MW600"
device.icon_name = "audio-headset-bluetooth"
Created source 3
"bluez_sink.58_17_0C_EA_02_89.headset_head_unit.monitor" with sample
spec s16le 1ch 8000Hz and channel map mono
device.description = "Monitor of MW600"
device.class = "monitor"
device.string = "58:17:0C:EA:02:89"
device.api = "bluez"
device.bus = "bluetooth"
device.form_factor = "headset"
bluez.path = "/org/bluez/hci0/dev_58_17_0C_EA_02_89"
bluez.class = "0x240404"
bluez.alias = "MW600"
device.icon_name = "audio-headset-bluetooth"
device.intended_roles = "phone"
Created source 4 "bluez_source.58_17_0C_EA_02_89.headset_head_unit"
with sample spec s16le 1ch 8000Hz and channel map mono
bluetooth.protocol = "headset_head_unit"
device.intended_roles = "phone"
device.description = "MW600"
device.string = "58:17:0C:EA:02:89"
device.api = "bluez"
device.class = "sound"
device.bus = "bluetooth"
device.form_factor = "headset"
bluez.path = "/org/bluez/hci0/dev_58_17_0C_EA_02_89"
bluez.class = "0x240404"
bluez.alias = "MW600"
device.icon_name = "audio-headset-bluetooth"
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: IO Thread starting up
RealtimeKit worked.
Successfully enabled SCHED_RR scheduling for thread, with priority 5.
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 resuming
Jun 13 15:23:01 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Stream properly set up, we're ready to roll!
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-device-restore.c: Could not set format on sink
bluez_sink.58_17_0C_EA_02_89.headset_head_unit
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluetooth-policy.c: Profile headset_head_unit cannot be
selected for loopback
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Sink
bluez_sink.58_17_0C_EA_02_89.headset_head_unit becomes idle, timeout
in 5 seconds.
default_sink: alsa_output.pci-0000_00_1f.3.analog-stereo ->
bluez_sink.58_17_0C_EA_02_89.headset_head_unit
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM >> +VGS=15
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-bluetooth-policy.c: Profile headset_head_unit cannot be
selected for loopback
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Source
bluez_source.58_17_0C_EA_02_89.headset_head_unit becomes idle, timeout
in 5 seconds.
default_source: alsa_input.pci-0000_00_1f.3.analog-stereo ->
bluez_source.58_17_0C_EA_02_89.headset_head_unit
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM >> +VGM=15
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] module.c: Loaded
"path=/org/bluez/hci0/dev_58_17_0C_EA_02_89 autodetect_mtu=0").
- org.bluez.MediaTransport1.ClearConfiguration() call on PulseAudio's
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 available for
profile a2dp_sink
dbus: path=/MediaEndpoint/A2DPSource,
interface=org.bluez.MediaEndpoint1, member=ClearConfiguration
Clearing transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 profile
a2dp_sink
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd1 state: idle ->
disconnected
Jun 13 15:23:01 endless pulseaudio[809]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile a2dp_sink to availability
status no
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Source
bluez_source.58_17_0C_EA_02_89.headset_head_unit idle for too long,
suspending ...
Suspend cause of source
bluez_source.58_17_0C_EA_02_89.headset_head_unit is 0x0004, suspending
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] core.c: Hmm, no
streams around, trying to vacuum.
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
module-suspend-on-idle.c: Sink
bluez_sink.58_17_0C_EA_02_89.headset_head_unit idle for too long,
suspending ...
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] sink.c: Suspend
cause of sink bluez_sink.58_17_0C_EA_02_89.headset_head_unit is
0x0004, suspending
Jun 13 15:23:06 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Releasing transport
/org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 released
Jun 13 15:23:06 endless pulseaudio[809]: [bluetooth]
module-bluez5-device.c: Audio stream torn down
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] core.c: Hmm, no
streams around, trying to vacuum.
Transport /org/bluez/hci0/dev_58_17_0C_EA_02_89/fd23 state: playing ->
idle
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio] card.c: Setting
card bluez_card.58_17_0C_EA_02_89 profile headset_head_unit to
availability status unknown
Setting port headset-output to status unknown
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Setting port headset-input to status unknown
Jun 13 15:23:06 endless pulseaudio[809]: [pulseaudio]
core-subscribe.c: Dropped redundant event due to change event.
Jun 13 15:23:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM << AT+VGS=15
Jun 13 15:23:10 endless pulseaudio[809]: [pulseaudio]
backend-native.c: RFCOMM >> OK
There was still another situation I've seen, which is the RFCOMM
getting disconnected at this point with
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s (which makes we create the card
without all profiles connected), but I don't have logs for it atm.
Post by Luiz Augusto von Dentz
Managed to reproduce the issue, if I recall correctly MW600 don't like
That is aligned with my observations when debugging this over the past
few days, and with I've seen on the logs above.
Post by Luiz Augusto von Dentz
/* Ignore card if has already set other initial profile than a2dp */
if (card->active_profile &&
!pa_streq(card->active_profile->name, "a2dp") &&
!pa_streq(card->active_profile->name, "a2dp_sink"))
return PA_HOOK_OK;
/* Set initial profile to hsp */
card_set_profile(u, card, false);
If I get it correctly the first if statement will not return in case
of A2DP, which basically negates restored profile?, and then it sets
HSP which I find to be the opposite of what we should be doing except
if there already an stream tagged with voice otherwise we shall really
prefer A2DP.
I'm reading this correctly, this code path is reached only when there
is a source-output which is tagged with media.role=phone (unless some
extra heuristic is enabled by passing "auto_switch=2" to
module-bluetooth-policy, which is not the case here), which is
controlled by the "if (source_output_count(c, userdata) == 0)" branch
about 8 lines above the ones you pasted.
I'm adding some extra debug around the initial profile selection to
have a clear picture of what is going on there and will keep analyzing
this further. I'll get back when I have something, now that I have a
better idea of what to look for, but any insights are welcome in the
meantime.
Just a heads up Ive sent a patch for BlueZ that shoud fix this for
MW600, it turns out the device did not reconnect A2DP after HFP and
would only do that is SCO is connected which is too late. Anyway I
briefly discussed with Tanu about the ordering of initial profile
shall be bluetooth-policy first than restore since that means restore
is run last overriding any profile set by bluetooth-policy in case the
user has set anything as preference.
--
Luiz Augusto von Dentz
João Paulo Rechi Vita
2018-06-26 15:41:04 UTC
Permalink
Hello,

On Tue, Jun 26, 2018 at 3:55 AM, Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Hi Joao,
On Thu, Jun 21, 2018 at 10:21 PM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
I'm adding some extra debug around the initial profile selection to
have a clear picture of what is going on there and will keep analyzing
this further. I'll get back when I have something, now that I have a
better idea of what to look for, but any insights are welcome in the
meantime.
Just a heads up Ive sent a patch for BlueZ that shoud fix this for
MW600, it turns out the device did not reconnect A2DP after HFP and
would only do that is SCO is connected which is too late.
That is great news, although I don't see any new patch on the list.
Can you share a link?

Just to add more info (although it may not be super useful at this
point), on the past few days I've been experimenting with how
module-card-restore is affecting this problem, combined with
increasing WAIT_FOR_PROFILES_TIMEOUT_USEC to 60s and got the following
summary:

WAIT_FOR_PROFILES_TIMEOUT_USEC=60s, module-card-restore restores A2DP:
a2dp_sink available: Yes, headset_head_unit available: Yes, active
profile: a2dp_sink
WAIT_FOR_PROFILES_TIMEOUT_USEC=60s, module-card-restore restores HSP:
a2dp_sink available: No, headset_head_unit available: Yes, active
profile: headset_head_unit
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, module-card-restore restores HSP:
a2dp_sink available: No, headset_head_unit available: No, active
profile: None -- card removed
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, no module-card-restore: a2dp_sink
available: No, headset_head_unit available: No, active profile: None
-- card removed
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, module-card-restore tries to
restore a2dp_sink but it does not because it is not available:
a2dp_sink available: No, headset_head_unit available: No, active
profile: None, card removed
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, module-card-restore restores A2DP
(this is without the patch that makes m-c-r ignore unavailble
profiles, just for testing): a2dp_sink available: Yes,
headset_head_unit available: Yes, active profile: off

Also, I've tried to make module-bluez5-device avoid acquiring the
transport right away when the card is created and have the source/sink
be created suspended, deferring the audio connection establishment to
when there is an actual stream to be transferred (which should resume
the sink) or we get an incoming connection. But I looks like I have
messed up the state machine while doing that and the source/sink was
never resumed, which is not really useful. I going to try your BlueZ
fix first (when I find it), and after that we can see if there is
anything else that needs to be fixed in PulseAudio.
Post by Luiz Augusto von Dentz
Anyway I
briefly discussed with Tanu about the ordering of initial profile
shall be bluetooth-policy first than restore since that means restore
is run last overriding any profile set by bluetooth-policy in case the
user has set anything as preference.
In my tests module-bluetooth-policy was not affecting this problem at
all since it was not taking any actions on these profiles (and I
didn't have any media.role=phone stream active). Are you trying to
address a different problem with that change?

My initial thought is that module-card-restore does more harm then
good for UX with Bluetooth headsets, actually. It sure was useful when
module-bluetooth-policy did not exist, but I think a good user
experience is based on dynamically adapting according to which streams
are active at a certain moment, instead of user input. This is mostly
covered by module-bluetooth-policy + module-role-{cork,ducking}, but I
don't think anything switches the profile to A2DP when there is a
"high-quality" stream playing if module-card-restore initially set the
profile to headset_head_sink. Maybe this is more of a UI bug and a
user-focused UI should not expose means for the user to manually
select the profile, which is aligned with a previous comment from
Post by Luiz Augusto von Dentz
If module-bluetooth-policy is sufficient, then module-card-restore
won't do anything anyway, because you never set the profile manually.
If you ever set the profile manually, that's an indication that module-
bluetooth-policy isn't always good enough.
Still, I think the general user will only manually change the profile
either if things go wrong for some reason, or before PulseAudio 12,
because HSP/HFP was selected by default. If they leave the setting on
the "wrong profile", it affects their experience next time using the
headset, despite if it is right afterwards or months later, or if the
headset has been removed and paired with a different machine in the
meantime. Again, it may be a UI issue after all, but comparing to
Android/iPhone (which is what a lot of users are likely to have
previous experience with), there is not even a way for users to
manually set the active profile for headsets. They can enable/disable
a profile for an specific headset on Android tho, which gives them
some sort of control. I don't think there is any client API for
disabling profiles on cards, but maybe that could be a good
alternative?

I realized automatic audio routing is a hot-topic and I may be missing
some alternatives or other previous discussions -- please point me to
them if that is the case.

--
João Paulo Rechi Vita
http://about.me/jprvita
Tanu Kaskinen
2018-06-27 07:08:51 UTC
Permalink
Post by João Paulo Rechi Vita
My initial thought is that module-card-restore does more harm then
good for UX with Bluetooth headsets, actually. It sure was useful when
module-bluetooth-policy did not exist, but I think a good user
experience is based on dynamically adapting according to which streams
are active at a certain moment, instead of user input. This is mostly
covered by module-bluetooth-policy + module-role-{cork,ducking}, but I
don't think anything switches the profile to A2DP when there is a
"high-quality" stream playing if module-card-restore initially set the
profile to headset_head_sink. Maybe this is more of a UI bug and a
user-focused UI should not expose means for the user to manually
select the profile, which is aligned with a previous comment from
Post by Tanu Kaskinen
If module-bluetooth-policy is sufficient, then module-card-restore
won't do anything anyway, because you never set the profile manually.
If you ever set the profile manually, that's an indication that module-
bluetooth-policy isn't always good enough.
Still, I think the general user will only manually change the profile
either if things go wrong for some reason, or before PulseAudio 12,
because HSP/HFP was selected by default. If they leave the setting on
the "wrong profile", it affects their experience next time using the
headset, despite if it is right afterwards or months later, or if the
headset has been removed and paired with a different machine in the
meantime. Again, it may be a UI issue after all, but comparing to
Android/iPhone (which is what a lot of users are likely to have
previous experience with), there is not even a way for users to
manually set the active profile for headsets. They can enable/disable
a profile for an specific headset on Android tho, which gives them
some sort of control. I don't think there is any client API for
disabling profiles on cards, but maybe that could be a good
alternative?
I agree, it's not nice that setting the profile once will interfere
with automatic configuration forever. Do you want to make a patch for
module-card-restore that adds an option (enabled by default) for
disabling profile restoring for bluetooth?

Offering a UI for disabling profiles doesn't seem like a better
alternative to me, at least for this problem. If there's some other use
case for disabling profiles, I'm not against the idea in principle.
--
Tanu

https://liberapay.com/tanuk
https://www.patreon.com/tanuk
Luiz Augusto von Dentz
2018-06-27 08:15:32 UTC
Permalink
Hi Joao,

On Tue, Jun 26, 2018 at 6:41 PM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
Hello,
On Tue, Jun 26, 2018 at 3:55 AM, Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Hi Joao,
On Thu, Jun 21, 2018 at 10:21 PM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
I'm adding some extra debug around the initial profile selection to
have a clear picture of what is going on there and will keep analyzing
this further. I'll get back when I have something, now that I have a
better idea of what to look for, but any insights are welcome in the
meantime.
Just a heads up Ive sent a patch for BlueZ that shoud fix this for
MW600, it turns out the device did not reconnect A2DP after HFP and
would only do that is SCO is connected which is too late.
That is great news, although I don't see any new patch on the list.
Can you share a link?
Just to add more info (although it may not be super useful at this
point), on the past few days I've been experimenting with how
module-card-restore is affecting this problem, combined with
increasing WAIT_FOR_PROFILES_TIMEOUT_USEC to 60s and got the following
a2dp_sink available: Yes, headset_head_unit available: Yes, active
profile: a2dp_sink
a2dp_sink available: No, headset_head_unit available: Yes, active
profile: headset_head_unit
a2dp_sink available: No, headset_head_unit available: No, active
profile: None -- card removed
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, no module-card-restore: a2dp_sink
available: No, headset_head_unit available: No, active profile: None
-- card removed
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, module-card-restore tries to
a2dp_sink available: No, headset_head_unit available: No, active
profile: None, card removed
WAIT_FOR_PROFILES_TIMEOUT_USEC=3s, module-card-restore restores A2DP
(this is without the patch that makes m-c-r ignore unavailble
profiles, just for testing): a2dp_sink available: Yes,
headset_head_unit available: Yes, active profile: off
Also, I've tried to make module-bluez5-device avoid acquiring the
transport right away when the card is created and have the source/sink
be created suspended, deferring the audio connection establishment to
when there is an actual stream to be transferred (which should resume
the sink) or we get an incoming connection. But I looks like I have
messed up the state machine while doing that and the source/sink was
never resumed, which is not really useful. I going to try your BlueZ
fix first (when I find it), and after that we can see if there is
anything else that needs to be fixed in PulseAudio.
Ive pushed the fix, at least MW600 reconnects properly.
Post by João Paulo Rechi Vita
Post by Luiz Augusto von Dentz
Anyway I
briefly discussed with Tanu about the ordering of initial profile
shall be bluetooth-policy first than restore since that means restore
is run last overriding any profile set by bluetooth-policy in case the
user has set anything as preference.
In my tests module-bluetooth-policy was not affecting this problem at
all since it was not taking any actions on these profiles (and I
didn't have any media.role=phone stream active). Are you trying to
address a different problem with that change?
My initial thought is that module-card-restore does more harm then
good for UX with Bluetooth headsets, actually. It sure was useful when
module-bluetooth-policy did not exist, but I think a good user
experience is based on dynamically adapting according to which streams
are active at a certain moment, instead of user input. This is mostly
covered by module-bluetooth-policy + module-role-{cork,ducking}, but I
don't think anything switches the profile to A2DP when there is a
"high-quality" stream playing if module-card-restore initially set the
profile to headset_head_sink. Maybe this is more of a UI bug and a
user-focused UI should not expose means for the user to manually
select the profile, which is aligned with a previous comment from
Post by Luiz Augusto von Dentz
If module-bluetooth-policy is sufficient, then module-card-restore
won't do anything anyway, because you never set the profile manually.
If you ever set the profile manually, that's an indication that module-
bluetooth-policy isn't always good enough.
Still, I think the general user will only manually change the profile
either if things go wrong for some reason, or before PulseAudio 12,
because HSP/HFP was selected by default. If they leave the setting on
the "wrong profile", it affects their experience next time using the
headset, despite if it is right afterwards or months later, or if the
headset has been removed and paired with a different machine in the
meantime. Again, it may be a UI issue after all, but comparing to
Android/iPhone (which is what a lot of users are likely to have
previous experience with), there is not even a way for users to
manually set the active profile for headsets. They can enable/disable
a profile for an specific headset on Android tho, which gives them
some sort of control. I don't think there is any client API for
disabling profiles on cards, but maybe that could be a good
alternative?
Yep, I guess having only one policy module is actually better in this
case so perhaps restore need to check if bluetooth-policy is loaded
and then ignore any bluetooth card.
Post by João Paulo Rechi Vita
I realized automatic audio routing is a hot-topic and I may be missing
some alternatives or other previous discussions -- please point me to
them if that is the case.
--
João Paulo Rechi Vita
http://about.me/jprvita
--
Luiz Augusto von Dentz
João Paulo Rechi Vita
2018-06-27 22:55:05 UTC
Permalink
On Wed, Jun 27, 2018 at 1:15 AM, Luiz Augusto von Dentz
Post by Luiz Augusto von Dentz
Hi Joao,
Ive pushed the fix, at least MW600 reconnects properly.
Thanks, I tested it with my MW600 and it is working great! I'll let
you know once I get results from QA with the other headsets.
Post by Luiz Augusto von Dentz
Post by João Paulo Rechi Vita
My initial thought is that module-card-restore does more harm then
good for UX with Bluetooth headsets, actually. It sure was useful when
module-bluetooth-policy did not exist, but I think a good user
experience is based on dynamically adapting according to which streams
are active at a certain moment, instead of user input. This is mostly
covered by module-bluetooth-policy + module-role-{cork,ducking}, but I
don't think anything switches the profile to A2DP when there is a
"high-quality" stream playing if module-card-restore initially set the
profile to headset_head_sink. Maybe this is more of a UI bug and a
user-focused UI should not expose means for the user to manually
select the profile, which is aligned with a previous comment from
Post by Tanu Kaskinen
If module-bluetooth-policy is sufficient, then module-card-restore
won't do anything anyway, because you never set the profile manually.
If you ever set the profile manually, that's an indication that module-
bluetooth-policy isn't always good enough.
Still, I think the general user will only manually change the profile
either if things go wrong for some reason, or before PulseAudio 12,
because HSP/HFP was selected by default. If they leave the setting on
the "wrong profile", it affects their experience next time using the
headset, despite if it is right afterwards or months later, or if the
headset has been removed and paired with a different machine in the
meantime. Again, it may be a UI issue after all, but comparing to
Android/iPhone (which is what a lot of users are likely to have
previous experience with), there is not even a way for users to
manually set the active profile for headsets. They can enable/disable
a profile for an specific headset on Android tho, which gives them
some sort of control. I don't think there is any client API for
disabling profiles on cards, but maybe that could be a good
alternative?
I agree, it's not nice that setting the profile once will interfere
with automatic configuration forever. Do you want to make a patch for
module-card-restore that adds an option (enabled by default) for
disabling profile restoring for bluetooth?
Yes, I can do it.
Post by Luiz Augusto von Dentz
Offering a UI for disabling profiles doesn't seem like a better
alternative to me, at least for this problem. If there's some other use
case for disabling profiles, I'm not against the idea in principle.
I was thinking about users that only want to use their headset for
HSP/HFP with VoIP applications, for example. But maybe
module-stream-restore is enough in this case and I'm over-engineering,
lets just leave this case aside for now.

--
João Paulo Rechi Vita
http://about.me/jprvita
João Paulo Rechi Vita
2018-07-10 02:23:28 UTC
Permalink
We can provide a better overall user experience with Bluetooth cards by
always choosing the higher audio quality profile (A2DP) by default and
updating the profile selection dynamically according to which streams
are active at a certain moment. The default initial selection has been
addressed by "85daab272 bluetooth: set better priorities for profiles"
and the dynamic profile selection is covered by module-bluetooth-policy.

In addition, module-card-restore's database entries for Bluetooth devices
are retained after a device is removed from the system, leading to the
previously selected profile being restored after a new pairing with the
same device, with no way for the user to erase this memory and reset the
default profile except manually fiddling with module-card-restore's
database.

This commit adds a module argument to have module-card-restore ignore
Bluetooth profiles and this behavior is set as default.
---
src/modules/module-card-restore.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)

diff --git a/src/modules/module-card-restore.c b/src/modules/module-card-restore.c
index 014e75435..10e6f4292 100644
--- a/src/modules/module-card-restore.c
+++ b/src/modules/module-card-restore.c
@@ -48,11 +48,14 @@ PA_MODULE_AUTHOR("Lennart Poettering");
PA_MODULE_DESCRIPTION("Automatically restore profile of cards");
PA_MODULE_VERSION(PACKAGE_VERSION);
PA_MODULE_LOAD_ONCE(true);
+PA_MODULE_USAGE(
+ "restore_bluetooth_profile=<boolean>"
+);

#define SAVE_INTERVAL (10 * PA_USEC_PER_SEC)

static const char* const valid_modargs[] = {
- NULL
+ "restore_bluetooth_profile=<boolean>"
};

struct userdata {
@@ -60,6 +63,7 @@ struct userdata {
pa_module *module;
pa_time_event *save_time_event;
pa_database *database;
+ bool restore_bluetooth_profile;
};

#define ENTRY_VERSION 4
@@ -554,6 +558,12 @@ static pa_hook_result_t card_choose_initial_profile_callback(pa_core *core, pa_c
if (!(e = entry_read(u, card->name)))
return PA_HOOK_OK;

+ if (!u->restore_bluetooth_profile) {
+ const char *s = pa_proplist_gets(card->proplist, PA_PROP_DEVICE_BUS);
+ if (!s || pa_streq(s, "bluetooth"))
+ return PA_HOOK_OK;
+ }
+
if (e->profile[0]) {
pa_card_profile *profile;

@@ -607,6 +617,7 @@ int pa__init(pa_module*m) {
pa_modargs *ma = NULL;
struct userdata *u;
char *fname;
+ bool restore_bluetooth_profile;

pa_assert(m);

@@ -615,9 +626,16 @@ int pa__init(pa_module*m) {
goto fail;
}

+ restore_bluetooth_profile = false;
+ if (pa_modargs_get_value_boolean(ma, "restore_bluetooth_profile", &restore_bluetooth_profile) < 0) {
+ pa_log("Invalid boolean value for restore_bluetooth_profile parameter");
+ goto fail;
+ }
+
m->userdata = u = pa_xnew0(struct userdata, 1);
u->core = m->core;
u->module = m;
+ u->restore_bluetooth_profile = restore_bluetooth_profile;

pa_module_hook_connect(m, &m->core->hooks[PA_CORE_HOOK_CARD_NEW], PA_HOOK_EARLY, (pa_hook_cb_t) card_new_hook_callback, u);
pa_module_hook_connect(m, &m->core->hooks[PA_CORE_HOOK_CARD_CHOOSE_INITIAL_PROFILE], PA_HOOK_NORMAL,
--
2.18.0
Luiz Augusto von Dentz
2018-07-10 10:10:13 UTC
Permalink
Hi Joao,

On Tue, Jul 10, 2018 at 5:23 AM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
We can provide a better overall user experience with Bluetooth cards by
always choosing the higher audio quality profile (A2DP) by default and
updating the profile selection dynamically according to which streams
are active at a certain moment. The default initial selection has been
addressed by "85daab272 bluetooth: set better priorities for profiles"
and the dynamic profile selection is covered by module-bluetooth-policy.
In addition, module-card-restore's database entries for Bluetooth devices
are retained after a device is removed from the system, leading to the
previously selected profile being restored after a new pairing with the
same device, with no way for the user to erase this memory and reset the
default profile except manually fiddling with module-card-restore's
database.
This commit adds a module argument to have module-card-restore ignore
Bluetooth profiles and this behavior is set as default.
I would have it done differently, just detect if
module-bluetooth-policy is loaded instead of having a argument since
on platforms not using module-bluetooth-policy it might be useful to
restore.
Post by João Paulo Rechi Vita
---
src/modules/module-card-restore.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)
diff --git a/src/modules/module-card-restore.c b/src/modules/module-card-restore.c
index 014e75435..10e6f4292 100644
--- a/src/modules/module-card-restore.c
+++ b/src/modules/module-card-restore.c
@@ -48,11 +48,14 @@ PA_MODULE_AUTHOR("Lennart Poettering");
PA_MODULE_DESCRIPTION("Automatically restore profile of cards");
PA_MODULE_VERSION(PACKAGE_VERSION);
PA_MODULE_LOAD_ONCE(true);
+PA_MODULE_USAGE(
+ "restore_bluetooth_profile=<boolean>"
+);
#define SAVE_INTERVAL (10 * PA_USEC_PER_SEC)
static const char* const valid_modargs[] = {
- NULL
+ "restore_bluetooth_profile=<boolean>"
};
struct userdata {
@@ -60,6 +63,7 @@ struct userdata {
pa_module *module;
pa_time_event *save_time_event;
pa_database *database;
+ bool restore_bluetooth_profile;
};
#define ENTRY_VERSION 4
@@ -554,6 +558,12 @@ static pa_hook_result_t card_choose_initial_profile_callback(pa_core *core, pa_c
if (!(e = entry_read(u, card->name)))
return PA_HOOK_OK;
+ if (!u->restore_bluetooth_profile) {
+ const char *s = pa_proplist_gets(card->proplist, PA_PROP_DEVICE_BUS);
+ if (!s || pa_streq(s, "bluetooth"))
+ return PA_HOOK_OK;
+ }
+
if (e->profile[0]) {
pa_card_profile *profile;
@@ -607,6 +617,7 @@ int pa__init(pa_module*m) {
pa_modargs *ma = NULL;
struct userdata *u;
char *fname;
+ bool restore_bluetooth_profile;
pa_assert(m);
@@ -615,9 +626,16 @@ int pa__init(pa_module*m) {
goto fail;
}
+ restore_bluetooth_profile = false;
+ if (pa_modargs_get_value_boolean(ma, "restore_bluetooth_profile", &restore_bluetooth_profile) < 0) {
+ pa_log("Invalid boolean value for restore_bluetooth_profile parameter");
+ goto fail;
+ }
+
m->userdata = u = pa_xnew0(struct userdata, 1);
u->core = m->core;
u->module = m;
+ u->restore_bluetooth_profile = restore_bluetooth_profile;
pa_module_hook_connect(m, &m->core->hooks[PA_CORE_HOOK_CARD_NEW], PA_HOOK_EARLY, (pa_hook_cb_t) card_new_hook_callback, u);
pa_module_hook_connect(m, &m->core->hooks[PA_CORE_HOOK_CARD_CHOOSE_INITIAL_PROFILE], PA_HOOK_NORMAL,
--
2.18.0
--
Luiz Augusto von Dentz
Tanu Kaskinen
2018-07-15 06:57:26 UTC
Permalink
Post by Luiz Augusto von Dentz
Hi Joao,
On Tue, Jul 10, 2018 at 5:23 AM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
We can provide a better overall user experience with Bluetooth cards by
always choosing the higher audio quality profile (A2DP) by default and
updating the profile selection dynamically according to which streams
are active at a certain moment. The default initial selection has been
addressed by "85daab272 bluetooth: set better priorities for
profiles"
and the dynamic profile selection is covered by module-bluetooth-
policy.
In addition, module-card-restore's database entries for Bluetooth devices
are retained after a device is removed from the system, leading to the
previously selected profile being restored after a new pairing with the
same device, with no way for the user to erase this memory and reset the
default profile except manually fiddling with module-card-restore's
database.
This commit adds a module argument to have module-card-restore ignore
Bluetooth profiles and this behavior is set as default.
I would have it done differently, just detect if
module-bluetooth-policy is loaded instead of having a argument since
on platforms not using module-bluetooth-policy it might be useful to
restore.
João, are you willing to implement that instead? I'm fine with either
approach, but Luiz's idea seems a bit better. Note that if you're going
to implement it, there's the added complication of needing to monitor
when modules are loaded and unloaded, it's not enough to check it only
during initialization.
Post by Luiz Augusto von Dentz
Post by João Paulo Rechi Vita
---
src/modules/module-card-restore.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)
diff --git a/src/modules/module-card-restore.c
b/src/modules/module-card-restore.c
index 014e75435..10e6f4292 100644
--- a/src/modules/module-card-restore.c
+++ b/src/modules/module-card-restore.c
@@ -48,11 +48,14 @@ PA_MODULE_AUTHOR("Lennart Poettering");
PA_MODULE_DESCRIPTION("Automatically restore profile of cards");
PA_MODULE_VERSION(PACKAGE_VERSION);
PA_MODULE_LOAD_ONCE(true);
+PA_MODULE_USAGE(
+ "restore_bluetooth_profile=<boolean>"
+);
#define SAVE_INTERVAL (10 * PA_USEC_PER_SEC)
static const char* const valid_modargs[] = {
- NULL
+ "restore_bluetooth_profile=<boolean>"
};
struct userdata {
@@ -60,6 +63,7 @@ struct userdata {
pa_module *module;
pa_time_event *save_time_event;
pa_database *database;
+ bool restore_bluetooth_profile;
};
#define ENTRY_VERSION 4
@@ -554,6 +558,12 @@ static pa_hook_result_t
card_choose_initial_profile_callback(pa_core *core, pa_c
if (!(e = entry_read(u, card->name)))
return PA_HOOK_OK;
+ if (!u->restore_bluetooth_profile) {
+ const char *s = pa_proplist_gets(card->proplist,
PA_PROP_DEVICE_BUS);
+ if (!s || pa_streq(s, "bluetooth"))
The condition should be

s && pa_streq(s, "bluetooth")

or

pa_safe_streq(s, "bluetooth")

because we should skip the restoring only for bluetooth cards, not for
cards with an unknown bus.
--
Tanu

https://www.patreon.com/tanuk
https://liberapay.com/tanuk
João Paulo Rechi Vita
2018-07-20 18:27:20 UTC
Permalink
Hello Tanu and Luiz,
Post by Tanu Kaskinen
Post by Luiz Augusto von Dentz
Hi Joao,
On Tue, Jul 10, 2018 at 5:23 AM, João Paulo Rechi Vita
Post by João Paulo Rechi Vita
We can provide a better overall user experience with Bluetooth cards by
always choosing the higher audio quality profile (A2DP) by default and
updating the profile selection dynamically according to which streams
are active at a certain moment. The default initial selection has been
addressed by "85daab272 bluetooth: set better priorities for profiles"
and the dynamic profile selection is covered by module-bluetooth-
policy.
In addition, module-card-restore's database entries for Bluetooth devices
are retained after a device is removed from the system, leading to the
previously selected profile being restored after a new pairing with the
same device, with no way for the user to erase this memory and reset the
default profile except manually fiddling with module-card-restore's
database.
This commit adds a module argument to have module-card-restore ignore
Bluetooth profiles and this behavior is set as default.
I would have it done differently, just detect if
module-bluetooth-policy is loaded instead of having a argument since
on platforms not using module-bluetooth-policy it might be useful to
restore.
João, are you willing to implement that instead? I'm fine with either
approach, but Luiz's idea seems a bit better. Note that if you're going
to implement it, there's the added complication of needing to monitor
when modules are loaded and unloaded, it's not enough to check it only
during initialization.
I agree with the idea that one could want to have module-card-restore
work on Bluetooth cards when module-bluetooth-policy is not loaded.
But I am not sure tying on module's behavior to whether or not a
different module is loaded or not is a good approach. I think it may
complicate debugging, as when analyzing module-card-restore behavior
you'd have to also think about module-bluetooth-policy as well
(although you need to think about both nowadays when looking at the
bigger picture of Bluetooth cards). I also think is a bit
non-intuitive for users, specially when you think of a user that
disables loading module-bluetooth-policy to avoid its behavior, and
then she gets a different behavior from module-card-restore (which is
she can't disable unless there is also a module argument for that).

In addition, with Luiz' proposal one can't have the current behavior
of having module-bluetooth-policy doing its dynamic profile change
dependent on the active streams AND have module-card-restore set the
initial profile to the saved one, which I believed was Tanu's reason
to have a module argument in the first place. But on his last comment
he says he's fine with either approach, so I probably guessed the
rationale wrongly.

I personally prefer having a static module argument than doing the
dynamic detection.
Post by Tanu Kaskinen
Post by Luiz Augusto von Dentz
Post by João Paulo Rechi Vita
---
src/modules/module-card-restore.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)
diff --git a/src/modules/module-card-restore.c
b/src/modules/module-card-restore.c
index 014e75435..10e6f4292 100644
--- a/src/modules/module-card-restore.c
+++ b/src/modules/module-card-restore.c
@@ -48,11 +48,14 @@ PA_MODULE_AUTHOR("Lennart Poettering");
PA_MODULE_DESCRIPTION("Automatically restore profile of cards");
PA_MODULE_VERSION(PACKAGE_VERSION);
PA_MODULE_LOAD_ONCE(true);
+PA_MODULE_USAGE(
+ "restore_bluetooth_profile=<boolean>"
+);
#define SAVE_INTERVAL (10 * PA_USEC_PER_SEC)
static const char* const valid_modargs[] = {
- NULL
+ "restore_bluetooth_profile=<boolean>"
};
struct userdata {
@@ -60,6 +63,7 @@ struct userdata {
pa_module *module;
pa_time_event *save_time_event;
pa_database *database;
+ bool restore_bluetooth_profile;
};
#define ENTRY_VERSION 4
@@ -554,6 +558,12 @@ static pa_hook_result_t
card_choose_initial_profile_callback(pa_core *core, pa_c
if (!(e = entry_read(u, card->name)))
return PA_HOOK_OK;
+ if (!u->restore_bluetooth_profile) {
+ const char *s = pa_proplist_gets(card->proplist,
PA_PROP_DEVICE_BUS);
+ if (!s || pa_streq(s, "bluetooth"))
The condition should be
s && pa_streq(s, "bluetooth")
or
pa_safe_streq(s, "bluetooth")
because we should skip the restoring only for bluetooth cards, not for
cards with an unknown bus.
Thanks! I'll fix it and send an updated version in case we decide to
stick with this approach.

--
João Paulo Rechi Vita
http://about.me/jprvita
João Paulo Rechi Vita
2018-07-20 19:39:22 UTC
Permalink
We can provide a better overall user experience with Bluetooth cards by
always choosing the higher audio quality profile (A2DP) by default and
updating the profile selection dynamically according to which streams
are active at a certain moment. The default initial selection has been
addressed by "85daab272 bluetooth: set better priorities for profiles"
and the dynamic profile selection is covered by module-bluetooth-policy.

In addition, module-card-restore's database entries for Bluetooth devices
are retained after a device is removed from the system, leading to the
previously selected profile being restored after a new pairing with the
same device, with no way for the user to erase this memory and reset the
default profile except manually fiddling with module-card-restore's
database.

This commit adds a module argument to have module-card-restore ignore
Bluetooth profiles and this behavior is set as default.
---
src/modules/module-card-restore.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)

diff --git a/src/modules/module-card-restore.c b/src/modules/module-card-restore.c
index 014e75435..25598f73c 100644
--- a/src/modules/module-card-restore.c
+++ b/src/modules/module-card-restore.c
@@ -48,11 +48,14 @@ PA_MODULE_AUTHOR("Lennart Poettering");
PA_MODULE_DESCRIPTION("Automatically restore profile of cards");
PA_MODULE_VERSION(PACKAGE_VERSION);
PA_MODULE_LOAD_ONCE(true);
+PA_MODULE_USAGE(
+ "restore_bluetooth_profile=<boolean>"
+);

#define SAVE_INTERVAL (10 * PA_USEC_PER_SEC)

static const char* const valid_modargs[] = {
- NULL
+ "restore_bluetooth_profile=<boolean>"
};

struct userdata {
@@ -60,6 +63,7 @@ struct userdata {
pa_module *module;
pa_time_event *save_time_event;
pa_database *database;
+ bool restore_bluetooth_profile;
};

#define ENTRY_VERSION 4
@@ -554,6 +558,12 @@ static pa_hook_result_t card_choose_initial_profile_callback(pa_core *core, pa_c
if (!(e = entry_read(u, card->name)))
return PA_HOOK_OK;

+ if (!u->restore_bluetooth_profile) {
+ const char *s = pa_proplist_gets(card->proplist, PA_PROP_DEVICE_BUS);
+ if (pa_safe_streq(s, "bluetooth"))
+ return PA_HOOK_OK;
+ }
+
if (e->profile[0]) {
pa_card_profile *profile;

@@ -607,6 +617,7 @@ int pa__init(pa_module*m) {
pa_modargs *ma = NULL;
struct userdata *u;
char *fname;
+ bool restore_bluetooth_profile;

pa_assert(m);

@@ -615,9 +626,16 @@ int pa__init(pa_module*m) {
goto fail;
}

+ restore_bluetooth_profile = false;
+ if (pa_modargs_get_value_boolean(ma, "restore_bluetooth_profile", &restore_bluetooth_profile) < 0) {
+ pa_log("Invalid boolean value for restore_bluetooth_profile parameter");
+ goto fail;
+ }
+
m->userdata = u = pa_xnew0(struct userdata, 1);
u->core = m->core;
u->module = m;
+ u->restore_bluetooth_profile = restore_bluetooth_profile;

pa_module_hook_connect(m, &m->core->hooks[PA_CORE_HOOK_CARD_NEW], PA_HOOK_EARLY, (pa_hook_cb_t) card_new_hook_callback, u);
pa_module_hook_connect(m, &m->core->hooks[PA_CORE_HOOK_CARD_CHOOSE_INITIAL_PROFILE], PA_HOOK_NORMAL,
--
2.18.0
Tanu Kaskinen
2018-07-22 14:46:28 UTC
Permalink
Post by João Paulo Rechi Vita
We can provide a better overall user experience with Bluetooth cards by
always choosing the higher audio quality profile (A2DP) by default and
updating the profile selection dynamically according to which streams
are active at a certain moment. The default initial selection has been
addressed by "85daab272 bluetooth: set better priorities for profiles"
and the dynamic profile selection is covered by module-bluetooth-policy.
In addition, module-card-restore's database entries for Bluetooth devices
are retained after a device is removed from the system, leading to the
previously selected profile being restored after a new pairing with the
same device, with no way for the user to erase this memory and reset the
default profile except manually fiddling with module-card-restore's
database.
This commit adds a module argument to have module-card-restore ignore
Bluetooth profiles and this behavior is set as default.
---
src/modules/module-card-restore.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)
Thanks! Applied.
--
Tanu

https://www.patreon.com/tanuk
https://liberapay.com/tanuk
Loading...