Automatic reconnect fails with repeated WiFi/modem handoff
Steps
- Connect to core
- Roam around an area that involves signal switching
- WiFi roaming within an SSID (e.g. corporate/university networks)
- Multi-SSID situations (to/from personal networks)
- Repeated WiFi/modem handoff
Expected
QuasselDroid always reconnects so long as the first connection had succeeded.
Actual
QuasselDroid eventually gives up, with Connection Lost in the core notification and the main UI requiring a manual disconnect to reconnect.
Additional
CoreConnection.kt appears to get stuck with an unexpected exception, and does not reconnect.
Trimmed logcat
05-06 01:02:42.073 3356 3356 I wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED bssid=a0:e0:af:AA:AA:AA reason=3 locally_generated=1
05-06 01:02:42.132 3356 3356 I wpa_supplicant: wlan0: Trying to associate with SSID 'Bbbbbbb'
05-06 01:02:42.217 32069 14771 W CoreConnection: Error encountered in connection
05-06 01:02:42.217 2275 2677 I Netd : Destroyed 7 sockets on XX.XX.XX.XXX in 2.1 ms
05-06 01:02:42.217 4030 14589 V NativeCrypto: Read error: ssl=0x809ff888: I/O error during system call, Software caused connection abort
05-06 01:02:42.217 32069 14771 W CoreConnection: javax.net.ssl.SSLException: Read error: ssl=0x83cc7e00: I/O error during system call, Software caused connection abort
05-06 01:02:42.217 32069 14771 W CoreConnection: at com.android.org.conscrypt.NativeCrypto.SSL_read(Native Method)
05-06 01:02:42.217 32069 14771 W CoreConnection: at com.android.org.conscrypt.OpenSSLSocketImpl$SSLInputStream.read(OpenSSLSocketImpl.java:758)
05-06 01:02:42.217 32069 14771 W CoreConnection: at java.util.zip.InflaterInputStream.fill(InflaterInputStream.java:243)
05-06 01:02:42.217 32069 14771 W CoreConnection: at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:158)
05-06 01:02:42.217 32069 14771 W CoreConnection: at de.kuschku.quasseldroid.util.backport.ReadableWrappedChannel.read(ReadableWrappedChannel.kt:54)
05-06 01:02:42.217 32069 14771 W CoreConnection: at de.kuschku.libquassel.util.nio.WrappedChannel.read(WrappedChannel.kt:141)
05-06 01:02:42.217 32069 14771 W CoreConnection: at de.kuschku.libquassel.connection.CoreConnection.run(CoreConnection.kt:198)
05-06 01:02:42.218 32069 14771 W CoreConnection: Last sent message: [QVariant.Typed(int, 5}), QVariant.Typed(QDateTime, 2018-05-06T06:02:41.282Z})]
05-06 01:02:42.219 32069 14771 W CoreConnection: Error encountered while closing connection
05-06 01:02:42.220 32069 14771 W CoreConnection: javax.net.ssl.SSLException: Write error: ssl=0x83cc7e00: I/O error during system call, Broken pipe
05-06 01:02:42.220 32069 14771 W CoreConnection: at com.android.org.conscrypt.NativeCrypto.SSL_write(Native Method)
05-06 01:02:42.220 32069 14771 W CoreConnection: at com.android.org.conscrypt.OpenSSLSocketImpl$SSLOutputStream.write(OpenSSLSocketImpl.java:824)
05-06 01:02:42.220 32069 14771 W CoreConnection: at java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.java:254)
05-06 01:02:42.220 32069 14771 W CoreConnection: at java.util.zip.DeflaterOutputStream.finish(DeflaterOutputStream.java:227)
05-06 01:02:42.220 32069 14771 W CoreConnection: at java.util.zip.DeflaterOutputStream.close(DeflaterOutputStream.java:239)
05-06 01:02:42.220 32069 14771 W CoreConnection: at de.kuschku.quasseldroid.util.backport.WritableWrappedChannel.implCloseChannel(WritableWrappedChannel.kt:66)
05-06 01:02:42.220 32069 14771 W CoreConnection: at java.nio.channels.spi.AbstractInterruptibleChannel.close(AbstractInterruptibleChannel.java:116)
05-06 01:02:42.220 32069 14771 W CoreConnection: at de.kuschku.libquassel.util.nio.WrappedChannel.close(WrappedChannel.kt:206)
05-06 01:02:42.220 32069 14771 W CoreConnection: at de.kuschku.libquassel.connection.CoreConnection.close(CoreConnection.kt:150)
05-06 01:02:42.220 32069 14771 W CoreConnection: at de.kuschku.libquassel.connection.CoreConnection.run(CoreConnection.kt:237)
05-06 01:02:42.220 4030 14589 V NativeCrypto: SSL shutdown failed: ssl=0x809ff888: I/O error during system call, Broken pipe
05-06 01:02:42.220 4030 14589 E WakeLock: release without a matched acquire!
05-06 01:02:42.222 2275 2685 D CommandListener: Clearing all IP addresses on wlan0
05-06 01:02:42.223 4030 14589 E GCM : Connection closed with errorCode 20
05-06 01:02:42.223 2687 2687 V NotificationService: pkg=com.iskrembilen.quasseldroid canInterrupt=false intercept=true
05-06 01:02:42.224 2687 4733 D ConnectivityService: reportNetworkConnectivity(306, false) by 10043
05-06 01:02:42.224 2687 14555 I chatty : uid=1000 system_server expire 2 lines
05-06 01:02:42.226 4030 14589 E WakeLock: release without a matched acquire!
05-06 01:02:42.229 3356 3356 I wpa_supplicant: wlan0: Associated with 00:20:91:BB:BB:BB
05-06 01:02:42.230 3356 3356 I wpa_supplicant: wlan0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully (based on lower layer success)
05-06 01:02:42.234 2687 3327 D ConnectivityService: NetworkAgentInfo [WIFI () - 306] EVENT_NETWORK_INFO_CHANGED, going from CONNECTED to DISCONNECTED
05-06 01:02:42.234 2687 3327 D ConnectivityService: NetworkAgentInfo [WIFI () - 306] got DISCONNECTED, was satisfying 9
05-06 01:02:42.240 4030 4030 I GeofencerStateMachine: sendWifiConnectivityChanged: connectivity=false
05-06 01:02:42.241 3356 3356 I wpa_supplicant: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
[…]
05-06 01:02:42.269 3356 3356 I wpa_supplicant: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:20:91:BB:BB:BB completed [id=0 id_str=XXXXXX]
05-06 01:02:42.271 3356 3356 I wpa_supplicant: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US
[…]
05-06 01:02:42.275 2265 19425 I hash_map_utils: key: 'all_call_states' value: ''
05-06 01:02:42.285 2687 3327 D ConnectivityService: Sending DISCONNECTED broadcast for type 1 NetworkAgentInfo [WIFI () - 306] isDefaultNetwork=true
[…]
05-06 01:02:42.416 2687 3323 D ConnectivityService: registerNetworkAgent NetworkAgentInfo{ ni{[type: WIFI[], state: CONNECTING/CONNECTING, reason: (unspecified), extra: "Bbbbbbb", […] }
05-06 01:02:42.421 3356 3356 E wpa_supplicant: PNO: In assoc process
[…]
05-06 01:02:42.435 2687 3323 D WifiStateMachine: Start Dhcp Watchdog 68
05-06 01:02:42.441 2275 2685 E Netd : netlink response contains error (No such file or directory)
05-06 01:02:42.441 2687 3325 E WifiPnoScanStateMachine: Unexpected message 160012
05-06 01:02:42.449 2687 3323 D WifiNative-wlan0: configureNeighborDiscoveryOffload(true)
05-06 01:02:42.449 2687 3323 D WifiNative-wlan0: configureNeighborDiscoveryOffload(true) returned: -95
[…]
05-06 01:02:42.503 2687 2687 V NotificationService: pkg=com.iskrembilen.quasseldroid canInterrupt=false intercept=true
05-06 01:02:42.509 2265 20248 I hash_map_utils: key: 'all_call_states' value: ''
05-06 01:02:42.510 2265 20247 I hash_map_utils: key: 'all_call_states' value: ''
05-06 01:02:42.521 32069 14892 W CoreConnection: Error encountered in connection
05-06 01:02:42.521 32069 14892 W CoreConnection:
05-06 01:02:42.522 32069 14892 W CoreConnection: Last sent message: [QVariant.Typed(int, 5}), QVariant.Typed(QDateTime, 2018-05-06T06:02:41.282Z})]