From a32b349b044e35cd7ec8e6b9c2cd2177e7c5a8ce Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 18 Jun 2026 02:43:48 +0000 Subject: [PATCH] debug(relay): trace background sub teardown + drop unsubscribe grace to 0 Investigating why backgrounding the app on the all-follows feed leaves ~172 outbox relays connected when only inbox + DM relays (~8) should remain. The static teardown chain (lifecycle ON_STOP -> unsubscribe -> client.unsubscribe -> PoolRequests.remove -> RelayPool.updatePool disconnect) is correct, so this adds runtime tracing at the two decisive hops to find where it stalls on-device: - LifecycleAwareKeyDataSourceSubscription: log subscribe/grace-start/ unsubscribe/dispose with the assembler name (tag BgRelayTrace). - RelayPool.updatePool: log desired/inPool/toRemove/connected counts. Also drops UNSUBSCRIBE_GRACE_MILLIS 30s -> 0 as an experiment: if the grace delay() was being starved on Dispatchers.Default once backgrounded (Doze/app-standby suspends timers), unsubscribing immediately on ON_STOP both proves and fixes the leak. To be reverted to a wakelock-safe grace once confirmed. Co-Authored-By: Claude Opus 4.8 (1M context) Claude-Session: https://claude.ai/code/session_01Ukw6FJPFh3JKGXL532p3ae --- .../LifecycleAwareKeyDataSourceSubscription.kt | 17 ++++++++++++++++- .../nip01Core/relay/client/pool/RelayPool.kt | 2 ++ 2 files changed, 18 insertions(+), 1 deletion(-) diff --git a/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/relayClient/subscriptions/LifecycleAwareKeyDataSourceSubscription.kt b/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/relayClient/subscriptions/LifecycleAwareKeyDataSourceSubscription.kt index 7b8f7334ea..966fc6909c 100644 --- a/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/relayClient/subscriptions/LifecycleAwareKeyDataSourceSubscription.kt +++ b/commons/src/commonMain/kotlin/com/vitorpamplona/amethyst/commons/relayClient/subscriptions/LifecycleAwareKeyDataSourceSubscription.kt @@ -27,6 +27,7 @@ import androidx.lifecycle.compose.LocalLifecycleOwner import com.vitorpamplona.amethyst.commons.relayClient.composeSubscriptionManagers.ComposeSubscriptionManager import com.vitorpamplona.amethyst.commons.relayClient.composeSubscriptionManagers.MutableComposeSubscriptionManager import com.vitorpamplona.amethyst.commons.relayClient.composeSubscriptionManagers.MutableQueryState +import com.vitorpamplona.quartz.utils.Log import kotlinx.coroutines.CoroutineScope import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.SupervisorJob @@ -35,7 +36,13 @@ import kotlinx.coroutines.delay import kotlinx.coroutines.flow.collectLatest import kotlinx.coroutines.launch -private const val UNSUBSCRIBE_GRACE_MILLIS = 30_000L +// DIAGNOSTIC: temporarily 0 to test whether unsubscribing the moment the app +// pauses actually disconnects the feed's outbox relays in the background. If the +// 30s grace's delay() was being starved on Dispatchers.Default once backgrounded +// (Doze/app-standby suspends timers), firing immediately on ON_STOP both proves it +// and fixes the leak. Restore to 30_000L (with a wakelock-/foreground-safe timer) +// once confirmed, to keep absorbing short app switches. +private const val UNSUBSCRIBE_GRACE_MILLIS = 0L /** * A lifecycle-aware version of [KeyDataSourceSubscription] that subscribes @@ -77,6 +84,7 @@ fun LifecycleAwareKeyDataSourceSubscription( key = state, subscribe = { dataSource.subscribe(state) }, unsubscribe = { dataSource.unsubscribe(state) }, + label = dataSource::class.simpleName ?: "?", ) } @@ -89,6 +97,7 @@ fun LifecycleAwareKeyDataSourceSubscription( key = states, subscribe = { dataSource.subscribe(states) }, unsubscribe = { dataSource.unsubscribe(states) }, + label = dataSource::class.simpleName ?: "?", ) } @@ -101,6 +110,7 @@ fun LifecycleAwareKeyDataSourceSubscription( key = state, subscribe = { dataSource.subscribe(state) }, unsubscribe = { dataSource.unsubscribe(state) }, + label = dataSource::class.simpleName ?: "?", ) } @@ -109,6 +119,7 @@ private fun LifecycleAwareSubscription( key: Any?, subscribe: () -> Unit, unsubscribe: () -> Unit, + label: String, ) { val lifecycle = LocalLifecycleOwner.current.lifecycle @@ -124,13 +135,16 @@ private fun LifecycleAwareSubscription( lifecycle.currentStateFlow.collectLatest { current -> if (current.isAtLeast(Lifecycle.State.STARTED)) { if (!subscribed) { + Log.d("BgRelayTrace") { "subscribe($label) — lifecycle=$current" } subscribe() subscribed = true } } else if (subscribed) { // Stopped: keep the REQ alive for a short grace period. // collectLatest cancels this delay if we return to STARTED first. + Log.d("BgRelayTrace") { "grace-start($label) — lifecycle=$current, waiting ${UNSUBSCRIBE_GRACE_MILLIS}ms" } delay(UNSUBSCRIBE_GRACE_MILLIS) + Log.d("BgRelayTrace") { "unsubscribe($label) — grace elapsed while $current" } unsubscribe() subscribed = false } @@ -139,6 +153,7 @@ private fun LifecycleAwareSubscription( onDispose { scope.cancel() + Log.d("BgRelayTrace") { "dispose-unsubscribe($label)" } // Idempotent: removing an absent key is a cheap no-op. Guarantees the // subscription is released even if the grace timer was still pending. unsubscribe() diff --git a/quartz/src/commonMain/kotlin/com/vitorpamplona/quartz/nip01Core/relay/client/pool/RelayPool.kt b/quartz/src/commonMain/kotlin/com/vitorpamplona/quartz/nip01Core/relay/client/pool/RelayPool.kt index b60eda98a6..854e45e80d 100644 --- a/quartz/src/commonMain/kotlin/com/vitorpamplona/quartz/nip01Core/relay/client/pool/RelayPool.kt +++ b/quartz/src/commonMain/kotlin/com/vitorpamplona/quartz/nip01Core/relay/client/pool/RelayPool.kt @@ -28,6 +28,7 @@ import com.vitorpamplona.quartz.nip01Core.relay.commands.toClient.Message import com.vitorpamplona.quartz.nip01Core.relay.commands.toRelay.Command import com.vitorpamplona.quartz.nip01Core.relay.normalizer.NormalizedRelayUrl import com.vitorpamplona.quartz.nip01Core.relay.sockets.WebsocketBuilder +import com.vitorpamplona.quartz.utils.Log import com.vitorpamplona.quartz.utils.cache.LargeCache import kotlinx.coroutines.flow.MutableStateFlow import kotlinx.coroutines.flow.asStateFlow @@ -156,6 +157,7 @@ class RelayPool( */ fun updatePool(newRelays: Set) { val toRemove = relays.keys() - newRelays + Log.d("BgRelayTrace") { "updatePool — desired=${newRelays.size}, inPool=${relays.size()}, toRemove=${toRemove.size}, connected=${connectedRelaysCount()}" } var atLeastOne = false newRelays.forEach { relay ->