-
-
Notifications
You must be signed in to change notification settings - Fork 1k
Detect silently dropped WebSocket connections and retry until subscriptions are restored #7164
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from 5 commits
3bb142c
9423e90
75c4b99
60df276
2e636e4
d60e7a5
3a4e4b3
9960362
3bb983f
28c5d56
ea186d7
08e61d0
2e979bc
53f6b47
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -57,6 +57,7 @@ import java.util.concurrent.atomic.AtomicLong | |
| import java.util.concurrent.atomic.AtomicReference | ||
| import kotlin.coroutines.cancellation.CancellationException | ||
| import kotlin.time.Duration | ||
| import kotlin.time.Duration.Companion.minutes | ||
| import kotlin.time.Duration.Companion.seconds | ||
| import kotlinx.coroutines.CompletableDeferred | ||
| import kotlinx.coroutines.CoroutineExceptionHandler | ||
|
|
@@ -99,6 +100,9 @@ import timber.log.Timber | |
|
|
||
| private val DELAY_BEFORE_RECONNECT = 10.seconds | ||
|
|
||
| /** Upper bound for the backoff between reconnection attempts while the server stays unreachable. */ | ||
| private val MAX_DELAY_BEFORE_RECONNECT = 2.minutes | ||
|
|
||
| /** | ||
| * Implementation of the [WebSocketCore] interface for managing WebSocket connections to a Home Assistant server. | ||
| * | ||
|
|
@@ -182,6 +186,9 @@ internal class WebSocketCoreImpl( | |
| @Volatile | ||
| private var pendingCloseReason: WebSocketState.Closed.Reason? = null | ||
|
|
||
| /** The running subscription restore loop, replaced on each closing so only one runs at a time. */ | ||
| private var reconnectJob: Job? = null | ||
|
|
||
| /** | ||
| * A [CompletableDeferred] that signals the establishment and authentication of a WebSocket connection. | ||
| * | ||
|
|
@@ -622,6 +629,26 @@ internal class WebSocketCoreImpl( | |
| } | ||
| } | ||
|
|
||
| override suspend fun ping(): Boolean { | ||
| // Capture the connection this ping verifies, so a connection (re)established while | ||
| // waiting for the pong is never cancelled by mistake. | ||
| val holder = connectionHolder.get() | ||
| val response = sendMessage(mapOf("type" to "ping")) | ||
| if (response is PongSocketResponse) return true | ||
|
|
||
| if (holder != null && connectionHolder.get() === holder) { | ||
| // No pong on a connection that is believed to be established means the socket is | ||
| // half-open: the server went away without the TCP connection being reset, for | ||
| // example when it restarted and its address moved. OkHttp keeps buffering writes | ||
| // into such a socket without ever failing, so no close callback would fire on its | ||
| // own. Cancelling forces onFailure, which runs handleClosingSocket and lets the | ||
| // restore loop bring the connection and its subscriptions back. | ||
| Timber.w("No pong received on the established connection, cancelling it to trigger reconnection") | ||
| holder.webSocket.cancel() | ||
| } | ||
| return false | ||
| } | ||
|
|
||
| override suspend fun <T : Any> subscribeTo( | ||
| type: String, | ||
| data: Map<String, Any?>, | ||
|
|
@@ -765,16 +792,18 @@ internal class WebSocketCoreImpl( | |
| awaitClose { | ||
| wsScope.launch { | ||
| eventSubscriptionMutex.withLock { | ||
| findSubscription(subscribeMessage) | ||
| ?.let { | ||
| val subscription = it.key | ||
| Timber.d("Unsubscribing from $subscribeMessage") | ||
| // Unsubscribe must happen before removing from activeMessages to ensure | ||
| // the server acknowledges before we stop handling events for this subscription | ||
| unsubscribeEvents(subscription) | ||
| channel.close() | ||
| activeMessages.remove(subscription) | ||
| } | ||
| // Resubscribing briefly tracks two entries for the same message, remove | ||
|
markfrancisonly marked this conversation as resolved.
Outdated
|
||
| // them all so no orphan keeps the connection alive | ||
| var subscription = findSubscription(subscribeMessage)?.key | ||
| while (subscription != null) { | ||
| Timber.d("Unsubscribing from $subscribeMessage") | ||
| // Unsubscribe must happen before removing from activeMessages to ensure | ||
| // the server acknowledges before we stop handling events for this subscription | ||
| unsubscribeEvents(subscription) | ||
| activeMessages.remove(subscription) | ||
| subscription = findSubscription(subscribeMessage)?.key | ||
| } | ||
| channel.close() | ||
| } | ||
| if (activeMessages.isEmpty()) { | ||
| Timber.i("No more subscriptions, closing connection.") | ||
|
|
@@ -1022,52 +1051,82 @@ internal class WebSocketCoreImpl( | |
| if (connectionHolder.get() == null) return | ||
|
|
||
| wsScope.launch { | ||
| val hasSubscriptions: Boolean | ||
|
|
||
| connectedMutex.withLock { | ||
|
markfrancisonly marked this conversation as resolved.
|
||
| val holder = connectionHolder.getAndSet(null) | ||
| // Another callback of the same closing already handled it | ||
| val holder = connectionHolder.getAndSet(null) ?: return@launch | ||
|
markfrancisonly marked this conversation as resolved.
|
||
| // Cancel URL observer - connect() will recreate it if needed | ||
| holder?.urlObserverJob?.cancel() | ||
| holder.urlObserverJob.cancel() | ||
|
|
||
| cleanupClosingSocket() | ||
| hasSubscriptions = activeMessages.any { it.value is ActiveMessage.Subscription } | ||
| } | ||
|
|
||
| val shouldAttemptReconnect = hasSubscriptions && wasActive | ||
|
|
||
| if (shouldAttemptReconnect && wsScope.isActive) { | ||
| // Delay before reconnect unless URL changed | ||
| if (closeReason != WebSocketState.Closed.Reason.CHANGED_URL) { | ||
| delay(DELAY_BEFORE_RECONNECT) | ||
| val hasSubscriptions = activeMessages.any { it.value is ActiveMessage.Subscription } | ||
|
|
||
| if (hasSubscriptions && wasActive && wsScope.isActive) { | ||
|
markfrancisonly marked this conversation as resolved.
Outdated
|
||
| // A new closing takes over the restore loop with a fresh snapshot, replacing | ||
| // the job under the lock so concurrent closings cannot start two loops | ||
| reconnectJob?.cancel() | ||
| reconnectJob = wsScope.launch { | ||
| // Delay before reconnect unless URL changed | ||
| if (closeReason != WebSocketState.Closed.Reason.CHANGED_URL) { | ||
| delay(DELAY_BEFORE_RECONNECT) | ||
| } | ||
| reconnectSubscriptions() | ||
| } | ||
| } | ||
| reconnectSubscriptions() | ||
| } | ||
| } | ||
| } | ||
|
|
||
| private suspend fun reconnectSubscriptions() { | ||
| if (connect()) { | ||
| Timber.d("Resubscribing to active subscriptions...") | ||
| activeMessages.filterValues { it is ActiveMessage.Subscription }.entries | ||
| .forEach { (oldId, oldActiveMessage) -> | ||
| oldActiveMessage as ActiveMessage.Subscription | ||
| activeMessages.remove(oldId) | ||
|
|
||
| val response = sendMessage( | ||
| Command.WithAnswer.Subscription( | ||
| request = oldActiveMessage.request, | ||
| eventFlow = oldActiveMessage.eventFlow, | ||
| onEvent = oldActiveMessage.onEvent, | ||
| ), | ||
| ) | ||
| if (response == null || response.success != true) { | ||
| Timber.e("Issue re-registering subscription with ${oldActiveMessage.request}") | ||
| } | ||
| var toRestore: Set<Long> = activeMessages.filterValues { it is ActiveMessage.Subscription }.keys | ||
| var retryDelay = DELAY_BEFORE_RECONNECT | ||
| while (toRestore.isNotEmpty()) { | ||
| if (connect()) { | ||
| // The server is reachable again, restart the backoff | ||
| retryDelay = DELAY_BEFORE_RECONNECT | ||
| toRestore = resubscribeActiveSubscriptions(toRestore) | ||
| if (toRestore.isEmpty()) return | ||
| Timber.w("${toRestore.size} subscriptions not restored, retrying in $retryDelay") | ||
|
markfrancisonly marked this conversation as resolved.
Outdated
|
||
| } else { | ||
| if (getConnectionState() == WebSocketState.ClosedAuth) { | ||
| Timber.e("Authentication failed, not retrying to resubscribe to active subscriptions") | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. When this happens the subscriptions stay in activeMessages but are never resubscribed. Even if auth is fixed later (a new token for instance), the next successful connection comes up with zero registrations on the server side and nothing restores them until the next socket closing. The more I look at this, the more I think the resubscription trigger belongs at the end of connect() rather than in the closing path: when a fresh connection is established and activeMessages still contains Subscription entries from a previous connection, start the restore job for them. Semantically it reads as "connect, then re-register anything left over from the previous connection". A fresh socket has no registrations by definition, so any tracked subscription at that point needs restoring. This matters especially because any sendMessage can theoretically reconnect the WebSocket (the worker's ping does this every 30s) and leave the subscriptions tracked but not subscribed. Note: it would need to launch the job (guarded by reconnectJob like today) rather than resubscribe inline: inline it would deadlock on connectedMutex and make unrelated sendMessage callers wait on the restoration. The closing-path loop would still be needed to actively retry while the server is unreachable; the connect() trigger would be the safety net for every other way a connection comes back. This is an idea to explore.
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
This makes logical sense. However, one of the reasons for putting it in the closing was to ensure a delay before retrying. Most connection failures are temporary due to a network change - immediately retrying will fail but a couple of seconds later there is a network again so it will work. The delay before attempting to setup a new connection should stay.
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I agree, I want to move only the logic of opening again the pending subscription out of this and directly in the connect path. I'm going to propose something within the PR |
||
| return | ||
| } | ||
| } else { | ||
| // TODO https://github.com/home-assistant/android/issues/5259 handle re-connection gracefully or terminates the flows | ||
| Timber.w("Unable to reconnect, cannot resubscribe to active subscriptions") | ||
| Timber.w( | ||
| "Unable to reconnect, retrying in $retryDelay to resubscribe to active subscriptions", | ||
| ) | ||
| } | ||
| delay(retryDelay) | ||
| // Back off while the server stays unreachable so a long outage is not hammered | ||
| retryDelay = (retryDelay * 2).coerceAtMost(MAX_DELAY_BEFORE_RECONNECT) | ||
| // Subscriptions closed while waiting no longer need to be restored | ||
| toRestore = toRestore.filterTo(mutableSetOf()) { activeMessages[it] is ActiveMessage.Subscription } | ||
| } | ||
| } | ||
|
|
||
| /** @return the ids of the subscriptions that could not be restored and are kept for a retry */ | ||
| private suspend fun resubscribeActiveSubscriptions(oldIds: Set<Long>): Set<Long> { | ||
| Timber.d("Resubscribing to active subscriptions...") | ||
| val failed = mutableSetOf<Long>() | ||
| oldIds.forEach { oldId -> | ||
| val oldActiveMessage = activeMessages[oldId] as? ActiveMessage.Subscription ?: return@forEach | ||
|
|
||
| val response = sendMessage( | ||
| Command.WithAnswer.Subscription( | ||
| request = oldActiveMessage.request, | ||
| eventFlow = oldActiveMessage.eventFlow, | ||
| onEvent = oldActiveMessage.onEvent, | ||
| ), | ||
| ) | ||
| if (response == null || response.success != true) { | ||
| failed += oldId | ||
| // Drop the rejected attempt, the kept original is retried instead | ||
| response?.id?.let { activeMessages.remove(it) } | ||
| Timber.e("Issue re-registering subscription with ${oldActiveMessage.request}") | ||
| } else { | ||
| activeMessages.remove(oldId) | ||
| } | ||
| } | ||
|
markfrancisonly marked this conversation as resolved.
Outdated
|
||
| return failed | ||
| } | ||
|
|
||
| private fun URL.toWebSocketURL(): String { | ||
|
|
||
Uh oh!
There was an error while loading. Please reload this page.