diff --git a/app/src/main/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModel.kt b/app/src/main/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModel.kt index f6552bf..1c975fc 100644 --- a/app/src/main/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModel.kt +++ b/app/src/main/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModel.kt @@ -3,7 +3,6 @@ package org.libremail.ui.accountsetup import android.content.ActivityNotFoundException import android.content.Intent -import android.util.Log import androidx.lifecycle.ViewModel import androidx.lifecycle.viewModelScope import dagger.hilt.android.lifecycle.HiltViewModel @@ -15,6 +14,7 @@ import kotlinx.coroutines.launch import org.libremail.auth.OutlookAuthManager import org.libremail.domain.model.Account import org.libremail.domain.repository.AccountRepository +import org.libremail.reporting.AppLog import javax.inject.Inject /** Stage of an account-setup attempt, shared by the Outlook and manual flows. */ @@ -68,12 +68,18 @@ class AccountSetupViewModel @Inject constructor( Account.outlook(oauth.email).id }.fold( onSuccess = { accountId -> + // No email: the account id embeds it (see accountLogRef) and must never be logged. + AppLog.i(TAG, "Outlook account added") _state.update { it.copy(status = SetupStatus.DONE, addedAccountId = accountId) } }, onFailure = { e -> - // Stripped from release builds by the Log.d ProGuard rule (keeps any account - // address / token detail out of shipped logs); visible in debug for diagnosis. - Log.d(TAG, "Outlook sign-in failed after redirect", e) + // AppLog.d's Logcat mirror is stripped from release builds by the -assumenosideeffects + // Log.d ProGuard rule (keeps any account address / token detail out of shipped + // logcat), but that rule only elides the `Log.d(...)` call inside AppLog.d — the + // buffer.record(...) line right after it is untouched, so this breadcrumb still + // reaches a submitted report. The throwable's message may carry the account + // email/token; AppLog's StackTraceScrubber redacts it before it is recorded. + AppLog.d(TAG, "Outlook sign-in failed after redirect", e) _state.update { it.copy(status = SetupStatus.IDLE, error = e.message ?: "Microsoft sign-in failed") } diff --git a/app/src/main/kotlin/org/libremail/ui/lock/AppLockViewModel.kt b/app/src/main/kotlin/org/libremail/ui/lock/AppLockViewModel.kt index 946f76c..58cfaa8 100644 --- a/app/src/main/kotlin/org/libremail/ui/lock/AppLockViewModel.kt +++ b/app/src/main/kotlin/org/libremail/ui/lock/AppLockViewModel.kt @@ -5,7 +5,6 @@ import android.content.Context import android.os.SystemClock import android.security.keystore.KeyPermanentlyInvalidatedException import android.security.keystore.UserNotAuthenticatedException -import android.util.Log import androidx.annotation.VisibleForTesting import androidx.lifecycle.ViewModel import androidx.lifecycle.viewModelScope @@ -32,6 +31,7 @@ import org.libremail.data.security.LockState import org.libremail.data.security.PassphraseSession import org.libremail.data.settings.SettingsRepository import org.libremail.data.sync.SyncScheduler +import org.libremail.reporting.AppLog import org.libremail.restart.ProcessRestarter import java.util.concurrent.ExecutionException import java.util.concurrent.TimeUnit @@ -149,6 +149,8 @@ class AppLockViewModel @Inject constructor( keyInvalidated = databaseKeyCipher.isInvalidated(), ) } + // LockAction is a non-PII enum, so it's safe to record verbatim as a breadcrumb. + AppLog.i(TAG, "app-lock foreground decision: $action") when (action) { LockAction.PROCEED -> _uiState.value = AppLockUiState.Unlocked @@ -191,6 +193,7 @@ class AppLockViewModel @Inject constructor( viewModelScope.launch { when (withContext(defaultDispatcher) { unlockOrArm() }) { UnlockResult.OK -> { + AppLog.i(TAG, "auth seal unlocked; cache readable") gate.onAuthenticated() publish() } @@ -198,7 +201,7 @@ class AppLockViewModel @Inject constructor( UnlockResult.UNRECOVERABLE -> { // The passphrase is permanently unrecoverable (key invalidated or deleted by a // screen-lock change). Wipe the cache safely at the next cold start and re-sync. - Log.w(TAG, "encrypted cache passphrase unrecoverable; clearing cache") + AppLog.w(TAG, "encrypted cache passphrase unrecoverable; clearing cache") clearCacheAndRestart(disableAppLock = false) } @@ -240,7 +243,7 @@ class AppLockViewModel @Inject constructor( return runCatching { databaseKeyStore.sealWithAuth() }.fold( onSuccess = { UnlockResult.OK }, onFailure = { e -> - Log.w(TAG, "arming auth seal failed", e) + AppLog.w(TAG, "arming auth seal failed", e) UnlockResult.RETRY }, ) @@ -249,17 +252,17 @@ class AppLockViewModel @Inject constructor( private suspend fun unwrapSealedPassphrase(): UnlockResult { // A sealed passphrase exists but its key is gone entirely: it can never be unwrapped. if (!databaseKeyCipher.hasKey()) { - Log.w(TAG, "auth-sealed passphrase present but key was deleted; cache unrecoverable") + AppLog.w(TAG, "auth-sealed passphrase present but key was deleted; cache unrecoverable") return UnlockResult.UNRECOVERABLE } return try { databaseKeyStore.unlockWithAuth() UnlockResult.OK } catch (e: KeyPermanentlyInvalidatedException) { - Log.w(TAG, "auth-bound key permanently invalidated", e) + AppLog.w(TAG, "auth-bound key permanently invalidated", e) UnlockResult.UNRECOVERABLE } catch (e: UserNotAuthenticatedException) { - Log.w(TAG, "auth window elapsed before unwrap; will retry", e) + AppLog.w(TAG, "auth window elapsed before unwrap; will retry", e) UnlockResult.RETRY } catch (e: CancellationException) { throw e @@ -268,12 +271,13 @@ class AppLockViewModel @Inject constructor( // process right after a successful auth. Re-lock and let the user retry rather than wiping // the cache on an ambiguous error (a genuinely lost key still surfaces as UNRECOVERABLE // via hasKey()/KeyPermanentlyInvalidatedException above). - Log.w(TAG, "unexpected failure unwrapping auth-sealed passphrase; will retry", e) + AppLog.w(TAG, "unexpected failure unwrapping auth-sealed passphrase; will retry", e) UnlockResult.RETRY } } private suspend fun clearCacheAndRestart(disableAppLock: Boolean) { + AppLog.w(TAG, "clearing encrypted cache and restarting (disableAppLock=$disableAppLock)") withContext(defaultDispatcher) { // Record the wipe intent BEFORE flipping app-lock off, so a crash between the two writes // leaves the wipe still pending (recoverable) rather than a disabled gate over a stale key. @@ -302,12 +306,12 @@ class AppLockViewModel @Inject constructor( try { operation.result.get(SYNC_ENQUEUE_TIMEOUT_SECONDS, TimeUnit.SECONDS) } catch (e: TimeoutException) { - Log.w(TAG, "re-sync enqueue not confirmed within timeout; restarting anyway", e) + AppLog.w(TAG, "re-sync enqueue not confirmed within timeout; restarting anyway", e) } catch (e: ExecutionException) { - Log.w(TAG, "re-sync enqueue failed; restarting anyway", e) + AppLog.w(TAG, "re-sync enqueue failed; restarting anyway", e) } catch (e: InterruptedException) { Thread.currentThread().interrupt() - Log.w(TAG, "interrupted awaiting re-sync enqueue; restarting anyway", e) + AppLog.w(TAG, "interrupted awaiting re-sync enqueue; restarting anyway", e) } } diff --git a/app/src/test/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModelTest.kt b/app/src/test/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModelTest.kt index 9cc131b..0033404 100644 --- a/app/src/test/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModelTest.kt +++ b/app/src/test/kotlin/org/libremail/ui/accountsetup/AccountSetupViewModelTest.kt @@ -23,18 +23,41 @@ import org.junit.Test import org.libremail.auth.OAuthResult import org.libremail.auth.OutlookAuthManager import org.libremail.domain.repository.AccountRepository +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import kotlin.test.assertEquals +import kotlin.test.assertFalse import kotlin.test.assertNotEquals import kotlin.test.assertNull import kotlin.test.assertTrue +/** + * Issue #326 migrated this ViewModel's logging to [AppLog]: a [RingLogBuffer] is installed here and + * assertions about what got logged are against [logBuffer] — including that a failed sign-in whose + * throwable carries the account email never lets that email reach the buffer (the seam's + * `StackTraceScrubber` must redact it). + */ @OptIn(ExperimentalCoroutinesApi::class) class AccountSetupViewModelTest { private val dispatcher = UnconfinedTestDispatcher() + private val logBuffer = RingLogBuffer() @Before - fun setUp() = Dispatchers.setMain(dispatcher) + fun setUp() { + Dispatchers.setMain(dispatcher) + // android.util.Log is a no-op stub that throws "not mocked" in JVM tests, and AppLog always + // forwards to it; stub every level up front, then install a real buffer so breadcrumbs can be + // asserted for real instead of via `verify { Log... }`. + mockkStatic(Log::class) + every { Log.d(any(), any()) } returns 0 + every { Log.d(any(), any(), any()) } returns 0 + every { Log.i(any(), any()) } returns 0 + every { Log.w(any(), any()) } returns 0 + every { Log.w(any(), any(), any()) } returns 0 + every { Log.e(any(), any(), any()) } returns 0 + AppLog.install(logBuffer) + } @After fun tearDown() { @@ -125,12 +148,15 @@ class AccountSetupViewModelTest { assertEquals("outlook:me@outlook.com", vm.state.value.addedAccountId) assertNull(vm.state.value.error) coVerify { accounts.addOutlookAccount("me@outlook.com", "tok", "{}") } + // Issue #326: the success breadcrumb never carries the account email. + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("Outlook account added", entry.message) + assertFalse(entry.message.contains("@")) } @Test fun `a failed token exchange returns to idle with the error surfaced`() = runTest(dispatcher) { - mockkStatic(Log::class) - every { Log.d(any(), any(), any()) } returns 0 val manager = mockk(relaxed = true) coEvery { manager.exchangeToken(any()) } throws IllegalStateException("Token exchange failed") val vm = viewModel(outlookAuthManager = manager) @@ -141,12 +167,15 @@ class AccountSetupViewModelTest { assertEquals(SetupStatus.IDLE, vm.state.value.status) assertEquals("Token exchange failed", vm.state.value.error) assertNull(vm.state.value.addedAccountId) + // Issue #326: the migrated Log.d -> AppLog.d call records a debug breadcrumb in the buffer + // (unlike raw Log.d, this survives release builds — only the Logcat mirror is stripped there). + val entry = logBuffer.snapshot().single() + assertEquals('D', entry.level) + assertTrue(entry.message.startsWith("Outlook sign-in failed after redirect"), entry.message) } @Test fun `a persistence failure after exchange returns to idle with an error`() = runTest(dispatcher) { - mockkStatic(Log::class) - every { Log.d(any(), any(), any()) } returns 0 val manager = mockk(relaxed = true) coEvery { manager.exchangeToken(any()) } returns OAuthResult(email = "me@outlook.com", accessToken = "tok", authStateJson = "{}") @@ -162,6 +191,26 @@ class AccountSetupViewModelTest { assertEquals("IMAP verification failed", vm.state.value.error) } + @Test + fun `a failure whose message carries the account email is scrubbed before it reaches the buffer`() = + runTest(dispatcher) { + // Drives a failing Outlook sign-in with a known test email embedded in the thrown + // exception's message, and asserts no buffer line contains that address: AppLog.d's + // StackTraceScrubber must redact it from the throwable's recorded stack trace text. + val knownTestEmail = "me@outlook.com" + val manager = mockk(relaxed = true) + coEvery { manager.exchangeToken(any()) } throws + IllegalStateException("Token exchange failed for $knownTestEmail") + val vm = viewModel(outlookAuthManager = manager) + + vm.onOutlookResult(mockk(relaxed = true)) + advanceUntilIdle() + + val snapshot = logBuffer.snapshot() + assertTrue(snapshot.isNotEmpty()) + snapshot.forEach { entry -> assertFalse(entry.message.contains(knownTestEmail), entry.message) } + } + @Test fun `consumeError clears a surfaced error`() { val vm = viewModel() diff --git a/app/src/test/kotlin/org/libremail/ui/lock/AppLockViewModelTest.kt b/app/src/test/kotlin/org/libremail/ui/lock/AppLockViewModelTest.kt index 36890cf..7a67c70 100644 --- a/app/src/test/kotlin/org/libremail/ui/lock/AppLockViewModelTest.kt +++ b/app/src/test/kotlin/org/libremail/ui/lock/AppLockViewModelTest.kt @@ -40,10 +40,13 @@ import org.libremail.data.security.PassphraseSession import org.libremail.data.settings.AppSettings import org.libremail.data.settings.SettingsRepository import org.libremail.data.sync.SyncScheduler +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import org.libremail.restart.ProcessRestarter import java.util.concurrent.ExecutionException import java.util.concurrent.TimeoutException import kotlin.test.assertEquals +import kotlin.test.assertFalse import kotlin.test.assertIs import kotlin.test.assertNotEquals import kotlin.test.assertTrue @@ -65,14 +68,33 @@ import kotlin.test.assertTrue * restart, and CLEAR_AND_REQUIRE_AUTH keeps app-lock on) and the `onAuthenticated` unlock/arm * classification (OK / UNRECOVERABLE / RETRY), so a mutation that wipes user data or drops the lock is * caught here rather than only on a device. + * + * Issue #326 migrated this ViewModel's logging to [AppLog], so a [RingLogBuffer] is installed here and + * assertions about what got logged are against [logBuffer] — never `verify { Log... }` — matching how + * the rest of the suite treats [AppLog] as the seam instead of Logcat. */ @OptIn(ExperimentalCoroutinesApi::class) class AppLockViewModelTest { private val dispatcher = UnconfinedTestDispatcher() + private val logBuffer = RingLogBuffer() @Before - fun setUp() = Dispatchers.setMain(dispatcher) + fun setUp() { + Dispatchers.setMain(dispatcher) + // android.util.Log is a no-op stub that throws "not mocked" in JVM tests, and AppLog always + // forwards to it; stub every level up front (regardless of which breadcrumbs a given test + // exercises) so no test needs its own ad-hoc Log mocking, then install a real buffer so + // breadcrumbs can be asserted for real instead of via `verify { Log... }`. + mockkStatic(Log::class) + every { Log.d(any(), any()) } returns 0 + every { Log.d(any(), any(), any()) } returns 0 + every { Log.i(any(), any()) } returns 0 + every { Log.w(any(), any()) } returns 0 + every { Log.w(any(), any(), any()) } returns 0 + every { Log.e(any(), any(), any()) } returns 0 + AppLog.install(logBuffer) + } @After fun tearDown() { @@ -174,6 +196,8 @@ class AppLockViewModelTest { // anyway (the periodic sync will still refill the wiped cache later). verify { future.get(any(), any()) } verify { processRestarter.restart() } + // Issue #326: the swallowed timeout is still breadcrumbed so a report can explain the delay. + assertTrue(logBuffer.snapshot().any { it.message.startsWith("re-sync enqueue not confirmed within timeout") }) } @Test @@ -189,6 +213,8 @@ class AppLockViewModelTest { // A failed enqueue is swallowed like a timeout: recovery restarts anyway. verify { future.get(any(), any()) } verify { processRestarter.restart() } + // Issue #326: the swallowed failure is breadcrumbed too. + assertTrue(logBuffer.snapshot().any { it.message.startsWith("re-sync enqueue failed; restarting anyway") }) } @Test @@ -208,11 +234,14 @@ class AppLockViewModelTest { assertTrue(reInterrupted) verify { future.get(any(), any()) } verify { processRestarter.restart() } + // Issue #326: the swallowed interrupt is breadcrumbed too. + assertTrue( + logBuffer.snapshot().any { it.message.startsWith("interrupted awaiting re-sync enqueue") }, + ) } @Test fun `onAuthenticated rethrows a cancellation while unwrapping and never wipes the cache`() = runTest(dispatcher) { - stubLog() val session = mockk(relaxed = true) every { session.isUnlocked() } returns false val databaseKeyStore = mockk(relaxed = true) @@ -333,6 +362,12 @@ class AppLockViewModelTest { future.get(any(), any()) processRestarter.restart() } + // Issue #326: the clear+restart recovery path is breadcrumbed with the disableAppLock flag. + assertTrue( + logBuffer.snapshot().any { + it.level == 'W' && it.message == "clearing encrypted cache and restarting (disableAppLock=true)" + }, + ) } @Test @@ -360,6 +395,12 @@ class AppLockViewModelTest { processRestarter.restart() } coVerify(exactly = 0) { settingsRepository.setAppLock(false) } + // Issue #326: app-lock stays on here, so the breadcrumb reflects disableAppLock=false. + assertTrue( + logBuffer.snapshot().any { + it.level == 'W' && it.message == "clearing encrypted cache and restarting (disableAppLock=false)" + }, + ) } @Test @@ -372,6 +413,8 @@ class AppLockViewModelTest { assertIs(vm.uiState.value) verify(exactly = 0) { processRestarter.restart() } + // Issue #326: every foreground pass with app-lock on records its (non-PII) LockAction decision. + assertEquals("app-lock foreground decision: PROCEED", logBuffer.snapshot().single().message) } @Test @@ -405,6 +448,11 @@ class AppLockViewModelTest { assertIs(vm.uiState.value) coVerify(exactly = 0) { databaseKeyStore.unlockWithAuth() } coVerify(exactly = 0) { databaseKeyStore.sealWithAuth() } + // Issue #326: a successful unlock records a breadcrumb that the cache became readable, with + // no PII (account id/email never reach this ViewModel). + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("auth seal unlocked; cache readable", entry.message) } @Test @@ -434,7 +482,6 @@ class AppLockViewModelTest { @Test fun `onAuthenticated clears the cache when the auth-bound key was deleted`() = runTest(dispatcher) { - stubLog() val (future, syncScheduler) = enqueueingScheduler() val session = mockk(relaxed = true) every { session.isUnlocked() } returns false @@ -462,11 +509,15 @@ class AppLockViewModelTest { future.get(any(), any()) processRestarter.restart() } + // Issue #326: both the classification that made this UNRECOVERABLE and the ViewModel's own + // "clearing the cache" breadcrumb are recorded. + val messages = logBuffer.snapshot().filter { it.level == 'W' }.map { it.message } + assertTrue("auth-sealed passphrase present but key was deleted; cache unrecoverable" in messages) + assertTrue("encrypted cache passphrase unrecoverable; clearing cache" in messages) } @Test fun `onAuthenticated clears the cache when the auth-bound key was permanently invalidated`() = runTest(dispatcher) { - stubLog() val (_, syncScheduler) = enqueueingScheduler() val session = mockk(relaxed = true) every { session.isUnlocked() } returns false @@ -490,11 +541,12 @@ class AppLockViewModelTest { coVerify { databaseKeyStore.setClearPending() } verify { processRestarter.restart() } + // Issue #326: the permanent-invalidation classification is breadcrumbed too. + assertTrue(logBuffer.snapshot().any { it.message.startsWith("auth-bound key permanently invalidated") }) } @Test fun `onAuthenticated re-locks for a retry when the auth window elapsed`() = runTest(dispatcher) { - stubLog() val gate = mockk(relaxed = true) every { gate.state } returns LockState.LOCKED val session = mockk(relaxed = true) @@ -520,11 +572,14 @@ class AppLockViewModelTest { verify { gate.lock() } assertIs(vm.uiState.value) verify(exactly = 0) { processRestarter.restart() } + // Issue #326: breadcrumbed with the scrubbed throwable attached (the 3-arg AppLog.w overload), + // not just the bare message — the trailing newline is the scrubbed stack trace. + val entry = logBuffer.snapshot().single { it.message.startsWith("auth window elapsed before unwrap") } + assertTrue(entry.message.contains("\n"), entry.message) } @Test fun `onAuthenticated re-locks for a retry on an ambiguous unwrap failure`() = runTest(dispatcher) { - stubLog() val gate = mockk(relaxed = true) every { gate.state } returns LockState.LOCKED val session = mockk(relaxed = true) @@ -549,6 +604,12 @@ class AppLockViewModelTest { // An ambiguous error must NOT wipe the cache on an otherwise-successful auth: re-lock + retry. verify { gate.lock() } verify(exactly = 0) { processRestarter.restart() } + // Issue #326: the catch-all classification is breadcrumbed too. + assertTrue( + logBuffer.snapshot().any { + it.message.startsWith("unexpected failure unwrapping auth-sealed passphrase") + }, + ) } @Test @@ -600,7 +661,6 @@ class AppLockViewModelTest { @Test fun `onAuthenticated re-locks for a retry when arming the auth seal fails`() = runTest(dispatcher) { - stubLog() val gate = mockk(relaxed = true) every { gate.state } returns LockState.LOCKED val session = mockk(relaxed = true) @@ -623,6 +683,25 @@ class AppLockViewModelTest { verify { gate.lock() } assertIs(vm.uiState.value) verify(exactly = 0) { processRestarter.restart() } + // Issue #326: arming failures are breadcrumbed too. + assertTrue(logBuffer.snapshot().any { it.message.startsWith("arming auth seal failed") }) + } + + // --- AppLog breadcrumbs carry no PII (issue #326) --------------------------------------------- + + @Test + fun `a cache-clear recovery breadcrumb never contains an email address`() = runTest(dispatcher) { + // AppLockViewModel only ever sees keystore/auth exceptions and enum decisions — never an + // account id or email — so no buffer line it writes should ever contain an "@". This pins that + // contract as the ViewModel evolves, rather than relying on code review alone to catch a leak. + val vm = clearOnForegroundViewModel() + + vm.onForeground() + advanceUntilIdle() + + val snapshot = logBuffer.snapshot() + assertTrue(snapshot.isNotEmpty()) + snapshot.forEach { entry -> assertFalse(entry.message.contains("@"), entry.message) } } /** A [SyncScheduler] whose `syncNow()` returns an [Operation] whose result future can be stubbed. */ @@ -646,9 +725,6 @@ class AppLockViewModelTest { ): AppLockViewModel { mockkStatic(SystemClock::class) every { SystemClock.elapsedRealtime() } returns 1_000L - // android.util.Log is a no-op stub that throws "not mocked" in JVM tests; the timeout path logs. - mockkStatic(Log::class) - every { Log.w(any(), any(), any()) } returns 0 mockkObject(KeyInvalidationPolicy) every { KeyInvalidationPolicy.decide(any(), any(), any(), any()) } returns LockAction.CLEAR_AND_REQUIRE_AUTH return viewModel( @@ -674,7 +750,6 @@ class AppLockViewModelTest { ): AppLockViewModel { mockkStatic(SystemClock::class) every { SystemClock.elapsedRealtime() } returns FOREGROUND_AT - stubLog() mockkObject(KeyInvalidationPolicy) every { KeyInvalidationPolicy.decide(any(), any(), any(), any()) } returns action return viewModel( @@ -686,13 +761,6 @@ class AppLockViewModelTest { ) } - /** android.util.Log is a no-op stub that throws "not mocked" in JVM tests; the recovery paths log. */ - private fun stubLog() { - mockkStatic(Log::class) - every { Log.w(any(), any()) } returns 0 - every { Log.w(any(), any(), any()) } returns 0 - } - private companion object { const val FOREGROUND_AT = 1_000L }