Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
20 changes: 18 additions & 2 deletions app/src/main/java/to/bitkit/App.kt
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ import to.bitkit.services.PubkyAuthHandlerRegistrar
import to.bitkit.utils.Crypto
import to.bitkit.utils.Logger
import to.bitkit.utils.SubscriptionClockOffsetSync
import java.util.concurrent.atomic.AtomicInteger
import javax.inject.Inject

@HiltAndroidApp
Expand Down Expand Up @@ -99,11 +100,26 @@ class CurrentActivity : ActivityLifecycleCallbacks {
var value: Activity? = null
private set

private val startedCount = AtomicInteger(0)

/**
* Whether any activity is started (visible), including one paused behind a system dialog. Use this, not
* `ProcessLifecycleOwner`, which never initializes here: the manifest removes androidx.startup's
* `InitializationProvider`.
*/
val hasStartedActivity: Boolean get() = startedCount.get() > 0

override fun onActivityCreated(activity: Activity, bundle: Bundle?) = Unit
override fun onActivityStarted(activity: Activity) = run { this.value = activity }
override fun onActivityStarted(activity: Activity) = run {
startedCount.incrementAndGet()
this.value = activity
}
override fun onActivityResumed(activity: Activity) = run { this.value = activity }
override fun onActivityPaused(activity: Activity) = clearIfCurrent(activity)
override fun onActivityStopped(activity: Activity) = clearIfCurrent(activity)
override fun onActivityStopped(activity: Activity) = run {
startedCount.updateAndGet { maxOf(0, it - 1) }
clearIfCurrent(activity)
}
override fun onActivitySaveInstanceState(activity: Activity, bundle: Bundle) = Unit
override fun onActivityDestroyed(activity: Activity) = clearIfCurrent(activity)

Expand Down
65 changes: 64 additions & 1 deletion app/src/main/java/to/bitkit/services/LightningService.kt
Original file line number Diff line number Diff line change
@@ -1,11 +1,13 @@
package to.bitkit.services

import android.os.Process
import com.synonym.bitkitcore.AddressType
import kotlinx.coroutines.CoroutineDispatcher
import kotlinx.coroutines.Job
import kotlinx.coroutines.NonCancellable
import kotlinx.coroutines.cancelAndJoin
import kotlinx.coroutines.currentCoroutineContext
import kotlinx.coroutines.delay
import kotlinx.coroutines.ensureActive
import kotlinx.coroutines.flow.MutableSharedFlow
import kotlinx.coroutines.flow.SharedFlow
Expand Down Expand Up @@ -36,6 +38,7 @@ import org.lightningdevkit.ldknode.Event
import org.lightningdevkit.ldknode.FeeRate
import org.lightningdevkit.ldknode.KeychainKind
import org.lightningdevkit.ldknode.LightningBalance
import org.lightningdevkit.ldknode.LogRecord
import org.lightningdevkit.ldknode.Node
import org.lightningdevkit.ldknode.NodeException
import org.lightningdevkit.ldknode.NodeStatus
Expand All @@ -54,6 +57,7 @@ import org.lightningdevkit.ldknode.SpendableUtxo
import org.lightningdevkit.ldknode.TransactionDetails
import org.lightningdevkit.ldknode.Txid
import org.lightningdevkit.ldknode.defaultConfig
import to.bitkit.App
import to.bitkit.async.BaseCoroutineScope
import to.bitkit.async.ServiceQueue
import to.bitkit.data.SettingsStore
Expand Down Expand Up @@ -93,6 +97,7 @@ import to.bitkit.utils.LoggerLdk
import to.bitkit.utils.ServiceError
import to.bitkit.utils.jsonLogOf
import java.io.File
import java.util.concurrent.atomic.AtomicBoolean
import javax.inject.Inject
import javax.inject.Singleton
import kotlin.coroutines.AbstractCoroutineContextElement
Expand All @@ -101,9 +106,11 @@ import kotlin.coroutines.cancellation.CancellationException
import kotlin.io.path.Path
import kotlin.time.Clock
import kotlin.time.Duration
import kotlin.time.Duration.Companion.milliseconds
import kotlin.time.Duration.Companion.seconds
import kotlin.time.Instant
import org.lightningdevkit.ldknode.AddressType as LdkAddressType
import org.lightningdevkit.ldknode.LogLevel as LdkLogLevel

typealias NodeEventHandler = suspend (Event) -> Unit

Expand Down Expand Up @@ -196,6 +203,8 @@ class LightningService internal constructor(
private val ldkQueue: CoroutineContext,
private val onchainFeeRateFactory: (ULong) -> FeeRate = { FeeRate.fromSatPerVbUnchecked(it) },
private val clock: Clock = Clock.System,
private val isAppInBackground: () -> Boolean = ::isProcessInBackground,
private val exitProcess: () -> Unit = { Process.killProcess(Process.myPid()) },
) : BaseCoroutineScope(bgDispatcher, TAG) {

companion object {
Expand Down Expand Up @@ -226,6 +235,9 @@ class LightningService internal constructor(
*/
private val NODE_RELEASE_GATE_TIMEOUT = 90.seconds

/** Time given to the async log writer to persist the exit reason before the process is killed. */
private val EXIT_LOG_FLUSH_DELAY = 500.milliseconds

private val DEFAULT_SCORING_FEE_PARAMETERS = ScoringFeeParameters(
basePenaltyMsat = 1_024uL,
basePenaltyAmountMultiplierMsat = 131_072uL,
Expand Down Expand Up @@ -281,6 +293,10 @@ class LightningService internal constructor(
@Volatile
private var releaseJob: Job? = null

// Watches the current node's ldk-node logs for tracked tasks left detached by a timed-out stop.
@Volatile
internal var runtimeMonitor = NodeRuntimeMonitor()

suspend fun setup(
walletIndex: Int,
customServerUrl: String? = null,
Expand All @@ -291,14 +307,17 @@ class LightningService internal constructor(
Logger.debug("Building node…", context = TAG)

val config = config(walletIndex)
val monitor = NodeRuntimeMonitor()
val builtNode = build(
walletIndex,
customServerUrl,
customRgsServerUrl,
config,
monitor,
channelMigration,
)
currentWalletIndex = walletIndex
runtimeMonitor = monitor
node = builtNode

Logger.info("LDK node setup", context = TAG)
Expand All @@ -320,6 +339,7 @@ class LightningService internal constructor(
customServerUrl: String?,
customRgsServerUrl: String?,
config: Config,
runtimeMonitor: NodeRuntimeMonitor,
channelMigration: ChannelDataMigration? = null,
): Node = ServiceQueue.LDK.background(ldkQueue) {
val storedSettings = settingsStore.data.first()
Expand All @@ -335,7 +355,7 @@ class LightningService internal constructor(
.map { it.toLdkAddressType() }

val builder = Builder.fromConfig(config).apply {
setCustomLogger(LdkLogWriter())
setCustomLogger(LdkLogWriter(onRecord = runtimeMonitor::onLog))
configureChainSource(customServerUrl)
configureGossipSource(customRgsServerUrl)
configureScorerSource()
Expand Down Expand Up @@ -528,6 +548,7 @@ class LightningService internal constructor(
Logger.debug("Node already stopped", context = TAG)
return@withContext
}
val monitor = runtimeMonitor

Logger.debug("Stopping node…", context = TAG)
ServiceQueue.LDK.background(ldkQueue) {
Expand All @@ -537,10 +558,26 @@ class LightningService internal constructor(
}
this@LightningService.node = null
}
// Releasing a node whose stop left tasks detached shuts down its tokio runtime under them, and the first
// one to resume (a VSS write returning, or a thaw from the freezer) aborts the app with "A Tokio 1.x
// context was found, but it is being shutdown." In the background, kill the process while the runtime
// is alive instead; a cold start restores everything. In the foreground, release as before.
if (monitor.hasDetachedWork && isAppInBackground() && exitBeforeRuntimeShutdown()) return@withContext
releaseHandle(node)
Logger.info("Node stopped", context = TAG)
}

private suspend fun exitBeforeRuntimeShutdown(): Boolean {
Logger.warn("Exiting process: node stop left ldk_node tasks detached while in background", context = TAG)
delay(EXIT_LOG_FLUSH_DELAY)
if (!isAppInBackground()) {
Logger.warn("Cancelled process exit: app returned to foreground", context = TAG)
return false
}
exitProcess()
Comment thread
jvsena42 marked this conversation as resolved.
Resolved
return true
}

/**
* Releases the rust handle instead of leaving it to the GC finalizer, keeping it off the
* single-threaded LDK queue and off the lifecycle critical path.
Expand Down Expand Up @@ -1578,3 +1615,29 @@ internal fun exactOriginalSendFee(
check(inputTotal >= outputTotal)
return inputTotal - outputTotal
}

private fun isProcessInBackground(): Boolean = App.currentActivity?.hasStartedActivity != true

/**
* Flags a node whose stop timed out and left tracked tasks detached on its tokio runtime.
*
* ldk-node reports this only through its log, as an `ERROR` from `ldk_node::runtime` starting with
* "Detaching" (background tasks, cancellable background tasks, or the event processor).
*/
internal class NodeRuntimeMonitor {
companion object {
private const val RUNTIME_MODULE = "ldk_node::runtime"
private const val DETACHING_PREFIX = "Detaching "
}

private val detached = AtomicBoolean(false)

val hasDetachedWork: Boolean get() = detached.get()

fun onLog(record: LogRecord) {
if (record.level != LdkLogLevel.ERROR) return
if (!record.modulePath.startsWith(RUNTIME_MODULE)) return
if (!record.args.startsWith(DETACHING_PREFIX)) return
detached.set(true)
}
}
2 changes: 2 additions & 0 deletions app/src/main/java/to/bitkit/utils/LoggerLdk.kt
Original file line number Diff line number Diff line change
Expand Up @@ -181,10 +181,12 @@ class LoggerLdk @Inject constructor(
class LdkLogWriter(
private val maxLogLevel: LdkLogLevel = Env.ldkLogLevel,
saver: LogSaver = AppLogger.getOrCreateSaver(),
private val onRecord: (LogRecord) -> Unit = {},
) : LogWriter {
private val delegate: LoggerImpl = LoggerImpl(LDK, saver)

override fun log(record: LogRecord) {
onRecord(record)
if (record.level < maxLogLevel) return

val msg = record.args
Expand Down
50 changes: 50 additions & 0 deletions app/src/test/java/to/bitkit/CurrentActivityTest.kt
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
package to.bitkit

import android.app.Activity
import org.junit.Test
import org.mockito.kotlin.mock
import kotlin.test.assertFalse
import kotlin.test.assertNull
import kotlin.test.assertTrue

class CurrentActivityTest {
private val sut = CurrentActivity()
private val activity = mock<Activity>()

@Test
fun `has no started activity before any start`() {
assertFalse(sut.hasStartedActivity)
}

@Test
fun `keeps a paused activity started while it stays visible`() {
sut.onActivityStarted(activity)
sut.onActivityResumed(activity)

sut.onActivityPaused(activity)

assertTrue(sut.hasStartedActivity)
assertNull(sut.value)
}

@Test
fun `has no started activity once every started activity stops`() {
val other = mock<Activity>()
sut.onActivityStarted(activity)
sut.onActivityStarted(other)

sut.onActivityStopped(activity)
assertTrue(sut.hasStartedActivity)

sut.onActivityStopped(other)
assertFalse(sut.hasStartedActivity)
}

@Test
fun `ignores a stop without a matching start`() {
sut.onActivityStopped(activity)
sut.onActivityStarted(activity)

assertTrue(sut.hasStartedActivity)
}
}
64 changes: 63 additions & 1 deletion app/src/test/java/to/bitkit/services/LightningServiceTest.kt
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@ import org.lightningdevkit.ldknode.Event
import org.lightningdevkit.ldknode.FeeRate
import org.lightningdevkit.ldknode.KeychainKind
import org.lightningdevkit.ldknode.LightningBalance
import org.lightningdevkit.ldknode.LogRecord
import org.lightningdevkit.ldknode.Network
import org.lightningdevkit.ldknode.Node
import org.lightningdevkit.ldknode.NodeException
Expand Down Expand Up @@ -101,12 +102,19 @@ import kotlin.time.Clock
import kotlin.time.Duration.Companion.milliseconds
import kotlin.time.Instant
import com.synonym.bitkitcore.AddressType as BitkitAddressType
import org.lightningdevkit.ldknode.LogLevel as LdkLogLevel
import org.lightningdevkit.ldknode.PreparedOnchainSend as NativePreparedOnchainSend

private const val VERIFY_TIMEOUT_MS = 2_000L
private const val RELEASE_GATE_PROBE_MS = 200L
private const val STOP_BOUND_MS = 5_000L
private val SHORT_GATE_TIMEOUT = 200.milliseconds
private val detachingRecord = LogRecord(
LdkLogLevel.ERROR,
"Detaching background tasks after cancellation timed out.",
"ldk_node::runtime",
362u,
)

class LightningServiceTest : BaseUnitTest() {
private val keychain = mock<Keychain>()
Expand All @@ -123,13 +131,18 @@ class LightningServiceTest : BaseUnitTest() {
val tempFolder = TemporaryFolder()

private lateinit var sut: LightningService
private var isAppInBackground = false
private var exitCount = 0

@Before
fun setUp() {
sut = createService()
}

private fun createService(ldkDispatcher: CoroutineDispatcher = testDispatcher): LightningService =
private fun createService(
ldkDispatcher: CoroutineDispatcher = testDispatcher,
isAppInBackground: () -> Boolean = { this.isAppInBackground },
): LightningService =
LightningService(
bgDispatcher = testDispatcher,
ioDispatcher = testDispatcher,
Expand All @@ -141,6 +154,8 @@ class LightningServiceTest : BaseUnitTest() {
watchOnlyAccountLifecycleCoordinator = watchOnlyAccountLifecycleCoordinator,
ldkQueue = ldkDispatcher,
onchainFeeRateFactory = { sendFeeRate },
isAppInBackground = isAppInBackground,
exitProcess = { exitCount++ },
).also { it.node = node }

@OptIn(ExperimentalCoroutinesApi::class)
Expand Down Expand Up @@ -631,6 +646,53 @@ class LightningServiceTest : BaseUnitTest() {
assertNull(sut.node)
}

// Regression #1536: releasing the node shuts down its runtime under the detached tasks, which abort the app
@Test
fun `stop exits the process instead of releasing a node with detached work in background`() = test {
isAppInBackground = true
sut.runtimeMonitor.onLog(detachingRecord)

sut.stop()

verify(node).stop()
verify(node, never()).destroy()
assertEquals(1, exitCount)
assertNull(sut.node)
}

@Test
fun `stop releases a node with detached work when the app returns before the exit`() = test {
var backgroundChecks = 0
sut = createService(isAppInBackground = { backgroundChecks++ == 0 })
sut.runtimeMonitor.onLog(detachingRecord)

sut.stop()

verify(node).destroy()
assertEquals(0, exitCount)
assertEquals(2, backgroundChecks)
}

@Test
fun `stop releases a node with detached work in foreground`() = test {
sut.runtimeMonitor.onLog(detachingRecord)

sut.stop()

verify(node).destroy()
assertEquals(0, exitCount)
}

@Test
fun `stop releases a node without detached work in background`() = test {
isAppInBackground = true

sut.stop()

verify(node).destroy()
assertEquals(0, exitCount)
}

@Test
fun `stop is a no-op when no node is set`() = test {
sut.node = null
Expand Down
Loading
Loading