ITD not trying to reconnect after PineTime re-enters range #44

New Issue

hafl · 2022-11-28T04:46:30Z

hafl commented

2022-11-28 04:46:30 +00:00

Steps to reproduce:

launch itd
confirm pinetime is connected
wander out of range for a few minutes
re-enter range

Per bluetoothctl (bluetoothctl devices Connected) there no connected devices.
Per pinetime, no bt icon is displayed.

The actual steps to reproduce may require wandering in and out of range more than once before staying out of range for a few minutes.

Built from source, git log shows 73a679d10bf09a965b5afd3d0e81f51813325c67 as the latest commit.

Steps to reproduce: * launch itd * confirm pinetime is connected * wander out of range for a few minutes * re-enter range Per bluetoothctl (`bluetoothctl devices Connected`) there no connected devices. Per pinetime, no bt icon is displayed. The actual steps to reproduce may require wandering in and out of range more than once before staying out of range for a few minutes. Built from source, git log shows `73a679d10bf09a965b5afd3d0e81f51813325c67` as the latest commit.

itd-outputs

6.0 KiB

hafl commented

2022-11-28 04:50:19 +00:00

Sorry, forgot to add, this was on Arch Linux Arm, Pine64 PinePhonePro.

hafl commented

2022-11-28 04:57:09 +00:00

pacman -Q | grep -i bluez
bluez 5.66-1
bluez-libs 5.66-1
bluez-plugins 5.66-1
bluez-qt 5.100.0-1
bluez-tools 0.2.0-5
bluez-utils 5.66-1

``` pacman -Q | grep -i bluez bluez 5.66-1 bluez-libs 5.66-1 bluez-plugins 5.66-1 bluez-qt 5.100.0-1 bluez-tools 0.2.0-5 bluez-utils 5.66-1 ```

hafl changed title from ~~IIT not trying to reconnect after PineTime re-enters range~~ to ITD not trying to reconnect after PineTime re-enters range

2022-11-28 05:16:17 +00:00

Elara6331 commented

2022-11-28 21:21:30 +00:00

In your output, I can see these lines:

11:32PM DBG Device not connected, connecting
11:32PM DBG InfiniTime device found in list mac=D7:F3:C3:74:52:44
11:32PM DBG Device not connected, connecting
11:32PM DBG Reconnected to device, running OnReconnect callback
11:32PM DBG Checking characteristic status

11:32PM DBG InfiniTime device found in list mac=D7:F3:C3:74:52:44
11:32PM DBG Device not connected, connecting
11:32PM DBG Reconnected to device, running OnReconnect callback

Which tells me ITD actually did reconnect to the device

In your output, I can see these lines: ``` 11:32PM DBG Device not connected, connecting 11:32PM DBG InfiniTime device found in list mac=D7:F3:C3:74:52:44 11:32PM DBG Device not connected, connecting 11:32PM DBG Reconnected to device, running OnReconnect callback 11:32PM DBG Checking characteristic status ``` ``` 11:32PM DBG InfiniTime device found in list mac=D7:F3:C3:74:52:44 11:32PM DBG Device not connected, connecting 11:32PM DBG Reconnected to device, running OnReconnect callback ``` Which tells me ITD actually did reconnect to the device

hafl commented

2022-11-29 02:22:11 +00:00

After reporting this, it did not display the BT icon on the PineTime nor did any future notifications pop up. I'll see if I can capture any additional information in a future reply.

hafl commented

2022-11-29 03:01:20 +00:00

Actually, I guess there isn't much more to capture.

$ ./itctl notify one two
10:00PM FTL Error while running app error="not connected"

And the output of itd has changed by one line:

10:00PM DBG Checking characteristic status

Actually, I guess there isn't much more to capture. ``` $ ./itctl notify one two 10:00PM FTL Error while running app error="not connected" ``` And the output of itd has changed by one line: ``` 10:00PM DBG Checking characteristic status ```

Ghost commented

2022-12-14 03:59:56 +00:00

I'm seeing the same problem on Arch Linux on AMD. I've attached a debug log where I've inserted a few blank lines each time I walked out of range for a few seconds. Each time I came back in range I sent a notification. Everything worked fine the first two times I returned, but the third time nothing at all was logged, the watch claimed to be disconnected, and sending a notification resulted in only the single "Checking characteristic status" line you see at the end.

itd.log

6.6 KiB

Elara6331 commented

2023-02-13 03:41:36 +00:00

Actually, I guess there isn't much more to capture.
$ ./itctl notify one two
10:00PM FTL Error while running app error="not connected"
And the output of itd has changed by one line:
10:00PM DBG Checking characteristic status   

This indicates that InfiniTime isn't connected, so it's normal in that case. If you try to reconnect to manually through bluetooth settings, does ITD display a connection notification? If not, this is likely due to BlueZ being notoriously unreliable in the way it handles connections. Sometimes, it just decides to block forever without ever returning a response, which will stop ITD's reconnect loop and prevent it from responding to further events. Does restarting ITD fix it until it decides to break again? That would confirm this as the issue.

> Actually, I guess there isn't much more to capture. > > ``` > $ ./itctl notify one two > 10:00PM FTL Error while running app error="not connected" > ``` > > And the output of itd has changed by one line: > ``` > 10:00PM DBG Checking characteristic status > ``` This indicates that InfiniTime isn't connected, so it's normal in that case. If you try to reconnect to manually through bluetooth settings, does ITD display a connection notification? If not, this is likely due to BlueZ being notoriously unreliable in the way it handles connections. Sometimes, it just decides to block forever without ever returning a response, which will stop ITD's reconnect loop and prevent it from responding to further events. Does restarting ITD fix it until it decides to break again? That would confirm this as the issue.

hafl commented

2023-02-13 11:09:21 +00:00

Yes. Restarting ITD (and I believe taking no other actions, IIRC, I'll double check this later and update again, I have just been using the watch standalone ever since) at that point will cause it to resume functioning until it decides to break again.

Ghost commented

2023-02-18 03:08:47 +00:00

Arsen6331: Yes, based on a bit of testing, it seems to be the problem you are describing. I took these steps:

Started itd with the watch nearby. It connected and displayed the connection message as expected.
Walked out of range and back. It spontaneously reconnected and displayed the connection message.
Walked out of range and back again. It failed to spontaneously reconnect. Bluetooth manager did not display a "connect" option, but running bluetoothctl connect $mac caused it to connect. On reconnection, no messages were logged by itd and no connection message was displayed, but sending a notification with notify-send did cause the notification to show up on the watch.
Walked out of range and back again. It failed to spontaneously connect. Restarted itd, and it connected and displayed the connection message as expected.

So I think we are indeed seeing BlueZ's "notorious unreliability". 😔 Is there any possibility of a workaround, short of writing a script that restarts itd when the watch disconnects?

Arsen6331: Yes, based on a bit of testing, it seems to be the problem you are describing. I took these steps: - Started itd with the watch nearby. It connected and displayed the connection message as expected. - Walked out of range and back. It spontaneously reconnected and displayed the connection message. - Walked out of range and back again. It failed to spontaneously reconnect. Bluetooth manager did not display a "connect" option, but running `bluetoothctl connect $mac` caused it to connect. On reconnection, *no* messages were logged by itd and *no* connection message was displayed, but sending a notification with `notify-send` *did* cause the notification to show up on the watch. - Walked out of range and back again. It failed to spontaneously connect. Restarted itd, and it connected and displayed the connection message as expected. So I think we are indeed seeing BlueZ's "notorious unreliability". 😔 Is there any possibility of a workaround, short of writing a script that restarts itd when the watch disconnects?

Ghost commented

2023-08-14 20:45:07 +00:00

Similar issue with the pinephone waking up from deep sleep mode. Sometimes it won't reconnect to the pinetime and I have to restart ITD

Sign in to join this conversation.