fix(debug): Bound the billing cache and fold pro history into diagnostics

BillingCache reads and writes are now bounded by a timeout seam: a wedged DataStore file lock made the debug-log header hang, and a silent fallback to the default snapshot would have reported "never bought" for an install whose evidence merely could not be read. Reads now fail loudly, writes fail soft. UpgradeDiagnosticsGplay absorbs the pro-state history that the recorder header used to read directly, with a separate failure boundary per source so one broken DataStore cannot suppress the other's evidence. RecorderModule's start-failure guard now covers ordinary exceptions, not just cancellation, stops the uncommitted recorder under NonCancellable and appears once instead of per resume branch.
2026-09-14 18:26:11 -04:00 · 2026-07-30 12:55:31 +02:00
parent e364a5b02c
commit 7fb1f7aabd
6 changed files with 396 additions and 239 deletions
@@ -12,24 +12,32 @@ import dagger.hilt.android.qualifiers.ApplicationContext
 import eu.darken.capod.common.datastore.basicReader
 import eu.darken.capod.common.datastore.basicWriter
 import eu.darken.capod.common.datastore.createValue
+import eu.darken.capod.common.debug.logging.Logging.Priority.WARN
+import eu.darken.capod.common.debug.logging.log
+import eu.darken.capod.common.debug.logging.logTag
 import kotlinx.coroutines.flow.first
+import kotlinx.coroutines.withTimeoutOrNull
+import java.io.IOException
 import javax.inject.Inject
 import javax.inject.Singleton

+// Retained legacy migration: installs that predate the DataStore move still carry their upgrade
+// state in the "settings_gplay" SharedPreferences file.
+private val Context.billingCacheDataStore by preferencesDataStore(
+    name = "settings_gplay",
+    produceMigrations = { ctx -> listOf(SharedPreferencesMigration(ctx, "settings_gplay")) },
+)
+
@Singleton
-class BillingCache @Inject constructor(
-    @ApplicationContext private val context: Context,
+class BillingCache internal constructor(
+    private val dataStore: DataStore<Preferences>,
 ) {

-    // Retained legacy migration: installs that predate the DataStore move still carry their upgrade
-    // state in the "settings_gplay" SharedPreferences file.
-    private val Context.dataStore by preferencesDataStore(
-        name = "settings_gplay",
-        produceMigrations = { ctx -> listOf(SharedPreferencesMigration(ctx, "settings_gplay")) },
-    )
+    @Inject constructor(@ApplicationContext context: Context) : this(context.billingCacheDataStore)

-    private val dataStore: DataStore<Preferences>
-        get() = context.dataStore
+    // Test seam: the bounded reads/writes below run on real dispatchers, so a virtual-time test
+    // cannot advance the production bound. Same pattern as UpgradeRepoGplay.launchTimeoutMs.
+    internal var cacheTimeoutMs: Long = CACHE_TIMEOUT_MS

    // Raw keys shared between the DataStoreValues and stampLastProState's transaction — one
    // source of truth for key name and encoding.
@@ -66,8 +74,15 @@ class BillingCache @Inject constructor(
        val proUnconfirmedSince: Long,
    )

+    // Bounded on purpose: a wedged DataStore file lock would otherwise hang the caller forever.
+    // A timeout must NOT fall back to the default snapshot -- that would report "never bought"
+    // for an install whose evidence merely couldn't be read, which is the exact distinction the
+    // debug-log header exists to make.
    suspend fun snapshot(): Snapshot {
-        val prefs = dataStore.data.first()
+        val prefs = withTimeoutOrNull(cacheTimeoutMs) { dataStore.data.first() } ?: run {
+            log(TAG, WARN) { "snapshot() timed out after ${cacheTimeoutMs}ms" }
+            throw IOException("BillingCache snapshot timed out after ${cacheTimeoutMs}ms")
+        }
        return Snapshot(
            lastProStateAt = prefs[lastProStateAtKey] ?: 0L,
            lastProStateSku = prefs[lastProStateSkuKey] ?: "",
@@ -83,11 +98,19 @@ class BillingCache @Inject constructor(
    // entitlement layer out of order) opened a still-valid episode that this older confirmation must
    // not erase.
    suspend fun stampLastProState(skuId: String, at: Long) {
-        dataStore.edit { prefs ->
-            prefs[lastProStateSkuKey] = skuId
-            prefs[lastProStateAtKey] = at
-            val episodeStart = prefs[proUnconfirmedSinceKey] ?: 0L
-            if (episodeStart in 1..at) prefs[proUnconfirmedSinceKey] = 0L
-        }
+        // Fail-soft: this decorates the entitlement path, it must never be the thing that blocks it.
+        withTimeoutOrNull(cacheTimeoutMs) {
+            dataStore.edit { prefs ->
+                prefs[lastProStateSkuKey] = skuId
+                prefs[lastProStateAtKey] = at
+                val episodeStart = prefs[proUnconfirmedSinceKey] ?: 0L
+                if (episodeStart in 1..at) prefs[proUnconfirmedSinceKey] = 0L
+            }
+        } ?: log(TAG, WARN) { "stampLastProState($skuId, $at) timed out after ${cacheTimeoutMs}ms, write skipped" }
+    }
+
+    companion object {
+        private const val CACHE_TIMEOUT_MS = 2_000L
+        private val TAG = logTag("Upgrade", "Gplay", "BillingCache")
    }
 }
@@ -1,31 +1,63 @@
 package eu.darken.capod.common.upgrade.core

+import eu.darken.capod.common.debug.logging.Logging.Priority.WARN
+import eu.darken.capod.common.debug.logging.asLog
+import eu.darken.capod.common.debug.logging.log
+import eu.darken.capod.common.debug.logging.logTag
 import eu.darken.capod.common.upgrade.UpgradeDiagnostics
+import eu.darken.capod.main.core.CurriculumVitae
+import kotlinx.coroutines.CancellationException
 import java.time.Instant
 import javax.inject.Inject
 import javax.inject.Singleton

 /**
- * Reports the local billing cache into the debug log header.
+ * Reports the local billing cache and the lifetime Pro-state history into the debug log header.
 *
 * `lastProStateAt > 0` is the "this install once confirmed a real Pro purchase" bit. It predates
 * the CurriculumVitae pro-state counters by years and lives in a DataStore that was never migrated
 * or renamed, so it survives update chains that the newer counters can't speak to. Without it in
 * the header, a purchase complaint can't be told apart from a never-bought install.
 *
- * Depends on [BillingCache] alone -- see [UpgradeDiagnostics] for why this must not pull in
- * UpgradeRepoGplay.
+ * Depends on [BillingCache] and [CurriculumVitae] alone -- see [UpgradeDiagnostics] for why this
+ * must not pull in UpgradeRepoGplay.
 */
@Singleton
 class UpgradeDiagnosticsGplay @Inject constructor(
    private val billingCache: BillingCache,
+    private val curriculumVitae: CurriculumVitae,
 ) : UpgradeDiagnostics {

    override suspend fun debugInfo(): String {
-        val snapshot = billingCache.snapshot()
-        val lastProAt = snapshot.lastProStateAt.takeIf { it > 0 }?.let { Instant.ofEpochMilli(it) } ?: "never"
-        val lastProSku = snapshot.lastProStateSku.takeIf { it.isNotEmpty() } ?: "unknown/legacy"
-        val unconfirmedSince = snapshot.proUnconfirmedSince.takeIf { it > 0 }?.let { Instant.ofEpochMilli(it) } ?: "none"
-        return "BillingCache(lastProStateAt=$lastProAt, lastProStateSku=$lastProSku, proUnconfirmedSince=$unconfirmedSince)"
+        val cache = try {
+            val snapshot = billingCache.snapshot()
+            val lastProAt = snapshot.lastProStateAt.takeIf { it > 0 }?.let { Instant.ofEpochMilli(it) } ?: "never"
+            val lastProSku = snapshot.lastProStateSku.takeIf { it.isNotEmpty() } ?: "unknown/legacy"
+            val unconfirmedSince =
+                snapshot.proUnconfirmedSince.takeIf { it > 0 }?.let { Instant.ofEpochMilli(it) } ?: "none"
+            "BillingCache(lastProStateAt=$lastProAt, lastProStateSku=$lastProSku, " +
+                "proUnconfirmedSince=$unconfirmedSince)"
+        } catch (e: CancellationException) {
+            throw e
+        } catch (e: Exception) {
+            log(TAG, WARN) { "Billing cache unavailable: ${e.asLog()}" }
+            "BillingCache=unavailable"
+        }
+        // Separate boundary from the cache read above on purpose: these are different DataStores,
+        // and the counters only cover installs new enough to have them. A failure to read one must
+        // not suppress the other's independent evidence.
+        val history = try {
+            curriculumVitae.proHistory().toString()
+        } catch (e: CancellationException) {
+            throw e
+        } catch (e: Exception) {
+            log(TAG, WARN) { "Pro history unavailable: ${e.asLog()}" }
+            "unavailable"
+        }
+        return "$cache, ProHistory=$history"
+    }
+
+    companion object {
+        private val TAG = logTag("Upgrade", "Gplay", "Diagnostics")
    }
 }
@@ -20,15 +20,16 @@ import eu.darken.capod.common.debug.logging.logTag
 import eu.darken.capod.common.debug.logging.asLog
 import eu.darken.capod.common.flow.DynamicStateFlow
 import eu.darken.capod.common.upgrade.UpgradeDiagnostics
-import eu.darken.capod.main.core.CurriculumVitae
 import kotlinx.coroutines.CancellationException
 import kotlinx.coroutines.CoroutineScope
+import kotlinx.coroutines.NonCancellable
 import kotlinx.coroutines.flow.Flow
 import kotlinx.coroutines.flow.filter
 import kotlinx.coroutines.flow.first
 import kotlinx.coroutines.flow.launchIn
 import kotlinx.coroutines.flow.onEach
 import kotlinx.coroutines.plus
+import kotlinx.coroutines.withContext
 import java.io.File
 import javax.inject.Inject
 import javax.inject.Singleton
@@ -40,7 +41,6 @@ class RecorderModule @Inject constructor(
    private val dispatcherProvider: DispatcherProvider,
    private val installId: InstallId,
    private val timeSource: TimeSource,
-    private val curriculumVitae: CurriculumVitae,
    private val upgradeDiagnostics: UpgradeDiagnostics,
 ) {

@@ -86,46 +86,38 @@ class RecorderModule @Inject constructor(
                        val newRecorder = Recorder(timeSource)
                        newRecorder.start(logFile)

-                        if (!isResume) {
-                            val startTime = timeSource.currentTimeMillis()
-                            writeTriggerFile(sessionDir, startTime)
-                            // The recorder is already live but not yet committed to the state: a
-                            // cancellation escaping the header would abandon it where stopRecorder()
-                            // can't reach it.
-                            try {
-                                logRecordingHeader()
-                            } catch (e: CancellationException) {
-                                newRecorder.stop()
-                                this@RecorderModule.currentLogDir = null
-                                throw e
-                            }
-
-                            this@RecorderModule.currentLogDir = sessionDir
-
-                            copy(
-                                recorder = newRecorder,
-                                currentLogDir = sessionDir,
-                                recordingStartedAt = startTime,
-                                persistedLogDir = null,
-                            )
-                        } else {
-                            try {
-                                logRecordingHeader()
-                            } catch (e: CancellationException) {
-                                newRecorder.stop()
-                                this@RecorderModule.currentLogDir = null
-                                throw e
-                            }
-
-                            this@RecorderModule.currentLogDir = sessionDir
-
-                            copy(
-                                recorder = newRecorder,
-                                currentLogDir = sessionDir,
-                                recordingStartedAt = if (recordingStartedAt > 0L) recordingStartedAt else timeSource.currentTimeMillis(),
-                                persistedLogDir = null,
-                            )
+                        val startTime = when {
+                            !isResume -> timeSource.currentTimeMillis()
+                            recordingStartedAt > 0L -> recordingStartedAt
+                            else -> timeSource.currentTimeMillis()
                        }
+
+                        try {
+                            if (!isResume) writeTriggerFile(sessionDir, startTime)
+
+                            logRecordingHeader()
+                        } catch (e: Exception) {
+                            // The recorder is already live but not yet committed to the state: an exception
+                            // escaping the header would abandon it where stopRecorder() can't reach it.
+                            withContext(NonCancellable) {
+                                try {
+                                    newRecorder.stop()
+                                } catch (stopError: Exception) {
+                                    e.addSuppressed(stopError)
+                                }
+                                this@RecorderModule.currentLogDir = null
+                            }
+                            throw e
+                        }
+
+                        this@RecorderModule.currentLogDir = sessionDir
+
+                        copy(
+                            recorder = newRecorder,
+                            currentLogDir = sessionDir,
+                            recordingStartedAt = startTime,
+                            persistedLogDir = null,
+                        )
                    } else if (!shouldRecord && isRecording) {
                        requireNotNull(recorder) { "Recorder is null despite isRecording" }.stop()

@@ -160,20 +152,7 @@ class RecorderModule @Inject constructor(
        log(TAG, INFO) { "BuildConfig.Versions: ${BuildConfigWrap.VERSION_DESCRIPTION}" }

        try {
-            // Billing complaints usually arrive as debug logs: having the lifetime grace/Pro-loss
-            // history in the header saves a support round-trip.
-            log(TAG, INFO) { "Pro history: ${curriculumVitae.proHistory()}" }
-        } catch (e: CancellationException) {
-            throw e
-        } catch (e: Exception) {
-            // Diagnostics only — a broken history read must not stop the recorder from starting.
-            log(TAG, WARN) { "Pro history unavailable: ${e.asLog()}" }
-        }
-
-        // Separate boundary from the block above on purpose: these read different DataStores, and
-        // the counters above only cover installs new enough to have them. A failure to read one
-        // must not suppress the other's independent evidence.
-        try {
+            // Diagnostics only — a broken read must not stop the recorder from starting.
            upgradeDiagnostics.debugInfo()?.let { log(TAG, INFO) { "Upgrade diagnostics: $it" } }
        } catch (e: CancellationException) {
            throw e
@@ -1,19 +1,26 @@
 package eu.darken.capod.common.debug.recording.core

 import androidx.test.core.app.ApplicationProvider
+import eu.darken.capod.common.BuildConfigWrap
 import eu.darken.capod.common.InstallId
 import eu.darken.capod.common.SystemTimeSource
 import eu.darken.capod.common.debug.logging.FileLogger
 import eu.darken.capod.common.debug.logging.Logging
 import eu.darken.capod.common.upgrade.UpgradeDiagnostics
-import eu.darken.capod.main.core.CurriculumVitae
 import io.kotest.matchers.nulls.shouldBeNull
 import io.kotest.matchers.nulls.shouldNotBeNull
 import io.kotest.matchers.shouldBe
 import io.mockk.coEvery
 import io.mockk.coVerify
+import io.mockk.every
 import io.mockk.mockk
+import io.mockk.mockkObject
+import io.mockk.unmockkObject
 import kotlinx.coroutines.CancellationException
+import kotlinx.coroutines.CoroutineExceptionHandler
+import kotlinx.coroutines.CoroutineScope
+import kotlinx.coroutines.SupervisorJob
+import kotlinx.coroutines.cancel
 import kotlinx.coroutines.delay
 import kotlinx.coroutines.flow.first
 import kotlinx.coroutines.launch
@@ -27,18 +34,18 @@ import testhelpers.TestApplication
 import testhelpers.coroutine.TestDispatcherProvider

 /**
- * The recording header reads two independent diagnostics sources. Both reads happen AFTER the
- * recorder is already writing, so a failure in either must never abort the state update — that
+ * The recording header reads diagnostics that live outside the recorder. Those reads happen AFTER
+ * the recorder is already writing, so a guarded failure must never abort the state update — that
 * would leave a running recorder the module no longer knows about, i.e. a debug recording that
- * can't be stopped or collected.
+ * can't be stopped or collected. Failures that DO escape the header have to take the uncommitted
+ * recorder down with them.
 */
@RunWith(RobolectricTestRunner::class)
@Config(sdk = [33], application = TestApplication::class)
 class RecorderModuleDiagnosticsTest : BaseTest() {

    private fun buildModule(
-        scope: kotlinx.coroutines.CoroutineScope,
-        curriculumVitae: CurriculumVitae,
+        scope: CoroutineScope,
        upgradeDiagnostics: UpgradeDiagnostics,
    ) = RecorderModule(
        context = ApplicationProvider.getApplicationContext(),
@@ -46,111 +53,15 @@ class RecorderModuleDiagnosticsTest : BaseTest() {
        dispatcherProvider = TestDispatcherProvider(),
        installId = mockk<InstallId>(relaxed = true),
        timeSource = SystemTimeSource,
-        curriculumVitae = curriculumVitae,
        upgradeDiagnostics = upgradeDiagnostics,
    )

-    @Test
-    fun `a failing pro-history read still leaves a tracked recording`() = runTest {
-        val cv = mockk<CurriculumVitae>()
-        coEvery { cv.proHistory() } throws IllegalStateException("history unreadable")
-        val diagnostics = mockk<UpgradeDiagnostics>()
-        coEvery { diagnostics.debugInfo() } returns "BillingCache(...)"
-
-        val module = buildModule(backgroundScope, cv, diagnostics)
-
-        module.startRecorder().shouldNotBeNull()
-        module.state.first { it.isRecording }.currentLogDir.shouldNotBeNull()
-        // The other source is independent: its evidence must still be collected.
-        coVerify { diagnostics.debugInfo() }
-
-        module.stopRecorder().shouldNotBeNull()
-    }
-
    @Test
    fun `a failing upgrade-diagnostics read still leaves a tracked recording`() = runTest {
-        val cv = mockk<CurriculumVitae>()
-        coEvery { cv.proHistory() } returns CurriculumVitae.ProHistory(
-            lastState = null,
-            graceEngagedCount = 0,
-            graceEngagedLast = null,
-            proLostCount = 0,
-            proLostLast = null,
-        )
        val diagnostics = mockk<UpgradeDiagnostics>()
        coEvery { diagnostics.debugInfo() } throws IllegalStateException("cache unreadable")

-        val module = buildModule(backgroundScope, cv, diagnostics)
-
-        module.startRecorder().shouldNotBeNull()
-        module.state.first { it.isRecording }.currentLogDir.shouldNotBeNull()
-        coVerify { cv.proHistory() }
-
-        module.stopRecorder().shouldNotBeNull()
-    }
-
-    /**
-     * Cancellation is the one thing the header reads deliberately rethrow, so it is the one failure
-     * that can abort the state update. The recorder is already live at that point: it has to be
-     * stopped on the way out, or it keeps writing into a session the module no longer tracks.
-     *
-     * The start is launched, not awaited: an aborted update never flips isRecording, so
-     * startRecorder() stays suspended. The virtual-time delay is what lets the module's own
-     * background collectors run to completion.
-     */
-    @Test
-    fun `a cancelled pro-history read stops the recorder instead of leaking it`() = runTest {
-        val fileLoggersBefore = Logging.loggers.filterIsInstance<FileLogger>()
-        val cv = mockk<CurriculumVitae>()
-        coEvery { cv.proHistory() } throws CancellationException("scope died mid-read")
-        val diagnostics = mockk<UpgradeDiagnostics>()
-        coEvery { diagnostics.debugInfo() } returns "BillingCache(...)"
-
-        val module = buildModule(backgroundScope, cv, diagnostics)
-
-        backgroundScope.launch { module.startRecorder() }
-        delay(1_000)
-
-        coVerify { cv.proHistory() }
-        module.state.first().isRecording shouldBe false
-        module.currentLogDir.shouldBeNull()
-        // The recorder that was already writing when the header aborted got stopped.
-        Logging.loggers.filterIsInstance<FileLogger>() shouldBe fileLoggersBefore
-    }
-
-    @Test
-    fun `a cancelled upgrade-diagnostics read stops the recorder instead of leaking it`() = runTest {
-        val fileLoggersBefore = Logging.loggers.filterIsInstance<FileLogger>()
-        val cv = mockk<CurriculumVitae>()
-        coEvery { cv.proHistory() } returns CurriculumVitae.ProHistory(
-            lastState = null,
-            graceEngagedCount = 0,
-            graceEngagedLast = null,
-            proLostCount = 0,
-            proLostLast = null,
-        )
-        val diagnostics = mockk<UpgradeDiagnostics>()
-        coEvery { diagnostics.debugInfo() } throws CancellationException("scope died mid-read")
-
-        val module = buildModule(backgroundScope, cv, diagnostics)
-
-        backgroundScope.launch { module.startRecorder() }
-        delay(1_000)
-
-        coVerify { diagnostics.debugInfo() }
-        module.state.first().isRecording shouldBe false
-        module.currentLogDir.shouldBeNull()
-        Logging.loggers.filterIsInstance<FileLogger>() shouldBe fileLoggersBefore
-    }
-
-    @Test
-    fun `both reads failing still leaves a tracked recording`() = runTest {
-        val cv = mockk<CurriculumVitae>()
-        coEvery { cv.proHistory() } throws IllegalStateException("history unreadable")
-        val diagnostics = mockk<UpgradeDiagnostics>()
-        coEvery { diagnostics.debugInfo() } throws IllegalStateException("cache unreadable")
-
-        val module = buildModule(backgroundScope, cv, diagnostics)
+        val module = buildModule(backgroundScope, diagnostics)

        val logDir = module.startRecorder()
        logDir.exists() shouldBe true
@@ -158,4 +69,67 @@ class RecorderModuleDiagnosticsTest : BaseTest() {

        module.stopRecorder().shouldNotBeNull()
    }
+
+    /**
+     * Cancellation is the one thing the guarded header read deliberately rethrows, so it is one of
+     * the failures that can abort the state update. The recorder is already live at that point: it
+     * has to be stopped on the way out, or it keeps writing into a session the module no longer
+     * tracks.
+     *
+     * The start is launched, not awaited: an aborted update never flips isRecording, so
+     * startRecorder() stays suspended. The virtual-time delay is what lets the module's own
+     * background collectors run to completion.
+     */
+    @Test
+    fun `a cancelled upgrade-diagnostics read stops the recorder instead of leaking it`() = runTest {
+        val fileLoggersBefore = Logging.loggers.filterIsInstance<FileLogger>()
+        val diagnostics = mockk<UpgradeDiagnostics>()
+        coEvery { diagnostics.debugInfo() } throws CancellationException("scope died mid-read")
+
+        val module = buildModule(backgroundScope, diagnostics)
+
+        backgroundScope.launch { module.startRecorder() }
+        delay(1_000)
+
+        coVerify { diagnostics.debugInfo() }
+        module.state.first().isRecording shouldBe false
+        module.currentLogDir.shouldBeNull()
+        // The recorder that was already writing when the header aborted got stopped: its file
+        // logger is no longer installed.
+        Logging.loggers.filterIsInstance<FileLogger>() shouldBe fileLoggersBefore
+    }
+
+    /**
+     * Same window as above, but for an ordinary failure instead of a cancellation. The header's
+     * injected sources are individually guarded, so the escape path is one of the unguarded first
+     * log lines — here the build description read.
+     */
+    @Test
+    fun `a failing header read stops the uncommitted recorder`() = runTest {
+        val fileLoggersBefore = Logging.loggers.filterIsInstance<FileLogger>()
+        val diagnostics = mockk<UpgradeDiagnostics>()
+        coEvery { diagnostics.debugInfo() } returns "BillingCache(...)"
+
+        mockkObject(BuildConfigWrap)
+        every { BuildConfigWrap.VERSION_DESCRIPTION } throws IllegalStateException("build info unreadable")
+
+        // Own scope: the escaping exception fails the collector, which must not fail the test's own
+        // scope. SupervisorJob keeps the module's state flow alive so it can be inspected after.
+        val moduleScope = CoroutineScope(coroutineContext + SupervisorJob() + CoroutineExceptionHandler { _, _ -> })
+        try {
+            val module = buildModule(moduleScope, diagnostics)
+
+            moduleScope.launch { module.startRecorder() }
+            delay(1_000)
+
+            module.state.first().isRecording shouldBe false
+            module.currentLogDir.shouldBeNull()
+            // Non-vacuity: without the guard's cleanup the started recorder's file logger would
+            // still be installed here.
+            Logging.loggers.filterIsInstance<FileLogger>() shouldBe fileLoggersBefore
+        } finally {
+            moduleScope.cancel()
+            unmockkObject(BuildConfigWrap)
+        }
+    }
 }
@@ -1,15 +1,25 @@
 package eu.darken.capod.common.upgrade.core

+import android.content.Context
+import androidx.datastore.core.DataStore
+import androidx.datastore.preferences.core.Preferences
 import androidx.test.core.app.ApplicationProvider
 import eu.darken.capod.common.datastore.value
+import io.kotest.assertions.throwables.shouldThrow
 import io.kotest.matchers.shouldBe
+import kotlinx.coroutines.Dispatchers
+import kotlinx.coroutines.awaitCancellation
+import kotlinx.coroutines.flow.Flow
+import kotlinx.coroutines.flow.flow
 import kotlinx.coroutines.test.runTest
+import kotlinx.coroutines.withContext
 import org.junit.Test
 import org.junit.runner.RunWith
 import org.robolectric.RobolectricTestRunner
 import org.robolectric.annotation.Config
 import testhelpers.BaseTest
 import testhelpers.TestApplication
+import java.io.IOException

@RunWith(RobolectricTestRunner::class)
@Config(sdk = [33], application = TestApplication::class)
@@ -17,53 +27,90 @@ class BillingCacheTest : BaseTest() {

    // One test method on purpose: BillingCache is a @Singleton in production, and DataStore
    // forbids two active instances on the same file — a second BillingCache in this process
-    // would crash, not exercise anything real.
+    // would crash, not exercise anything real. That includes the legacy-migration check below.
    @Test
    fun `stampLastProState round-trips through the DataStoreValues`() = runTest {
-        // Real DataStore, no mocks: this catches an encoding mismatch between the raw keys the
-        // atomic stamp transaction writes and the keys/types the DataStoreValues read.
-        val cache = BillingCache(ApplicationProvider.getApplicationContext())
+        // Real time on purpose: the reads/writes below are bounded by cacheTimeoutMs, and the real
+        // DataStore does its I/O off the test scheduler -- under virtual time the bound would fire
+        // instantly while nothing else is scheduled.
+        withContext(Dispatchers.IO) {
+            val context = ApplicationProvider.getApplicationContext<Context>()

-        cache.lastProStateAt.value() shouldBe 0L
-        cache.lastProStateSku.value() shouldBe ""
+            // Installs that predate the DataStore move keep their upgrade state in the legacy
+            // "settings_gplay" SharedPreferences file. Seeded BEFORE the first DataStore access:
+            // dropping the migration would silently downgrade such an install to "never bought".
+            context.getSharedPreferences("settings_gplay", Context.MODE_PRIVATE).edit()
+                .putLong("gplay.cache.lastProAt", 1_000L)
+                .putString("gplay.cache.lastProSku", "legacy.sku")
+                .putLong("gplay.cache.proUnconfirmedAt", 2_000L)
+                .commit()

-        // Defaults on a never-Pro install: this exact triple is what the debug-log header reports
-        // as "never / unknown-legacy / none", and it's the signal that separates a never-bought
-        // install from one whose entitlement went missing.
-        cache.snapshot() shouldBe BillingCache.Snapshot(
-            lastProStateAt = 0L,
-            lastProStateSku = "",
-            proUnconfirmedSince = 0L,
-        )
+            // Real DataStore, no mocks: this catches an encoding mismatch between the raw keys the
+            // atomic stamp transaction writes and the keys/types the DataStoreValues read.
+            val cache = BillingCache(context)

+            cache.lastProStateAt.value() shouldBe 1_000L
+            cache.lastProStateSku.value() shouldBe "legacy.sku"
+
+            // The migrated triple has to surface through snapshot() too -- that is what the
+            // debug-log header reads, and it is the signal that separates a never-bought install
+            // from one whose entitlement went missing.
+            cache.snapshot() shouldBe BillingCache.Snapshot(
+                lastProStateAt = 1_000L,
+                lastProStateSku = "legacy.sku",
+                proUnconfirmedSince = 2_000L,
+            )
+
+            cache.stampLastProState(OurSku.Iap.PRO_UPGRADE.id, 1234L)
+
+            cache.lastProStateAt.value() shouldBe 1234L
+            cache.lastProStateSku.value() shouldBe OurSku.Iap.PRO_UPGRADE.id
+
+            cache.stampLastProState(OurSku.Sub.PRO_UPGRADE.id, 5678L)
+
+            cache.lastProStateAt.value() shouldBe 5678L
+            cache.lastProStateSku.value() shouldBe OurSku.Sub.PRO_UPGRADE.id
+
+            // Occurrence-aware episode clear: a confirmation closes an episode that began at or before
+            // it, but must leave a NEWER episode intact — a connection failure that occurred after this
+            // confirmation but was processed out of order opened a still-valid episode.
+            cache.proUnconfirmedSince.value(4_000L)
+            cache.stampLastProState(OurSku.Iap.PRO_UPGRADE.id, 5_000L) // confirmation newer than episode
+            cache.proUnconfirmedSince.value() shouldBe 0L
+
+            cache.proUnconfirmedSince.value(9_000L)
+            cache.stampLastProState(OurSku.Iap.PRO_UPGRADE.id, 8_000L) // confirmation older than episode
+            cache.proUnconfirmedSince.value() shouldBe 9_000L
+
+            // snapshot() must agree with the individual reads. It exists so the debug-log header reads
+            // all three in ONE DataStore emission: three separate reads can straddle a concurrent
+            // stampLastProState and report a combination that never existed.
+            cache.snapshot() shouldBe BillingCache.Snapshot(
+                lastProStateAt = 8_000L,
+                lastProStateSku = OurSku.Iap.PRO_UPGRADE.id,
+                proUnconfirmedSince = 9_000L,
+            )
+        }
+    }
+
+    @Test
+    fun `a wedged datastore is bounded, reads fail loudly and writes fail soft`() = runTest {
+        // Fake store, no file: a second real DataStore on the same file would crash this process.
+        val cache = BillingCache(HangingPreferencesDataStore()).apply { cacheTimeoutMs = 50L }
+
+        // A timeout must not masquerade as a default snapshot -- "never bought" and "couldn't read
+        // the evidence" are the two things the debug-log header exists to tell apart.
+        shouldThrow<IOException> { cache.snapshot() }
+
+        // The write only decorates the entitlement path, it must never block it.
        cache.stampLastProState(OurSku.Iap.PRO_UPGRADE.id, 1234L)
-
-        cache.lastProStateAt.value() shouldBe 1234L
-        cache.lastProStateSku.value() shouldBe OurSku.Iap.PRO_UPGRADE.id
-
-        cache.stampLastProState(OurSku.Sub.PRO_UPGRADE.id, 5678L)
-
-        cache.lastProStateAt.value() shouldBe 5678L
-        cache.lastProStateSku.value() shouldBe OurSku.Sub.PRO_UPGRADE.id
-
-        // Occurrence-aware episode clear: a confirmation closes an episode that began at or before
-        // it, but must leave a NEWER episode intact — a connection failure that occurred after this
-        // confirmation but was processed out of order opened a still-valid episode.
-        cache.proUnconfirmedSince.value(4_000L)
-        cache.stampLastProState(OurSku.Iap.PRO_UPGRADE.id, 5_000L) // confirmation newer than episode
-        cache.proUnconfirmedSince.value() shouldBe 0L
-
-        cache.proUnconfirmedSince.value(9_000L)
-        cache.stampLastProState(OurSku.Iap.PRO_UPGRADE.id, 8_000L) // confirmation older than episode
-        cache.proUnconfirmedSince.value() shouldBe 9_000L
-
-        // snapshot() must agree with the individual reads. It exists so the debug-log header reads
-        // all three in ONE DataStore emission: three separate reads can straddle a concurrent
-        // stampLastProState and report a combination that never existed.
-        cache.snapshot() shouldBe BillingCache.Snapshot(
-            lastProStateAt = 8_000L,
-            lastProStateSku = OurSku.Iap.PRO_UPGRADE.id,
-            proUnconfirmedSince = 9_000L,
-        )
    }
 }
+
+/** DataStore that never answers -- stands in for a wedged file lock. */
+internal class HangingPreferencesDataStore : DataStore<Preferences> {
+    override val data: Flow<Preferences> = flow { awaitCancellation() }
+
+    override suspend fun updateData(transform: suspend (Preferences) -> Preferences): Preferences =
+        awaitCancellation()
+}
@@ -1,17 +1,33 @@
 package eu.darken.capod.common.upgrade.core

+import eu.darken.capod.main.core.CurriculumVitae
+import io.kotest.assertions.throwables.shouldThrow
 import io.kotest.matchers.shouldBe
 import io.kotest.matchers.string.shouldContain
+import io.kotest.matchers.string.shouldNotContain
 import io.mockk.coEvery
 import io.mockk.mockk
+import kotlinx.coroutines.CancellationException
 import kotlinx.coroutines.test.runTest
 import org.junit.jupiter.api.Test
 import testhelpers.BaseTest

 class UpgradeDiagnosticsGplayTest : BaseTest() {

-    private fun create(snapshot: BillingCache.Snapshot) = UpgradeDiagnosticsGplay(
-        billingCache = mockk<BillingCache>().apply { coEvery { this@apply.snapshot() } returns snapshot },
+    private val proHistory = CurriculumVitae.ProHistory(
+        lastState = CurriculumVitae.ProState.PURCHASED,
+        graceEngagedCount = 2,
+        graceEngagedLast = null,
+        proLostCount = 0,
+        proLostLast = null,
+    )
+
+    private fun create(
+        snapshot: () -> BillingCache.Snapshot,
+        history: () -> CurriculumVitae.ProHistory = { proHistory },
+    ) = UpgradeDiagnosticsGplay(
+        billingCache = mockk<BillingCache>().apply { coEvery { this@apply.snapshot() } answers { snapshot() } },
+        curriculumVitae = mockk<CurriculumVitae>().apply { coEvery { proHistory() } answers { history() } },
    )

    @Test
@@ -19,20 +35,104 @@ class UpgradeDiagnosticsGplayTest : BaseTest() {
        // The whole point of this line in the log header is telling "never bought" apart from
        // "bought once, entitlement now missing". A raw 0 reads as a 1970 timestamp.
        val info = create(
-            BillingCache.Snapshot(lastProStateAt = 0L, lastProStateSku = "", proUnconfirmedSince = 0L)
+            { BillingCache.Snapshot(lastProStateAt = 0L, lastProStateSku = "", proUnconfirmedSince = 0L) }
        ).debugInfo()

-        info shouldBe "BillingCache(lastProStateAt=never, lastProStateSku=unknown/legacy, proUnconfirmedSince=none)"
+        info shouldContain
+            "BillingCache(lastProStateAt=never, lastProStateSku=unknown/legacy, proUnconfirmedSince=none)"
+    }
+
+    @Test
+    fun `the pro history rides along so a complaint arrives with both records`() = runTest {
+        val info = create(
+            { BillingCache.Snapshot(lastProStateAt = 0L, lastProStateSku = "", proUnconfirmedSince = 0L) }
+        ).debugInfo()
+
+        info shouldContain "ProHistory=$proHistory"
+    }
+
+    @Test
+    fun `a broken history read still reports the billing cache`() = runTest {
+        // Different DataStores: one failing must not suppress the other's independent evidence.
+        val info = create(
+            snapshot = {
+                BillingCache.Snapshot(
+                    lastProStateAt = 1_700_000_000_000L,
+                    lastProStateSku = OurSku.Iap.PRO_UPGRADE.id,
+                    proUnconfirmedSince = 0L,
+                )
+            },
+            history = { throw IllegalStateException("storage is full") },
+        ).debugInfo()
+
+        info shouldContain "lastProStateSku=${OurSku.Iap.PRO_UPGRADE.id}"
+        info shouldContain "ProHistory=unavailable"
+    }
+
+    @Test
+    fun `a broken billing cache read still reports the pro history`() = runTest {
+        // Mirror image of the above: the billing cache DataStore failing must not suppress the
+        // lifetime pro-state counters, which live in a different store.
+        var historyReads = 0
+        val info = create(
+            snapshot = { throw IllegalStateException("datastore is corrupt") },
+            history = { historyReads++; proHistory },
+        ).debugInfo()
+
+        historyReads shouldBe 1
+        info shouldContain "BillingCache=unavailable"
+        info shouldContain "ProHistory=$proHistory"
+    }
+
+    @Test
+    fun `a cancelled billing cache read is not swallowed`() = runTest {
+        shouldThrow<CancellationException> {
+            create(
+                snapshot = { throw CancellationException("scope died") },
+            ).debugInfo()
+        }
+    }
+
+    @Test
+    fun `a cancelled history read is not swallowed`() = runTest {
+        // Symmetric to the cache read: cancellation is not a diagnostics failure, it means the
+        // caller's scope died and the header read must unwind with it.
+        shouldThrow<CancellationException> {
+            create(
+                snapshot = {
+                    BillingCache.Snapshot(lastProStateAt = 0L, lastProStateSku = "", proUnconfirmedSince = 0L)
+                },
+                history = { throw CancellationException("scope died") },
+            ).debugInfo()
+        }
+    }
+
+    @Test
+    fun `a wedged billing cache is reported as unavailable, not as a never-pro install`() = runTest {
+        // End-to-end over a real BillingCache whose store never answers: the bounded read throws,
+        // and the header must say the evidence is missing instead of claiming "never bought".
+        val diagnostics = UpgradeDiagnosticsGplay(
+            billingCache = BillingCache(HangingPreferencesDataStore()).apply { cacheTimeoutMs = 50L },
+            curriculumVitae = mockk<CurriculumVitae>().apply { coEvery { proHistory() } returns proHistory },
+        )
+
+        val info = diagnostics.debugInfo()
+
+        info shouldContain "BillingCache=unavailable"
+        info shouldNotContain "lastProStateAt=never"
+        info shouldContain "ProHistory=$proHistory"
    }

    @Test
    fun `a confirmed purchase reports an instant and the sku`() = runTest {
        val info = create(
-            BillingCache.Snapshot(
-                lastProStateAt = 1_700_000_000_000L,
-                lastProStateSku = OurSku.Iap.PRO_UPGRADE.id,
-                proUnconfirmedSince = 0L,
-            )
+            {
+                BillingCache.Snapshot(
+                    lastProStateAt = 1_700_000_000_000L,
+                    lastProStateSku = OurSku.Iap.PRO_UPGRADE.id,
+                    proUnconfirmedSince = 0L,
+                )
+            }
        ).debugInfo()

        info shouldContain "lastProStateAt=2023-11-14T22:13:20Z"
@@ -43,11 +143,13 @@ class UpgradeDiagnosticsGplayTest : BaseTest() {
    @Test
    fun `an open unconfirmed episode is reported as an instant`() = runTest {
        val info = create(
-            BillingCache.Snapshot(
-                lastProStateAt = 1_700_000_000_000L,
-                lastProStateSku = OurSku.Sub.PRO_UPGRADE.id,
-                proUnconfirmedSince = 1_700_000_500_000L,
-            )
+            {
+                BillingCache.Snapshot(
+                    lastProStateAt = 1_700_000_000_000L,
+                    lastProStateSku = OurSku.Sub.PRO_UPGRADE.id,
+                    proUnconfirmedSince = 1_700_000_500_000L,
+                )
+            }
        ).debugInfo()

        info shouldContain "proUnconfirmedSince=2023-11-14T22:21:40Z"