Skip to content

During sleep, heartbeat thread stuck, causing disconnects on any wakelocks

Steps

  1. Connect to core using latest version (6dc4486a)
  2. Put Quasseldroid in the background, waiting a while
    • Not yet determined the exact length of time, possibly 2 minute heartbeat timeout, possibly another condition
  3. Receive a notification

Expected

Notification shows and plays sound once, Quasseldroid remains connected.

Actual

Quasseldroid disconnects and reconnects. Sometimes it'll save the notification state, avoiding the noise, other times it'll disconnect before it can save the notification-seen flag, resulting in a seeming double-notification (sound/vibration plays again).

Additional

I haven't yet figured out a consistent cause for this, but having the phone idle with screen off while using Quassel desktop to chat in other buffers seems to trigger it with vague reliability.

It might help to add debug logging around the heartbeat timeout.

ADB logcat of a double-notification

06-13 21:43:44.843 11640 13701 W CoreConnection: Error encountered in connection
06-13 21:43:44.847 11640 11670 I QuasselService: Reconnect: Scheduling backoff in 5 seconds
06-13 21:43:44.848 11640 13701 W CoreConnection: java.nio.channels.AsynchronousCloseException
06-13 21:43:44.848 11640 13701 W CoreConnection: 	at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:206)
06-13 21:43:44.848 11640 13701 W CoreConnection: 	at de.kuschku.quasseldroid.util.backport.ReadableWrappedChannel.read(ReadableWrappedChannel.kt:61)
06-13 21:43:44.848 11640 13701 W CoreConnection: 	at de.kuschku.libquassel.util.nio.WrappedChannel.read(WrappedChannel.kt:141)
06-13 21:43:44.848 11640 13701 W CoreConnection: 	at de.kuschku.libquassel.connection.CoreConnection.run(CoreConnection.kt:207)
06-13 21:43:44.850 11640 13701 W CoreConnection: Last sent message: [QVariant.Typed(int, 6}), QVariant.Typed(QDateTime, 2018-06-14T02:43:45.043Z})]
[...]
06-13 21:43:49.882 11640 11670 I QuasselService: Reconnect: Scheduled backoff happened
06-13 21:43:49.884 11640 11670 I SessionManager: Autoreconnect triggered

This has happened several times with the same debug messages.

Edited by Shane Synan