Apparent bluez 5.48 regression: Headphones fail to reconnect after suspend/resume

Hello,

I just joined the mailing list so can't directly reply to old messages, so sending with same title.

I'm experiencing the same issue as Robert here
https://www.spinics.net/lists/linux-bluetooth/msg73824.html, happening on the same laptop Dell XPS 13 but with different sub-model 9333, but on openSUSE Tumbleweed.

It looks like the bluez component is in a wrong state when either loading btusb with modprobe later on or resuming from suspend. The workaround is to restart the systemd bluetooth daemon. I suspect that plugging in USB bluetooth dongles would also have the same issue but I don't have one to test.

It used to work correctly before the upgrade from 5.47 to 5.48.

See my original report here for details:
https://bugzilla.suse.com/show_bug.cgi?id=1076898
Robert's report https://bugzilla.redhat.com/show_bug.cgi?id=1534857,
also confirmed by a third person.

Please let us know if this is reproducible on your side or whether it's an isolated case specific to our Dell hardware.

Thanks,

Vincent Petry

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Hi Vincent,

Quoted 10 lines · Vincent Petry

Hello,

I just joined the mailing list so can't directly reply to old messages, so sending with same title.

I'm experiencing the same issue as Robert here
https://www.spinics.net/lists/linux-bluetooth/msg73824.html, happening on the same laptop Dell XPS 13 but with different sub-model 9333, but on openSUSE Tumbleweed.

Quoted 5 lines

It looks like the bluez component is in a wrong state when either loading btusb with modprobe later on or resuming from suspend. The workaround is to restart the systemd bluetooth daemon. I suspect that plugging in USB bluetooth dongles would also have the same issue but I don't have one to test.

Does the system have any controller after resume? Does bluetoothctl report any device at all?

Quoted 21 lines

It used to work correctly before the upgrade from 5.47 to 5.48.

See my original report here for details:
https://bugzilla.suse.com/show_bug.cgi?id=1076898
Robert's report https://bugzilla.redhat.com/show_bug.cgi?id=1534857,
also confirmed by a third person.

Please let us know if this is reproducible on your side or whether it's an isolated case specific to our Dell hardware.

Thanks,

Vincent Petry

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Hello,

Quoted 13 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 10 lines · Vincent Petry

Hello,

I just joined the mailing list so can't directly reply to old messages, so sending with same title.

I'm experiencing the same issue as Robert here
https://www.spinics.net/lists/linux-bluetooth/msg73824.html, happening on the same laptop Dell XPS 13 but with different sub-model 9333, but on openSUSE Tumbleweed.

Quoted 7 lines

Quoted 5 lines

It looks like the bluez component is in a wrong state when either loading btusb with modprobe later on or resuming from suspend. The workaround is to restart the systemd bluetooth daemon. I suspect that plugging in USB bluetooth dongles would also have the same issue but I don't have one to test.

Does the system have any controller after resume? Does bluetoothctl report any device at all?

After resume from suspend, bluetoothctl sees the controller, yes and it does report my usual three devices from the saved list.

When I tell it to connect to the headset (which is turned on), I can hear the headset beep shortly which is the signal for connection, but then it disconnects again:
Attempting to connect to E3:XX:XX:XX:XX:XX
[CHG] Device E3:XX:XX:XX:XX:XX Connected: yes
Failed to connect: org.bluez.Error.Failed
[CHG] Device E3:XX:XX:XX:XX:XX Connected: no

If I tell it to connect to my bluetooth watch it stays connected.

Now I wanted to try accessing characteristics but the command "select-attribute" has gone missing ? I also tried "help gatt" as it seems to be a submenu but it says "Too many argumnets". Possibly another bug in bluez ? (I can send a separate email for this one if you want)

Anyway, I have a Python script that uses Dbus and said Python script is able to connect to my watch and talk to it even in this state.

So the bluez 5.48 regression seems to be specifically with headsets and also with scanning/discovering. I don't have any other device types to test with.

The workaround is to restart the bluetooth service and enable bluetooth afterwards.

Please make sure to look at
https://bugzilla.suse.com/show_bug.cgi?id=1076898 for logs I posted.

If you guys cannot reproduce the first regression I could try and bisect bluez locally to find the breaking change. For this I need to know how to set up bluez on my system after compiling. Is there any guide about this ? Should I tell it to overwrite the existing libs and reboot or is restarting the bluetooth service sufficient to make it use the newly installed version ?

Thanks,

Vincent

Quoted 17 lines

Quoted 17 lines

It used to work correctly before the upgrade from 5.47 to 5.48.

See my original report here for details:
https://bugzilla.suse.com/show_bug.cgi?id=1076898
Robert's report https://bugzilla.redhat.com/show_bug.cgi?id=1534857,
also confirmed by a third person.

Please let us know if this is reproducible on your side or whether it's an isolated case specific to our Dell hardware.

Thanks,

Vincent Petry

Quoted 6 lines

Quoted 4 lines

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

I'm seeing this too. My headphones go through a connect/disconnect cycle a few times and then quit. Unpairing and repairing does make it work.

Quoted 91 lines · Vincent Petry

Hello,

Quoted 13 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 10 lines · Vincent Petry

Hello,

I just joined the mailing list so can't directly reply to old messages, so sending with same title.

I'm experiencing the same issue as Robert here
https://www.spinics.net/lists/linux-bluetooth/msg73824.html, happening on the same laptop Dell XPS 13 but with different sub-model 9333, but on openSUSE Tumbleweed.

Quoted 7 lines

Quoted 5 lines

It looks like the bluez component is in a wrong state when either loading btusb with modprobe later on or resuming from suspend. The workaround is to restart the systemd bluetooth daemon. I suspect that plugging in USB bluetooth dongles would also have the same issue but I don't have one to test.

Does the system have any controller after resume? Does bluetoothctl report any device at all?

After resume from suspend, bluetoothctl sees the controller, yes and it does report my usual three devices from the saved list.

When I tell it to connect to the headset (which is turned on), I can hear the headset beep shortly which is the signal for connection, but then it disconnects again:
Attempting to connect to E3:XX:XX:XX:XX:XX
[CHG] Device E3:XX:XX:XX:XX:XX Connected: yes
Failed to connect: org.bluez.Error.Failed
[CHG] Device E3:XX:XX:XX:XX:XX Connected: no

If I tell it to connect to my bluetooth watch it stays connected.

Now I wanted to try accessing characteristics but the command "select-attribute" has gone missing ? I also tried "help gatt" as it seems to be a submenu but it says "Too many argumnets". Possibly another bug in bluez ? (I can send a separate email for this one if you want)

Anyway, I have a Python script that uses Dbus and said Python script is able to connect to my watch and talk to it even in this state.

So the bluez 5.48 regression seems to be specifically with headsets and also with scanning/discovering. I don't have any other device types to test with.

The workaround is to restart the bluetooth service and enable bluetooth afterwards.

Please make sure to look at
https://bugzilla.suse.com/show_bug.cgi?id=1076898 for logs I posted.

If you guys cannot reproduce the first regression I could try and bisect bluez locally to find the breaking change. For this I need to know how to set up bluez on my system after compiling. Is there any guide about this ? Should I tell it to overwrite the existing libs and reboot or is restarting the bluetooth service sufficient to make it use the newly installed version ?

Thanks,

Vincent

Quoted 17 lines

Quoted 17 lines

It used to work correctly before the upgrade from 5.47 to 5.48.

See my original report here for details:
https://bugzilla.suse.com/show_bug.cgi?id=1076898
Robert's report https://bugzilla.redhat.com/show_bug.cgi?id=1534857,
also confirmed by a third person.

Please let us know if this is reproducible on your side or whether it's an isolated case specific to our Dell hardware.

Thanks,

Vincent Petry

Quoted 5 lines

Quoted 4 lines

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Hello,

I have bisected bluez between 5.47 (good) and 5.48 (bad) to find the breaking commit for the headset reconnect issue.

Here are the results:

git bisect start
# bad: [0d1e3b9c5754022c779da129025d493a198d49cf] Release 5.48 git bisect bad 0d1e3b9c5754022c779da129025d493a198d49cf
# good: [d139fd866241fe0d99b5e430f937c8d6160cc7dd] Release 5.47 git bisect good d139fd866241fe0d99b5e430f937c8d6160cc7dd
# bad: [65aaf36f2a36895e4a351ac3fa1cb8da87d4589c] mesh: Correct length test in agent.c:request_ascii
git bisect bad 65aaf36f2a36895e4a351ac3fa1cb8da87d4589c
# good: [c50a8a397d4abd994a9115230279d5fe922b4aa5] adapter: Add btd_request_authorization_cable_configured()
git bisect good c50a8a397d4abd994a9115230279d5fe922b4aa5
# bad: [c133489d54cb6d28c3fd308557937acbc5245f5e] battery: Add BT SIG reserved number used by Battery Service
git bisect bad c133489d54cb6d28c3fd308557937acbc5245f5e
# good: [e577e478e9cb1d1a22e63fd7d8fff07c471590de] gatt: Add implementation of link option
git bisect good e577e478e9cb1d1a22e63fd7d8fff07c471590de
# bad: [5b9596dac4d0e25c5179be8643726a02c058b00a] advertising: Add implementation of Duration and Timeout
git bisect bad 5b9596dac4d0e25c5179be8643726a02c058b00a
# bad: [f9a2b1f515c7f5dced80397f4ea891d6c372175d] client: Fix not detecting advertising instance is no longer valid
git bisect bad f9a2b1f515c7f5dced80397f4ea891d6c372175d
# bad: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d] doc/advertising-api:
Mark LEAdvertisingManager1 stable
git bisect bad d6e9539e31c6bb5afd39ec6f09c518d232e6345d
# good: [10760c91c234fe2bfedf924c9e61f31861c2dc72] gatt: Fix crash while disconnecting ATT
git bisect good 10760c91c234fe2bfedf924c9e61f31861c2dc72

# first bad commit: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d]
doc/advertising-api: Mark LEAdvertisingManager1 stable

For every step I ran the following script that compiles and install into the system and then restarts the service, followed by modprobe btusb. The order is important to simulate hotplug or a return from a suspended system.

Steps:

1. Run compile script from
https://gist.github.com/PVince81/95d01439490355babd4c405d28a548dc
2. Enable bluetooth in Plasma 5 panel
3. Run bluetoothctl
4. Run "connect" command with headset's address
5. Wait for connect. If it connects, test changing the volume in Plasma 5 which will trigger a pop sound to confirm it works.

Looking at the commit in question I can't tell in what way it is related to our headset issues. Maybe a bluez expert can help here ? :-)

Please let me know if I can help testing patches.

Cheers,

Vincent

Quoted 96 lines · Nathaniel McCallum

I'm seeing this too. My headphones go through a connect/disconnect cycle a few times and then quit. Unpairing and repairing does make it work.

Quoted 91 lines · Vincent Petry

Hello,

Quoted 13 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 10 lines · Vincent Petry

Hello,

I just joined the mailing list so can't directly reply to old messages, so sending with same title.

I'm experiencing the same issue as Robert here
https://www.spinics.net/lists/linux-bluetooth/msg73824.html, happening on the same laptop Dell XPS 13 but with different sub-model 9333, but on openSUSE Tumbleweed.

Quoted 7 lines

Quoted 5 lines

It looks like the bluez component is in a wrong state when either loading btusb with modprobe later on or resuming from suspend. The workaround is to restart the systemd bluetooth daemon. I suspect that plugging in USB bluetooth dongles would also have the same issue but I don't have one to test.

Does the system have any controller after resume? Does bluetoothctl report any device at all?

After resume from suspend, bluetoothctl sees the controller, yes and it does report my usual three devices from the saved list.

When I tell it to connect to the headset (which is turned on), I can hear the headset beep shortly which is the signal for connection, but then it disconnects again:
Attempting to connect to E3:XX:XX:XX:XX:XX
[CHG] Device E3:XX:XX:XX:XX:XX Connected: yes
Failed to connect: org.bluez.Error.Failed
[CHG] Device E3:XX:XX:XX:XX:XX Connected: no

If I tell it to connect to my bluetooth watch it stays connected.

Now I wanted to try accessing characteristics but the command "select-attribute" has gone missing ? I also tried "help gatt" as it seems to be a submenu but it says "Too many argumnets". Possibly another bug in bluez ? (I can send a separate email for this one if you want)

Anyway, I have a Python script that uses Dbus and said Python script is able to connect to my watch and talk to it even in this state.

So the bluez 5.48 regression seems to be specifically with headsets and also with scanning/discovering. I don't have any other device types to test with.

The workaround is to restart the bluetooth service and enable bluetooth afterwards.

Please make sure to look at
https://bugzilla.suse.com/show_bug.cgi?id=1076898 for logs I posted.

If you guys cannot reproduce the first regression I could try and bisect bluez locally to find the breaking change. For this I need to know how to set up bluez on my system after compiling. Is there any guide about this ? Should I tell it to overwrite the existing libs and reboot or is restarting the bluetooth service sufficient to make it use the newly installed version ?

Thanks,

Vincent

Quoted 17 lines

Quoted 17 lines

It used to work correctly before the upgrade from 5.47 to 5.48.

See my original report here for details:
https://bugzilla.suse.com/show_bug.cgi?id=1076898
Robert's report https://bugzilla.redhat.com/show_bug.cgi?id=1534857,
also confirmed by a third person.

Please let us know if this is reproducible on your side or whether it's an isolated case specific to our Dell hardware.

Thanks,

Vincent Petry

Quoted 5 lines

Quoted 4 lines

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Hi Vincent,

Quoted 36 lines · Vincent Petry

Hello,

I have bisected bluez between 5.47 (good) and 5.48 (bad) to find the breaking commit for the headset reconnect issue.

Here are the results:

git bisect start
# bad: [0d1e3b9c5754022c779da129025d493a198d49cf] Release 5.48 git bisect bad 0d1e3b9c5754022c779da129025d493a198d49cf
# good: [d139fd866241fe0d99b5e430f937c8d6160cc7dd] Release 5.47 git bisect good d139fd866241fe0d99b5e430f937c8d6160cc7dd
# bad: [65aaf36f2a36895e4a351ac3fa1cb8da87d4589c] mesh: Correct length test in agent.c:request_ascii
git bisect bad 65aaf36f2a36895e4a351ac3fa1cb8da87d4589c
# good: [c50a8a397d4abd994a9115230279d5fe922b4aa5] adapter: Add btd_request_authorization_cable_configured()
git bisect good c50a8a397d4abd994a9115230279d5fe922b4aa5
# bad: [c133489d54cb6d28c3fd308557937acbc5245f5e] battery: Add BT SIG reserved number used by Battery Service
git bisect bad c133489d54cb6d28c3fd308557937acbc5245f5e
# good: [e577e478e9cb1d1a22e63fd7d8fff07c471590de] gatt: Add implementation of link option
git bisect good e577e478e9cb1d1a22e63fd7d8fff07c471590de
# bad: [5b9596dac4d0e25c5179be8643726a02c058b00a] advertising: Add implementation of Duration and Timeout
git bisect bad 5b9596dac4d0e25c5179be8643726a02c058b00a
# bad: [f9a2b1f515c7f5dced80397f4ea891d6c372175d] client: Fix not detecting advertising instance is no longer valid
git bisect bad f9a2b1f515c7f5dced80397f4ea891d6c372175d
# bad: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d] doc/advertising-api:
Mark LEAdvertisingManager1 stable
git bisect bad d6e9539e31c6bb5afd39ec6f09c518d232e6345d
# good: [10760c91c234fe2bfedf924c9e61f31861c2dc72] gatt: Fix crash while disconnecting ATT
git bisect good 10760c91c234fe2bfedf924c9e61f31861c2dc72

Quoted 2 lines

# first bad commit: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d]
doc/advertising-api: Mark LEAdvertisingManager1 stable

Im not able to decipher this, what is the patch where the problem first appeared? Also could you collect the HCI trace and syslog when it happens?

Quoted 122 lines

For every step I ran the following script that compiles and install into the system and then restarts the service, followed by modprobe btusb. The order is important to simulate hotplug or a return from a suspended system.

Steps:

1. Run compile script from
https://gist.github.com/PVince81/95d01439490355babd4c405d28a548dc
2. Enable bluetooth in Plasma 5 panel
3. Run bluetoothctl
4. Run "connect" command with headset's address
5. Wait for connect. If it connects, test changing the volume in Plasma 5 which will trigger a pop sound to confirm it works.

Looking at the commit in question I can't tell in what way it is related to our headset issues. Maybe a bluez expert can help here ? :-)

Please let me know if I can help testing patches.

Cheers,

Vincent

Quoted 95 lines · Nathaniel McCallum

I'm seeing this too. My headphones go through a connect/disconnect cycle a few times and then quit. Unpairing and repairing does make it work.

Quoted 90 lines · Vincent Petry

Hello,

Quoted 13 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 10 lines · Vincent Petry

Hello,

I just joined the mailing list so can't directly reply to old messages, so sending with same title.

I'm experiencing the same issue as Robert here
https://www.spinics.net/lists/linux-bluetooth/msg73824.html, happening on the same laptop Dell XPS 13 but with different sub-model 9333, but on openSUSE Tumbleweed.

Quoted 7 lines

Quoted 5 lines

It looks like the bluez component is in a wrong state when either loading btusb with modprobe later on or resuming from suspend. The workaround is to restart the systemd bluetooth daemon. I suspect that plugging in USB bluetooth dongles would also have the same issue but I don't have one to test.

Does the system have any controller after resume? Does bluetoothctl report any device at all?

After resume from suspend, bluetoothctl sees the controller, yes and it does report my usual three devices from the saved list.

When I tell it to connect to the headset (which is turned on), I can hear the headset beep shortly which is the signal for connection, but then it disconnects again:
Attempting to connect to E3:XX:XX:XX:XX:XX
[CHG] Device E3:XX:XX:XX:XX:XX Connected: yes
Failed to connect: org.bluez.Error.Failed
[CHG] Device E3:XX:XX:XX:XX:XX Connected: no

If I tell it to connect to my bluetooth watch it stays connected.

Now I wanted to try accessing characteristics but the command "select-attribute" has gone missing ? I also tried "help gatt" as it seems to be a submenu but it says "Too many argumnets". Possibly another bug in bluez ? (I can send a separate email for this one if you want)

Anyway, I have a Python script that uses Dbus and said Python script is able to connect to my watch and talk to it even in this state.

So the bluez 5.48 regression seems to be specifically with headsets and also with scanning/discovering. I don't have any other device types to test with.

The workaround is to restart the bluetooth service and enable bluetooth afterwards.

Please make sure to look at
https://bugzilla.suse.com/show_bug.cgi?id=1076898 for logs I posted.

If you guys cannot reproduce the first regression I could try and bisect bluez locally to find the breaking change. For this I need to know how to set up bluez on my system after compiling. Is there any guide about this ? Should I tell it to overwrite the existing libs and reboot or is restarting the bluetooth service sufficient to make it use the newly installed version ?

Thanks,

Vincent

Quoted 17 lines

Quoted 17 lines

It used to work correctly before the upgrade from 5.47 to 5.48.

See my original report here for details:
https://bugzilla.suse.com/show_bug.cgi?id=1076898
Robert's report https://bugzilla.redhat.com/show_bug.cgi?id=1534857,
also confirmed by a third person.

Please let us know if this is reproducible on your side or whether it's an isolated case specific to our Dell hardware.

Thanks,

Vincent Petry

Quoted 4 lines

Quoted 4 lines

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Hi Luiz,

Quoted 41 lines

Hi Vincent,

Quoted 36 lines · Vincent Petry

Hello,

I have bisected bluez between 5.47 (good) and 5.48 (bad) to find the breaking commit for the headset reconnect issue.

Here are the results:

git bisect start
# bad: [0d1e3b9c5754022c779da129025d493a198d49cf] Release 5.48 git bisect bad 0d1e3b9c5754022c779da129025d493a198d49cf
# good: [d139fd866241fe0d99b5e430f937c8d6160cc7dd] Release 5.47 git bisect good d139fd866241fe0d99b5e430f937c8d6160cc7dd
# bad: [65aaf36f2a36895e4a351ac3fa1cb8da87d4589c] mesh: Correct length test in agent.c:request_ascii
git bisect bad 65aaf36f2a36895e4a351ac3fa1cb8da87d4589c
# good: [c50a8a397d4abd994a9115230279d5fe922b4aa5] adapter: Add btd_request_authorization_cable_configured()
git bisect good c50a8a397d4abd994a9115230279d5fe922b4aa5
# bad: [c133489d54cb6d28c3fd308557937acbc5245f5e] battery: Add BT SIG reserved number used by Battery Service
git bisect bad c133489d54cb6d28c3fd308557937acbc5245f5e
# good: [e577e478e9cb1d1a22e63fd7d8fff07c471590de] gatt: Add implementation of link option
git bisect good e577e478e9cb1d1a22e63fd7d8fff07c471590de
# bad: [5b9596dac4d0e25c5179be8643726a02c058b00a] advertising: Add implementation of Duration and Timeout
git bisect bad 5b9596dac4d0e25c5179be8643726a02c058b00a
# bad: [f9a2b1f515c7f5dced80397f4ea891d6c372175d] client: Fix not detecting advertising instance is no longer valid
git bisect bad f9a2b1f515c7f5dced80397f4ea891d6c372175d
# bad: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d] doc/advertising-api:
Mark LEAdvertisingManager1 stable
git bisect bad d6e9539e31c6bb5afd39ec6f09c518d232e6345d
# good: [10760c91c234fe2bfedf924c9e61f31861c2dc72] gatt: Fix crash while disconnecting ATT
git bisect good 10760c91c234fe2bfedf924c9e61f31861c2dc72

Quoted 2 lines

# first bad commit: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d]
doc/advertising-api: Mark LEAdvertisingManager1 stable

Quoted 3 lines

Im not able to decipher this, what is the patch where the problem first appeared? Also could you collect the HCI trace and syslog when it happens?

Please try this:

1. git clone git://git.kernel.org/pub/scm/bluetooth/bluez.git
2. cd bluez
3. git show d6e9539e31c6bb5afd39ec6f09c518d232e6345d

This will show your the first bad commit / the patch that introduces the issue.

For the syslog, see attachments to my original report here
https://bugzilla.suse.com/show_bug.cgi?id=1076898

Do you have more information about how I could get the HCI trace ? Should I run bluetoothd through gdb and query the backtrace from the point where the error message happens, if that's what you are asking for ?

Hi Vincent,

Quoted 56 lines · Vincent Petry

Hi Luiz,

Quoted 41 lines

Hi Vincent,

Quoted 36 lines · Vincent Petry

Hello,

I have bisected bluez between 5.47 (good) and 5.48 (bad) to find the breaking commit for the headset reconnect issue.

Here are the results:

git bisect start
# bad: [0d1e3b9c5754022c779da129025d493a198d49cf] Release 5.48 git bisect bad 0d1e3b9c5754022c779da129025d493a198d49cf
# good: [d139fd866241fe0d99b5e430f937c8d6160cc7dd] Release 5.47 git bisect good d139fd866241fe0d99b5e430f937c8d6160cc7dd
# bad: [65aaf36f2a36895e4a351ac3fa1cb8da87d4589c] mesh: Correct length test in agent.c:request_ascii
git bisect bad 65aaf36f2a36895e4a351ac3fa1cb8da87d4589c
# good: [c50a8a397d4abd994a9115230279d5fe922b4aa5] adapter: Add btd_request_authorization_cable_configured()
git bisect good c50a8a397d4abd994a9115230279d5fe922b4aa5
# bad: [c133489d54cb6d28c3fd308557937acbc5245f5e] battery: Add BT SIG reserved number used by Battery Service
git bisect bad c133489d54cb6d28c3fd308557937acbc5245f5e
# good: [e577e478e9cb1d1a22e63fd7d8fff07c471590de] gatt: Add implementation of link option
git bisect good e577e478e9cb1d1a22e63fd7d8fff07c471590de
# bad: [5b9596dac4d0e25c5179be8643726a02c058b00a] advertising: Add implementation of Duration and Timeout
git bisect bad 5b9596dac4d0e25c5179be8643726a02c058b00a
# bad: [f9a2b1f515c7f5dced80397f4ea891d6c372175d] client: Fix not detecting advertising instance is no longer valid
git bisect bad f9a2b1f515c7f5dced80397f4ea891d6c372175d
# bad: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d] doc/advertising-api:
Mark LEAdvertisingManager1 stable
git bisect bad d6e9539e31c6bb5afd39ec6f09c518d232e6345d
# good: [10760c91c234fe2bfedf924c9e61f31861c2dc72] gatt: Fix crash while disconnecting ATT
git bisect good 10760c91c234fe2bfedf924c9e61f31861c2dc72

Quoted 2 lines

# first bad commit: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d]
doc/advertising-api: Mark LEAdvertisingManager1 stable

Quoted 3 lines

Im not able to decipher this, what is the patch where the problem first appeared? Also could you collect the HCI trace and syslog when it happens?

Please try this:

1. git clone git://git.kernel.org/pub/scm/bluetooth/bluez.git
2. cd bluez
3. git show d6e9539e31c6bb5afd39ec6f09c518d232e6345d

This will show your the first bad commit / the patch that introduces the issue.

Quoted 6 lines

For the syslog, see attachments to my original report here
https://bugzilla.suse.com/show_bug.cgi?id=1076898

Do you have more information about how I could get the HCI trace ? Should I run bluetoothd through gdb and query the backtrace from the point where the error message happens, if that's what you are asking for ?

Jan 20 15:50:47 vvortex.ttv pulseaudio[1964]: [pulseaudio]
bluez5-util.c: Information about device
/org/bluez/hci0/dev_E3_28_E9_20_58_08 is invalid
Jan 20 15:50:47 vvortex.ttv bluetoothd[3136]: Endpoint replied with an

error: org.bluez.Error.InvalidArguments

So this is really PulseAudio rejecting the connection, it probably loose track of the objects when resuming or we did not send the objects but in that case bluetoothctl would not be able to list them as well.

Hi Vincent,

Quoted 68 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 55 lines · Vincent Petry

Hi Luiz,

Quoted 41 lines

Hi Vincent,

Quoted 36 lines · Vincent Petry

Hello,

I have bisected bluez between 5.47 (good) and 5.48 (bad) to find the breaking commit for the headset reconnect issue.

Here are the results:

git bisect start
# bad: [0d1e3b9c5754022c779da129025d493a198d49cf] Release 5.48 git bisect bad 0d1e3b9c5754022c779da129025d493a198d49cf
# good: [d139fd866241fe0d99b5e430f937c8d6160cc7dd] Release 5.47 git bisect good d139fd866241fe0d99b5e430f937c8d6160cc7dd
# bad: [65aaf36f2a36895e4a351ac3fa1cb8da87d4589c] mesh: Correct length test in agent.c:request_ascii
git bisect bad 65aaf36f2a36895e4a351ac3fa1cb8da87d4589c
# good: [c50a8a397d4abd994a9115230279d5fe922b4aa5] adapter: Add btd_request_authorization_cable_configured()
git bisect good c50a8a397d4abd994a9115230279d5fe922b4aa5
# bad: [c133489d54cb6d28c3fd308557937acbc5245f5e] battery: Add BT SIG reserved number used by Battery Service
git bisect bad c133489d54cb6d28c3fd308557937acbc5245f5e
# good: [e577e478e9cb1d1a22e63fd7d8fff07c471590de] gatt: Add implementation of link option
git bisect good e577e478e9cb1d1a22e63fd7d8fff07c471590de
# bad: [5b9596dac4d0e25c5179be8643726a02c058b00a] advertising: Add implementation of Duration and Timeout
git bisect bad 5b9596dac4d0e25c5179be8643726a02c058b00a
# bad: [f9a2b1f515c7f5dced80397f4ea891d6c372175d] client: Fix not detecting advertising instance is no longer valid
git bisect bad f9a2b1f515c7f5dced80397f4ea891d6c372175d
# bad: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d] doc/advertising-api:
Mark LEAdvertisingManager1 stable
git bisect bad d6e9539e31c6bb5afd39ec6f09c518d232e6345d
# good: [10760c91c234fe2bfedf924c9e61f31861c2dc72] gatt: Fix crash while disconnecting ATT
git bisect good 10760c91c234fe2bfedf924c9e61f31861c2dc72

Quoted 2 lines

# first bad commit: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d]
doc/advertising-api: Mark LEAdvertisingManager1 stable

Quoted 3 lines

Im not able to decipher this, what is the patch where the problem first appeared? Also could you collect the HCI trace and syslog when it happens?

Please try this:

1. git clone git://git.kernel.org/pub/scm/bluetooth/bluez.git
2. cd bluez
3. git show d6e9539e31c6bb5afd39ec6f09c518d232e6345d

This will show your the first bad commit / the patch that introduces the issue.

Quoted 6 lines

For the syslog, see attachments to my original report here
https://bugzilla.suse.com/show_bug.cgi?id=1076898

Do you have more information about how I could get the HCI trace ? Should I run bluetoothd through gdb and query the backtrace from the point where the error message happens, if that's what you are asking for ?

Jan 20 15:50:47 vvortex.ttv pulseaudio[1964]: [pulseaudio]
bluez5-util.c: Information about device
/org/bluez/hci0/dev_E3_28_E9_20_58_08 is invalid
Jan 20 15:50:47 vvortex.ttv bluetoothd[3136]: Endpoint replied with an

Quoted 6 lines

error: org.bluez.Error.InvalidArguments

So this is really PulseAudio rejecting the connection, it probably loose track of the objects when resuming or we did not send the objects but in that case bluetoothctl would not be able to list them as well.

And I couldn't reproduce it myself:
https://gist.github.com/anonymous/423edb41e572577b8507d8d0662acc84

Hi Luiz,

Can you give me some pointers where I should put the gdb breakpoint to get a useful trace ?

I also saw that there is some DBG function logging things. How do I enable this logging and from where can I get its output ? Useful would probably to log some internal state with and without returning from suspend.

Regarding the breaking patch, it seems to be related to some advertising API that used to be marked experimental and is now not experimental any more in 5.48.
Does maybe pulseaudio use this API and had a fallback at the time said API was disabled ? And now that it's enabled its code path changed and maybe triggered a hidden bug ? Would need to look at the pulseaudio bluetooth source code.
Or does the patch in question enabled advertising where no advertising was done before ? Maybe it is advertising too early at a time where the system hasn't fully resumed from suspend ?

My pulseaudio version: pulseaudio-11.1-2.1.x86_64

Would be good if the other affected users post their distro + pulseaudio versions for cross-reference.

Cheers,

Vincent

Quoted 74 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 70 lines · Luiz Augusto von Dentz

Hi Vincent,

Quoted 55 lines · Vincent Petry

Hi Luiz,

Quoted 41 lines

Hi Vincent,

Quoted 36 lines · Vincent Petry

Hello,

I have bisected bluez between 5.47 (good) and 5.48 (bad) to find the breaking commit for the headset reconnect issue.

Here are the results:

git bisect start
# bad: [0d1e3b9c5754022c779da129025d493a198d49cf] Release 5.48 git bisect bad 0d1e3b9c5754022c779da129025d493a198d49cf
# good: [d139fd866241fe0d99b5e430f937c8d6160cc7dd] Release 5.47 git bisect good d139fd866241fe0d99b5e430f937c8d6160cc7dd
# bad: [65aaf36f2a36895e4a351ac3fa1cb8da87d4589c] mesh: Correct length test in agent.c:request_ascii
git bisect bad 65aaf36f2a36895e4a351ac3fa1cb8da87d4589c
# good: [c50a8a397d4abd994a9115230279d5fe922b4aa5] adapter: Add btd_request_authorization_cable_configured()
git bisect good c50a8a397d4abd994a9115230279d5fe922b4aa5
# bad: [c133489d54cb6d28c3fd308557937acbc5245f5e] battery: Add BT SIG reserved number used by Battery Service
git bisect bad c133489d54cb6d28c3fd308557937acbc5245f5e
# good: [e577e478e9cb1d1a22e63fd7d8fff07c471590de] gatt: Add implementation of link option
git bisect good e577e478e9cb1d1a22e63fd7d8fff07c471590de
# bad: [5b9596dac4d0e25c5179be8643726a02c058b00a] advertising: Add implementation of Duration and Timeout
git bisect bad 5b9596dac4d0e25c5179be8643726a02c058b00a
# bad: [f9a2b1f515c7f5dced80397f4ea891d6c372175d] client: Fix not detecting advertising instance is no longer valid
git bisect bad f9a2b1f515c7f5dced80397f4ea891d6c372175d
# bad: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d] doc/advertising-api:
Mark LEAdvertisingManager1 stable
git bisect bad d6e9539e31c6bb5afd39ec6f09c518d232e6345d
# good: [10760c91c234fe2bfedf924c9e61f31861c2dc72] gatt: Fix crash while disconnecting ATT
git bisect good 10760c91c234fe2bfedf924c9e61f31861c2dc72

Quoted 2 lines

# first bad commit: [d6e9539e31c6bb5afd39ec6f09c518d232e6345d]
doc/advertising-api: Mark LEAdvertisingManager1 stable

Quoted 3 lines

Im not able to decipher this, what is the patch where the problem first appeared? Also could you collect the HCI trace and syslog when it happens?

Please try this:

1. git clone git://git.kernel.org/pub/scm/bluetooth/bluez.git
2. cd bluez
3. git show d6e9539e31c6bb5afd39ec6f09c518d232e6345d

This will show your the first bad commit / the patch that introduces the issue.

Quoted 6 lines

For the syslog, see attachments to my original report here
https://bugzilla.suse.com/show_bug.cgi?id=1076898

Do you have more information about how I could get the HCI trace ? Should I run bluetoothd through gdb and query the backtrace from the point where the error message happens, if that's what you are asking for ?

Jan 20 15:50:47 vvortex.ttv pulseaudio[1964]: [pulseaudio]
bluez5-util.c: Information about device
/org/bluez/hci0/dev_E3_28_E9_20_58_08 is invalid
Jan 20 15:50:47 vvortex.ttv bluetoothd[3136]: Endpoint replied with an

error: org.bluez.Error.InvalidArguments

Quoted 7 lines

Quoted 4 lines

So this is really PulseAudio rejecting the connection, it probably loose track of the objects when resuming or we did not send the objects but in that case bluetoothctl would not be able to list them as well.

And I couldn't reproduce it myself:
https://gist.github.com/anonymous/423edb41e572577b8507d8d0662acc84

--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

2018-02-07 7:52 GMT+01:00 Vincent Petry <[email protected]>:

Quoted 21 lines

Hi Luiz,

Can you give me some pointers where I should put the gdb breakpoint to get a useful trace ?

I also saw that there is some DBG function logging things. How do I enable this logging and from where can I get its output ? Useful would probably to log some internal state with and without returning from suspend.

Regarding the breaking patch, it seems to be related to some advertising API that used to be marked experimental and is now not experimental any more in 5.48.
Does maybe pulseaudio use this API and had a fallback at the time said API was disabled ? And now that it's enabled its code path changed and maybe triggered a hidden bug ? Would need to look at the pulseaudio bluetooth source code.
Or does the patch in question enabled advertising where no advertising was done before ? Maybe it is advertising too early at a time where the system hasn't fully resumed from suspend ?

Quoted 4 lines

My pulseaudio version: pulseaudio-11.1-2.1.x86_64

Would be good if the other affected users post their distro + pulseaudio versions for cross-reference.

Hi, I am also affected by this since updating to bluez 5.48.

My distro is Arch Linux, pulseaudio 11.1-1, linux 4.14.15, using a Bose QuietComfort 35 headset with an Asus zenbook laptop (Intel 7260 wireless chip).

Please let me know if I can be of any help.

Hi,

Quoted 25 lines · Julien Nicoulaud

2018-02-07 7:52 GMT+01:00 Vincent Petry <[email protected]>:

Quoted 20 lines

Hi Luiz,

Can you give me some pointers where I should put the gdb breakpoint to get a useful trace ?

I also saw that there is some DBG function logging things. How do I enable this logging and from where can I get its output ? Useful would probably to log some internal state with and without returning from suspend.

Regarding the breaking patch, it seems to be related to some advertising API that used to be marked experimental and is now not experimental any more in 5.48.
Does maybe pulseaudio use this API and had a fallback at the time said API was disabled ? And now that it's enabled its code path changed and maybe triggered a hidden bug ? Would need to look at the pulseaudio bluetooth source code.
Or does the patch in question enabled advertising where no advertising was done before ? Maybe it is advertising too early at a time where the system hasn't fully resumed from suspend ?

Quoted 4 lines

My pulseaudio version: pulseaudio-11.1-2.1.x86_64

Would be good if the other affected users post their distro + pulseaudio versions for cross-reference.

Quoted 7 lines

Hi, I am also affected by this since updating to bluez 5.48.

My distro is Arch Linux, pulseaudio 11.1-1, linux 4.14.15, using a Bose QuietComfort 35 headset with an Asus zenbook laptop (Intel 7260 wireless chip).

Please let me know if I can be of any help.

Please check with the patch Ive sent yesterday: core: Fixes order InterfaceAdded