search

ably / ably-java

Java, Android, Clojure and Scala client library SDK for Ably realtime messaging service
https://ably.com/download
Apache License 2.0
85 stars 39 forks source link

Transport state change events suppressed after loss of network #233

Open paddybyers opened 7 years ago

paddybyers commented 7 years ago

A realtime library instance gets into a state, after some combination of having lost (and regained) a network connection, and a failing authCallback, in which all transport events are discarded as a result of the transport validity check: https://github.com/ably/ably-java/blob/master/lib/src/main/java/io/ably/lib/transport/ConnectionManager.java#L223

This means that if there is a subsequent periodic sequence reconnection attempts (from a consistently failing authCallback) all transport disconnection events are discarded, and the connection thus never enters suspended.

Log extract:

11-15 15:49:17.379 26963 26963 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:49:17.380 26963 26963 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:49:17.387 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:49:17.388 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:49:24.088 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:49:24.089 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
//Network there but Auth Callback fails\
11-15 15:49:24.091 26963 27062 V io.ably.lib.transport.ConnectionManager: setState(): setting disconnected\
11-15 15:49:24.092 26963 27062 D io.ably.lib.transport.ConnectionManager: setState(): setting disconnected\
11-15 15:49:55.527 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:49:55.529 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:49:55.534 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:49:55.535 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:49:55.537 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:49:55.538 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:49:59.209 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:49:59.209 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:50:29.210 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:50:29.212 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:50:29.213 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:50:29.215 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:50:29.216 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:50:29.217 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:50:29.518 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:50:29.518 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:50:59.519 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:50:59.521 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:50:59.522 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:50:59.524 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:50:59.525 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:50:59.526 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:50:59.831 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:50:59.831 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:51:29.832 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:51:29.834 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:51:29.835 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:51:29.837 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:51:29.838 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:51:29.839 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:51:30.156 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:51:30.157 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:52:00.158 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:52:00.159 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:52:00.161 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:52:00.162 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:52:00.163 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:52:00.164 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:52:00.564 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:52:00.564 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:52:00.564 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:52:30.566 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:52:30.568 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:52:30.569 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:52:30.571 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:52:30.572 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:52:30.574 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:52:30.869 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:52:30.869 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:53:00.871 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:53:00.873 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:53:00.874 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:53:00.875 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:53:00.877 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:53:00.880 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:53:01.179 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:53:01.180 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:53:31.181 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:53:31.181 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:53:31.181 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:53:31.182 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:53:31.182 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:53:31.183 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:53:31.368 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:53:31.368 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
//Network Disconnected\
11-15 15:53:31.368 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:54:01.369 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:54:01.369 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:54:01.370 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:54:01.370 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:54:01.371 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:54:01.372 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:54:01.398 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:54:01.398 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:54:31.400 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:54:31.401 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:54:31.402 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:54:31.403 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:54:31.404 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:54:31.405 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:54:31.441 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:54:31.442 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:55:01.443 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:55:01.444 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:55:01.445 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:55:01.446 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:55:01.447 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:55:01.448 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:55:01.483 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:55:01.484 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:55:31.485 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:55:31.486 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:55:31.488 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:55:31.489 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:55:31.490 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:55:31.491 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:55:31.525 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:55:31.525 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:56:01.528 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:56:01.531 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:56:01.533 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:56:01.534 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:56:01.535 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:56:01.538 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:56:01.580 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
11-15 15:56:01.580 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying disconnected; id = null\
//No set suspended yet\
11-15 15:56:31.583 26963 27062 V io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:56:31.586 26963 27062 D io.ably.lib.transport.ConnectionManager: requestState(): requesting connecting; id = null\
11-15 15:56:31.588 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:56:31.589 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState(): notifying connecting; id = null\
11-15 15:56:31.591 26963 27062 V io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\
11-15 15:56:31.592 26963 27062 D io.ably.lib.transport.ConnectionManager: notifyState: wrong transport\

┆Issue is synchronized with this Jira Task by Unito

mattheworiordan commented 7 years ago

What's the status on a fix and test for this?