diff --git a/app/src/main/kotlin/org/libremail/data/sync/BackfillWorker.kt b/app/src/main/kotlin/org/libremail/data/sync/BackfillWorker.kt index fd4ae7c..d340512 100644 --- a/app/src/main/kotlin/org/libremail/data/sync/BackfillWorker.kt +++ b/app/src/main/kotlin/org/libremail/data/sync/BackfillWorker.kt @@ -10,6 +10,7 @@ import dagger.assisted.Assisted import dagger.assisted.AssistedInject import kotlinx.coroutines.CancellationException import org.libremail.data.security.EncryptedCacheGuard +import org.libremail.reporting.AppLog /** * Runs one bounded slice of the full-history backfill (issue #12). Cancellable (WorkManager stops it @@ -31,7 +32,10 @@ class BackfillWorker @AssistedInject constructor( override suspend fun doWork(): Result { // Can't open the encrypted DB without the user present — retry later rather than parking a // WorkManager thread (which also wedges the shared serial executor) on an unsatisfiable await. - if (cacheGuard.isCacheLocked()) return Result.retry() + if (cacheGuard.isCacheLocked()) { + AppLog.i(TAG, "backfill deferred: cache locked") + return Result.retry() + } return runCatching { // Chain bounded slices back-to-back while history remains, so a large mailbox isn't limited // to one slice per periodic run. runBackfill() returns true while any folder still has pages @@ -39,8 +43,19 @@ class BackfillWorker @AssistedInject constructor( val mailBackfiller = backfiller.get() while (mailBackfiller.runBackfill() && !isStopped) { /* page the next slice */ } }.fold( - onSuccess = { Result.success() }, - onFailure = { error -> if (error is CancellationException) throw error else Result.retry() }, + onSuccess = { + AppLog.i(TAG, "backfill worker: success") + Result.success() + }, + onFailure = { error -> + if (error is CancellationException) throw error + AppLog.w(TAG, "backfill worker: retry", error) + Result.retry() + }, ) } + + private companion object { + const val TAG = "BackfillWorker" + } } diff --git a/app/src/main/kotlin/org/libremail/data/sync/MailBackfiller.kt b/app/src/main/kotlin/org/libremail/data/sync/MailBackfiller.kt index 7d8fa92..6ee52b0 100644 --- a/app/src/main/kotlin/org/libremail/data/sync/MailBackfiller.kt +++ b/app/src/main/kotlin/org/libremail/data/sync/MailBackfiller.kt @@ -25,6 +25,8 @@ import org.libremail.domain.model.ImapConnectionParams import org.libremail.domain.repository.MailRepository import org.libremail.mail.ImapClient import org.libremail.power.BatteryStatusProvider +import org.libremail.reporting.AppLog +import org.libremail.reporting.accountLogRef import javax.inject.Inject import javax.inject.Singleton @@ -65,13 +67,19 @@ class MailBackfiller @Inject constructor( * count as more work — it is retried on a future scheduled run instead of spun on back-to-back. */ suspend fun runBackfill(maxBatches: Int = DEFAULT_MAX_BATCHES): Boolean = maintenanceGate.mutex.withLock { + AppLog.i(TAG, "backfill slice: maxBatches=$maxBatches") var remaining = maxBatches var moreWork = false - for (account in accountDao.getAll().map { it.toDomain() }) { + accounts@ for (account in accountDao.getAll().map { it.toDomain() }) { val params = runCatching { connectionFactory.imapParamsFor(account) }.getOrNull() ?: continue val policy = accountSettingsRepository.effectiveRetention(settingsRepository, account.id) for (folder in messageDao.syncedFolders(account.id)) { - if (remaining <= 0) return@withLock true + if (remaining <= 0) { + // The budget ran out before every folder was visited, so there is very likely more + // work left even though nothing here reported it directly. + moreWork = true + break@accounts + } // Per-folder failures (e.g. a transient server error) must not abort the whole slice. val result = runCatching { backfillFolder(account, params, folder, policy, remaining) } .getOrElse { FolderResult(batches = 0, moreWork = true) } @@ -79,6 +87,7 @@ class MailBackfiller @Inject constructor( if (result.moreWork) moreWork = true } } + AppLog.i(TAG, "backfill slice done: moreWork=$moreWork") moreWork } @@ -153,6 +162,8 @@ class MailBackfiller @Inject constructor( delay(BACKFILL_BATCH_DELAY_MS) } if (complete) markComplete(account.id, folder, beforeUid) + val folderLabel = logSafeFolderLabel(folder) + AppLog.d(TAG, "backfill ${accountLogRef(account.id)} folder=$folderLabel pages=$batches complete=$complete") return FolderResult(batches, moreWork = !complete && !stalled) } @@ -226,6 +237,8 @@ class MailBackfiller @Inject constructor( } private companion object { + const val TAG = "MailBackfiller" + /** Headers fetched per server page. */ const val BACKFILL_BATCH_SIZE = 50 diff --git a/app/src/main/kotlin/org/libremail/data/sync/MailPruner.kt b/app/src/main/kotlin/org/libremail/data/sync/MailPruner.kt index 07a9d8b..e07728e 100644 --- a/app/src/main/kotlin/org/libremail/data/sync/MailPruner.kt +++ b/app/src/main/kotlin/org/libremail/data/sync/MailPruner.kt @@ -13,6 +13,7 @@ import org.libremail.data.settings.AccountSettingsRepository import org.libremail.data.settings.RetentionPolicy import org.libremail.data.settings.SettingsRepository import org.libremail.data.settings.effectiveRetention +import org.libremail.reporting.AppLog import javax.inject.Inject import javax.inject.Singleton @@ -49,6 +50,7 @@ class MailPruner @Inject constructor( if (policy.isUnlimited) continue removed += pruneAccount(account.id, policy, nowMillis) } + AppLog.i(TAG, "prune done: removed=$removed") removed } @@ -82,6 +84,8 @@ class MailPruner @Inject constructor( } private companion object { + const val TAG = "MailPruner" + /** Ids per DELETE, kept under SQLite's 999-host-parameter limit on older Android. */ const val DELETE_CHUNK = 500 } diff --git a/app/src/main/kotlin/org/libremail/data/sync/MailSyncer.kt b/app/src/main/kotlin/org/libremail/data/sync/MailSyncer.kt index 3b63219..1b649e6 100644 --- a/app/src/main/kotlin/org/libremail/data/sync/MailSyncer.kt +++ b/app/src/main/kotlin/org/libremail/data/sync/MailSyncer.kt @@ -21,6 +21,8 @@ import org.libremail.domain.repository.MailRepository import org.libremail.mail.ImapClient import org.libremail.notifications.MailNotifier import org.libremail.power.BatteryStatusProvider +import org.libremail.reporting.AppLog +import org.libremail.reporting.accountLogRef import javax.inject.Inject import javax.inject.Singleton @@ -47,6 +49,7 @@ class MailSyncer @Inject constructor( /** Syncs every account's inbox. Succeeds if at least one account synced (or there are none). */ override suspend fun syncAll(): Result { val accounts = accountDao.getAll().map { it.toDomain() } + AppLog.i(TAG, "sync all: ${accounts.size} accounts") if (accounts.isEmpty()) return Result.success(0) val result = syncMutex.withLock { @@ -64,6 +67,8 @@ class MailSyncer @Inject constructor( } if (anySuccess || firstError == null) Result.success(total) else Result.failure(firstError) } + result.onSuccess { total -> AppLog.i(TAG, "sync all done: fetched=$total") } + .onFailure { error -> AppLog.w(TAG, "sync all failed", error) } if (result.isSuccess) accounts.forEach { prefetchIfEnabled(it, INBOX) } return result } @@ -147,6 +152,8 @@ class MailSyncer @Inject constructor( notifier.notifyNewMail(account, newMessages.sortedByDescending { it.timestampMillis }) } } + val folderLabel = logSafeFolderLabel(folder) + AppLog.d(TAG, "sync ${accountLogRef(account.id)} folder=$folderLabel fetched=${fetched.size}") fetched.size } @@ -172,6 +179,7 @@ class MailSyncer @Inject constructor( } private companion object { + const val TAG = "MailSyncer" const val INBOX = "INBOX" /** diff --git a/app/src/main/kotlin/org/libremail/data/sync/PruneWorker.kt b/app/src/main/kotlin/org/libremail/data/sync/PruneWorker.kt index a0f8c86..003c9c4 100644 --- a/app/src/main/kotlin/org/libremail/data/sync/PruneWorker.kt +++ b/app/src/main/kotlin/org/libremail/data/sync/PruneWorker.kt @@ -9,6 +9,7 @@ import dagger.Lazy import dagger.assisted.Assisted import dagger.assisted.AssistedInject import org.libremail.data.security.EncryptedCacheGuard +import org.libremail.reporting.AppLog /** * Enforces device-only retention (issue #13) by running [MailPruner]. Purely local — it never @@ -28,10 +29,23 @@ class PruneWorker @AssistedInject constructor( override suspend fun doWork(): Result { // Can't open the encrypted DB without the user present — retry later rather than parking a // WorkManager thread (which also wedges the shared serial executor) on an unsatisfiable await. - if (cacheGuard.isCacheLocked()) return Result.retry() + if (cacheGuard.isCacheLocked()) { + AppLog.i(TAG, "prune deferred: cache locked") + return Result.retry() + } return runCatching { pruner.get().prune() }.fold( - onSuccess = { Result.success() }, - onFailure = { Result.retry() }, + onSuccess = { + AppLog.i(TAG, "prune worker: success") + Result.success() + }, + onFailure = { error -> + AppLog.w(TAG, "prune worker: retry", error) + Result.retry() + }, ) } + + private companion object { + const val TAG = "PruneWorker" + } } diff --git a/app/src/main/kotlin/org/libremail/data/sync/SyncLogging.kt b/app/src/main/kotlin/org/libremail/data/sync/SyncLogging.kt new file mode 100644 index 0000000..24b832f --- /dev/null +++ b/app/src/main/kotlin/org/libremail/data/sync/SyncLogging.kt @@ -0,0 +1,45 @@ +// SPDX-License-Identifier: GPL-3.0-or-later +package org.libremail.data.sync + +/** + * The folder name safe to write to an [org.libremail.reporting.AppLog] breadcrumb (and so, in turn, a + * submitted [org.libremail.reporting.DebugReport]): the leaf name itself for a known **system** folder + * (INBOX, Sent, Drafts, Trash, Spam/Junk, Archive — including the alternate names real IMAP servers use + * for them), or a fixed placeholder for anything else. A user-created folder or label (e.g. a client + * name or project) can be PII-ish, so only this fixed, closed set of well-known names is ever logged + * verbatim; every other folder logs as the placeholder, regardless of nesting or the server's hierarchy + * delimiter. Matching is name-only — no server SPECIAL-USE attributes are available down here at the + * sync layer — so it is necessarily best-effort in the same way + * [org.libremail.domain.model.FolderRole.roleOf]'s display-name fallback is. That is the safe direction: + * a false negative just logs the placeholder, never a leaked name. + */ +internal fun logSafeFolderLabel(folder: String): String { + val leaf = folder.substringAfterLast('/').substringAfterLast('.').trim() + return if (leaf.lowercase() in SYSTEM_FOLDER_NAMES) leaf else FOLDER_PLACEHOLDER +} + +private const val FOLDER_PLACEHOLDER = "" + +/** Case-insensitive leaf names recognized as provider-supplied system folders, never user-created. */ +private val SYSTEM_FOLDER_NAMES = setOf( + "inbox", + "sent", + "sent mail", + "sent items", + "sent messages", + "drafts", + "draft", + "junk", + "spam", + "junk e-mail", + "junk email", + "bulk mail", + "trash", + "deleted", + "deleted items", + "deleted messages", + "bin", + "archive", + "archives", + "all mail", +) diff --git a/app/src/main/kotlin/org/libremail/data/sync/SyncWorker.kt b/app/src/main/kotlin/org/libremail/data/sync/SyncWorker.kt index 32a8b01..987162c 100644 --- a/app/src/main/kotlin/org/libremail/data/sync/SyncWorker.kt +++ b/app/src/main/kotlin/org/libremail/data/sync/SyncWorker.kt @@ -9,6 +9,7 @@ import dagger.Lazy import dagger.assisted.Assisted import dagger.assisted.AssistedInject import org.libremail.data.security.EncryptedCacheGuard +import org.libremail.reporting.AppLog @HiltWorker class SyncWorker @AssistedInject constructor( @@ -23,10 +24,23 @@ class SyncWorker @AssistedInject constructor( override suspend fun doWork(): Result { // Can't open the encrypted DB without the user present — retry later rather than parking a // WorkManager thread (which also wedges the shared serial executor) on an unsatisfiable await. - if (cacheGuard.isCacheLocked()) return Result.retry() + if (cacheGuard.isCacheLocked()) { + AppLog.i(TAG, "sync deferred: cache locked") + return Result.retry() + } return mailSyncer.get().syncAll().fold( - onSuccess = { Result.success() }, - onFailure = { Result.retry() }, + onSuccess = { + AppLog.i(TAG, "sync worker: success") + Result.success() + }, + onFailure = { error -> + AppLog.w(TAG, "sync worker: retry", error) + Result.retry() + }, ) } + + private companion object { + const val TAG = "SyncWorker" + } } diff --git a/app/src/test/kotlin/org/libremail/data/sync/BackfillWorkerTest.kt b/app/src/test/kotlin/org/libremail/data/sync/BackfillWorkerTest.kt index b45ed6e..66a59ef 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/BackfillWorkerTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/BackfillWorkerTest.kt @@ -1,31 +1,59 @@ // SPDX-License-Identifier: GPL-3.0-or-later package org.libremail.data.sync +import android.util.Log import androidx.work.ListenableWorker.Result import dagger.Lazy import io.mockk.coEvery import io.mockk.coVerify import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import io.mockk.verify import kotlinx.coroutines.test.runTest +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.security.EncryptedCacheGuard +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import kotlin.test.assertEquals +import kotlin.test.assertFalse +import kotlin.test.assertTrue /** * [BackfillWorker] must defer while the encrypted cache is locked rather than park this WorkManager * thread opening the DB. It gates on [EncryptedCacheGuard], resolving the (`Lazy`) [MailBackfiller] - * only once unlocked — the same pre-auth invariant `SyncWorker`/`SendWorker` enforce. + * only once unlocked — the same pre-auth invariant `SyncWorker`/`SendWorker` enforce. Also covers issue + * #329's AppLog breadcrumbs on the deferred/success/retry outcomes. */ class BackfillWorkerTest { private val backfiller = mockk() private val lazyBackfiller = mockk> { every { get() } returns backfiller } private val cacheGuard = mockk() + private val logBuffer = RingLogBuffer() private fun worker() = BackfillWorker(mockk(relaxed = true), mockk(relaxed = true), lazyBackfiller, cacheGuard) + @Before + fun setUp() { + // `android.util.Log` is a no-op stub under plain JVM unit tests, so it is statically mocked here, + // mirroring org.libremail.reporting.AppLogTest — doWork() now breadcrumbs through AppLog. + 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() = unmockkAll() + @Test fun `retries without resolving the backfiller when the cache is locked`() = runTest { coEvery { cacheGuard.isCacheLocked() } returns true @@ -54,4 +82,44 @@ class BackfillWorkerTest { assertEquals(Result.retry(), worker().doWork()) } + + // --- issue #329: AppLog breadcrumbs --------------------------------------------------------- + + @Test + fun `logs a deferred breadcrumb when the cache is locked, without touching the backfiller`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns true + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("backfill deferred: cache locked", entry.message) + } + + @Test + fun `logs a success breadcrumb once every chained slice completes`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns false + coEvery { backfiller.runBackfill(any()) } returnsMany listOf(true, false) + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("backfill worker: success", entry.message) + } + + @Test + fun `logs a scrubbed retry breadcrumb when backfilling throws`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns false + coEvery { backfiller.runBackfill(any()) } throws + IllegalStateException("auth failed for a@example.org") + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('W', entry.level) + assertTrue(entry.message.startsWith("backfill worker: retry"), entry.message) + assertTrue(entry.message.contains("IllegalStateException"), entry.message) + assertFalse(entry.message.contains("a@example.org"), entry.message) + } } diff --git a/app/src/test/kotlin/org/libremail/data/sync/MailBackfillerTest.kt b/app/src/test/kotlin/org/libremail/data/sync/MailBackfillerTest.kt index c145cd1..7c1af2d 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/MailBackfillerTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/MailBackfillerTest.kt @@ -2,12 +2,15 @@ package org.libremail.data.sync import android.content.Context +import android.util.Log import com.icegreen.greenmail.util.GreenMail import com.icegreen.greenmail.util.ServerSetupTest import io.mockk.coEvery import io.mockk.coVerify import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import jakarta.mail.Folder import jakarta.mail.Message import jakarta.mail.Session @@ -38,6 +41,8 @@ import org.libremail.mail.FetchedMessage import org.libremail.mail.ImapClient import org.libremail.power.BatteryStatus import org.libremail.power.BatteryStatusProvider +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import java.util.Date import java.util.Properties import kotlin.test.assertEquals @@ -74,15 +79,33 @@ class MailBackfillerTest { // though `cached` would silently absorb it. Isolates the "no message fetched twice" guarantee. private var totalOffered = 0 + // issue #329: AppLog breadcrumbs — a fresh buffer per test (a new instance per @Test, per JUnit4). + private val logBuffer = RingLogBuffer() + @Before fun setUp() { greenMail = GreenMail(ServerSetupTest.SMTP_IMAP) greenMail.start() greenMail.setUser("alice@example.org", "secret") + + // `android.util.Log` is a no-op stub under plain JVM unit tests, so it is statically mocked here + // for the whole class, mirroring org.libremail.reporting.AppLogTest — every test now exercises + // real backfill code, which breadcrumbs through AppLog. + 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() = greenMail.stop() + fun tearDown() { + greenMail.stop() + unmockkAll() + } private fun params() = ImapConnectionParams( host = "127.0.0.1", @@ -353,6 +376,68 @@ class MailBackfillerTest { } } + // --- issue #329: AppLog breadcrumbs --------------------------------------------------------- + + @Test + fun `runBackfill logs a start breadcrumb, a per-folder breadcrumb, and a done breadcrumb`() = runTest { + appendMessages(TOTAL) + seedForegroundWindow() + + backfiller(AccountSettings("acct")).runBackfill(maxBatches = 3) + + val snapshot = logBuffer.snapshot() + val start = snapshot.first { it.message.startsWith("backfill slice:") } + val perFolder = snapshot.first { it.message.startsWith("backfill acct:") } + val done = snapshot.first { it.message.startsWith("backfill slice done:") } + assertEquals('I', start.level) + assertEquals("backfill slice: maxBatches=3", start.message) + assertEquals('D', perFolder.level) + assertTrue(perFolder.message.contains("folder=INBOX"), perFolder.message) + assertTrue(perFolder.message.contains("pages="), perFolder.message) + assertTrue(perFolder.message.contains("complete="), perFolder.message) + assertEquals('I', done.level) + assertTrue(done.message.contains("moreWork="), done.message) + snapshot.forEach { assertNoPii(it.message) } + } + + @Test + fun `an already-complete folder logs no redundant per-folder breadcrumb on the next slice`() = runTest { + appendMessages(60) + seedForegroundWindow() + val backfiller = backfiller(AccountSettings("acct")) + var guard = 0 + while (backfiller.runBackfill() && guard++ < 10) { /* drive to completion */ } + logBuffer.clear() + + // The folder is already complete; this slice does no work for it. + backfiller.runBackfill() + + assertTrue( + logBuffer.snapshot().none { it.message.startsWith("backfill acct:") }, + "an already-complete folder must not spam a breadcrumb on every subsequent slice", + ) + } + + @Test + fun `no slice of a full backfill ever logs the account's email, host, or a message address`() = runTest { + appendMessages(TOTAL) + seedForegroundWindow() + val backfiller = backfiller(AccountSettings("acct")) + + var guard = 0 + while (backfiller.runBackfill() && guard++ < 10) { /* drive to completion */ } + + val snapshot = logBuffer.snapshot() + assertTrue(snapshot.isNotEmpty(), "the run must have logged something to be a meaningful check") + snapshot.forEach { assertNoPii(it.message) } + } + + /** No test fixture's email address or host may ever reach a log line — the hard PII rule. */ + private fun assertNoPii(message: String) { + assertFalse(message.contains("@example.org"), message) // covers the account and every sender + assertFalse(message.contains("127.0.0.1"), message) // the GreenMail host + } + private fun fetchedMessage(uid: String) = FetchedMessage( uid = uid, sender = "Sender", diff --git a/app/src/test/kotlin/org/libremail/data/sync/MailMaintenanceGateTest.kt b/app/src/test/kotlin/org/libremail/data/sync/MailMaintenanceGateTest.kt index ade809d..7732a0e 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/MailMaintenanceGateTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/MailMaintenanceGateTest.kt @@ -1,9 +1,12 @@ // SPDX-License-Identifier: GPL-3.0-or-later package org.libremail.data.sync +import android.util.Log import io.mockk.coEvery import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import kotlinx.coroutines.CompletableDeferred import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.delay @@ -13,6 +16,8 @@ import kotlinx.coroutines.launch import kotlinx.coroutines.runBlocking import kotlinx.coroutines.sync.withLock import kotlinx.coroutines.yield +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.local.dao.AccountDao import org.libremail.data.local.dao.MessageDao @@ -28,6 +33,8 @@ import org.libremail.mail.FetchedMessage import org.libremail.mail.ImapClient import org.libremail.power.BatteryStatus import org.libremail.power.BatteryStatusProvider +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import java.util.Collections import java.util.concurrent.atomic.AtomicInteger import kotlin.test.assertEquals @@ -52,6 +59,25 @@ class MailMaintenanceGateTest { smtp = ServerConfigEmbedded("127.0.0.1", 465, "NONE"), ) + // issue #329: MailBackfiller/MailPruner now breadcrumb through AppLog, whose Logcat forwarding + // (`android.util.Log`) is a no-op stub under plain JVM unit tests — mock it statically, mirroring + // org.libremail.reporting.AppLogTest. The breadcrumbs themselves are asserted in + // MailBackfillerTest/MailPrunerTest; this class only needs to not crash. + @Before + fun setUp() { + 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(RingLogBuffer()) + } + + @After + fun tearDown() = unmockkAll() + /** * The gate's contract: everyone who acquires the *same* gate takes the *same* exclusive lock, so no * two critical sections overlap. Guards against a regression that hands out a fresh lock per access diff --git a/app/src/test/kotlin/org/libremail/data/sync/MailPrunerTest.kt b/app/src/test/kotlin/org/libremail/data/sync/MailPrunerTest.kt index acc09e8..f475878 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/MailPrunerTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/MailPrunerTest.kt @@ -2,15 +2,20 @@ package org.libremail.data.sync import android.content.Context +import android.util.Log import io.mockk.Runs import io.mockk.coEvery import io.mockk.coVerify import io.mockk.every import io.mockk.just import io.mockk.mockk +import io.mockk.mockkStatic import io.mockk.slot +import io.mockk.unmockkAll import kotlinx.coroutines.flow.flowOf import kotlinx.coroutines.test.runTest +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.local.dao.AccountDao import org.libremail.data.local.dao.MessageDao @@ -20,8 +25,11 @@ import org.libremail.data.settings.AccountSettingsRepository import org.libremail.data.settings.AppSettings import org.libremail.data.settings.SettingsRepository import org.libremail.domain.model.AccountSettings +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import java.io.File import kotlin.test.assertEquals +import kotlin.test.assertFalse import kotlin.test.assertTrue /** @@ -40,6 +48,27 @@ class MailPrunerTest { smtp = ServerConfigEmbedded("smtp.example.org", 465, "SSL_TLS"), ) + // issue #329: AppLog breadcrumbs — a fresh buffer per test (a new instance per @Test, per JUnit4). + private val logBuffer = RingLogBuffer() + + @Before + fun setUp() { + // `android.util.Log` is a no-op stub under plain JVM unit tests, so it is statically mocked here + // for the whole class, mirroring org.libremail.reporting.AppLogTest — every test now exercises + // real prune code, which breadcrumbs through AppLog. + 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() = unmockkAll() + private fun pruner(global: AppSettings, accountSettings: AccountSettings, messageDao: MessageDao): MailPruner { val accountDao = mockk() coEvery { accountDao.getAll() } returns listOf(account) @@ -136,4 +165,61 @@ class MailPrunerTest { coVerify(exactly = 0) { messageDao.syncedIdsOlderThan(any(), any()) } coVerify(exactly = 0) { messageDao.syncedIdsBeyondCountInFolder(any(), any(), any()) } } + + // --- issue #329: AppLog breadcrumbs --------------------------------------------------------- + + @Test + fun `prune logs a done breadcrumb with the removed count`() = runTest { + val messageDao = mockk(relaxed = true) + coEvery { messageDao.syncedFolders("acct") } returns listOf("INBOX", "Archive") + coEvery { messageDao.syncedIdsBeyondCountInFolder("acct", "INBOX", 2) } returns + listOf("acct:INBOX:1", "acct:INBOX:2") + coEvery { messageDao.syncedIdsBeyondCountInFolder("acct", "Archive", 2) } returns listOf("acct:Archive:9") + coEvery { messageDao.deleteByIds(any()) } just Runs + + pruner( + global = AppSettings(retentionCount = 2, retentionMonths = 0), + accountSettings = AccountSettings("acct"), + messageDao = messageDao, + ).prune() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("prune done: removed=3", entry.message) + } + + @Test + fun `prune logs a done breadcrumb even when nothing is removed`() = runTest { + val messageDao = mockk(relaxed = true) + + pruner( + global = AppSettings(retentionCount = 0, retentionMonths = 0), + accountSettings = AccountSettings("acct"), + messageDao = messageDao, + ).prune() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("prune done: removed=0", entry.message) + } + + @Test + fun `prune never logs the account email or host, even while removing rows by age and count`() = runTest { + val messageDao = mockk(relaxed = true) + coEvery { messageDao.syncedFolders("acct") } returns listOf("INBOX") + coEvery { messageDao.syncedIdsOlderThan(any(), any()) } returns listOf("acct:INBOX:1") + coEvery { messageDao.syncedIdsBeyondCountInFolder("acct", "INBOX", 2) } returns listOf("acct:INBOX:2") + coEvery { messageDao.deleteByIds(any()) } just Runs + + pruner( + global = AppSettings(retentionCount = 2, retentionMonths = 6), + accountSettings = AccountSettings("acct"), + messageDao = messageDao, + ).prune() + + logBuffer.snapshot().forEach { entry -> + assertFalse(entry.message.contains("a@example.org"), entry.message) + assertFalse(entry.message.contains("example.org"), entry.message) + } + } } diff --git a/app/src/test/kotlin/org/libremail/data/sync/MailSyncConcurrencyTest.kt b/app/src/test/kotlin/org/libremail/data/sync/MailSyncConcurrencyTest.kt index efe7d66..27af4f0 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/MailSyncConcurrencyTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/MailSyncConcurrencyTest.kt @@ -2,14 +2,19 @@ package org.libremail.data.sync import android.content.Context +import android.util.Log import io.mockk.coEvery import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import kotlinx.coroutines.CompletableDeferred import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.flow.flowOf import kotlinx.coroutines.launch import kotlinx.coroutines.runBlocking +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.local.dao.AccountDao import org.libremail.data.local.dao.BackfillProgressDao @@ -28,6 +33,8 @@ import org.libremail.mail.FetchedMessage import org.libremail.mail.ImapClient import org.libremail.power.BatteryStatus import org.libremail.power.BatteryStatusProvider +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import java.io.File import java.util.concurrent.atomic.AtomicInteger import kotlin.test.assertEquals @@ -74,6 +81,25 @@ class MailSyncConcurrencyTest { useXoauth2 = false, ) + // issue #329: MailSyncer/MailBackfiller/MailPruner now breadcrumb through AppLog, whose Logcat + // forwarding (`android.util.Log`) is a no-op stub under plain JVM unit tests — mock it statically, + // mirroring org.libremail.reporting.AppLogTest. The breadcrumbs themselves are asserted in + // MailSyncerTest/MailBackfillerTest/MailPrunerTest; this class only needs to not crash. + @Before + fun setUp() { + 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(RingLogBuffer()) + } + + @After + fun tearDown() = unmockkAll() + // --- sync ↔ backfill ----------------------------------------------------------------------- /** diff --git a/app/src/test/kotlin/org/libremail/data/sync/MailSyncerTest.kt b/app/src/test/kotlin/org/libremail/data/sync/MailSyncerTest.kt index 4e1a75a..0e7a0b2 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/MailSyncerTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/MailSyncerTest.kt @@ -5,12 +5,17 @@ import android.content.Context import android.net.ConnectivityManager import android.net.Network import android.net.NetworkCapabilities +import android.util.Log import io.mockk.coEvery import io.mockk.coVerify import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import kotlinx.coroutines.flow.flowOf import kotlinx.coroutines.test.runTest +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.local.dao.AccountDao import org.libremail.data.local.dao.MessageDao @@ -28,12 +33,24 @@ import org.libremail.mail.ImapClient import org.libremail.notifications.MailNotifier import org.libremail.power.BatteryStatus import org.libremail.power.BatteryStatusProvider +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import java.io.IOException import kotlin.test.assertEquals +import kotlin.test.assertFalse import kotlin.test.assertTrue +/** + * Also covers issue #329's net-new [AppLog] breadcrumbs: every test exercises real sync code, so + * `android.util.Log` (a no-op stub under plain JVM unit tests) is statically mocked here for the whole + * class, mirroring [org.libremail.reporting.AppLogTest]. [logBuffer] is fresh per test (a new + * [MailSyncerTest] instance per `@Test`, per JUnit4) and installed before every test so the dedicated + * breadcrumb tests below can assert against it directly. + */ class MailSyncerTest { + private val logBuffer = RingLogBuffer() + private val account = AccountEntity( id = "acct", email = "a@example.org", @@ -43,6 +60,21 @@ class MailSyncerTest { smtp = ServerConfigEmbedded("smtp.example.org", 465, "SSL_TLS"), ) + @Before + fun setUp() { + 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() = unmockkAll() + /** The IMAP client of the most recently built [syncer], for verifying the fetch window size. */ private lateinit var lastImapClient: ImapClient @@ -382,4 +414,61 @@ class MailSyncerTest { every { it.getSystemService(ConnectivityManager::class.java) } returns manager } } + + // --- issue #329: AppLog breadcrumbs --------------------------------------------------------- + + @Test + fun `syncFolder records a debug breadcrumb with the account ref, folder, and fetched count`() = runTest { + val repo = mockk(relaxed = true) + val fetched = listOf( + FetchedMessage("1", "Ada", "ada@example.org", "Secret subject", 1_000L, isRead = true, isFlagged = false), + ) + + syncer(FetchPolicy.ON_DEMAND, repo, fetched = fetched).syncFolder("acct", "INBOX") + + val entry = logBuffer.snapshot().single() + assertEquals('D', entry.level) + assertTrue(entry.message.contains("folder=INBOX"), entry.message) + assertTrue(entry.message.contains("fetched=1"), entry.message) + assertNoPii(entry.message) + } + + @Test + fun `syncAll logs a start breadcrumb and a done breadcrumb with the fetched total`() = runTest { + val syncer = syncAllSyncer(accounts = listOf(accountEntity("one"), accountEntity("two"))) + + syncer.syncAll() + + val snapshot = logBuffer.snapshot() + val start = snapshot.first { it.message.startsWith("sync all:") } + val done = snapshot.first { it.message.startsWith("sync all done:") } + assertEquals('I', start.level) + assertEquals("sync all: 2 accounts", start.message) + assertEquals('I', done.level) + assertEquals("sync all done: fetched=2", done.message) + snapshot.forEach { assertNoPii(it.message) } + } + + @Test + fun `syncAll logs a warning breadcrumb with the scrubbed failure when every account fails`() = runTest { + val syncer = syncAllSyncer( + accounts = listOf(accountEntity("bad1"), accountEntity("bad2")), + failingIds = setOf("bad1", "bad2"), + ) + + syncer.syncAll() + + val entry = logBuffer.snapshot().first { it.message.startsWith("sync all failed") } + assertEquals('W', entry.level) + // The throwable's class survives the scrub; its free-text message does not (issue #325). + assertTrue(entry.message.contains("IOException"), entry.message) + assertFalse(entry.message.contains("no network"), entry.message) + logBuffer.snapshot().forEach { assertNoPii(it.message) } + } + + /** No test fixture's email address or host may ever reach a log line — the hard PII rule. */ + private fun assertNoPii(message: String) { + assertFalse(message.contains("@example.org"), message) + assertFalse(message.contains("example.org"), message) + } } diff --git a/app/src/test/kotlin/org/libremail/data/sync/PruneWorkerTest.kt b/app/src/test/kotlin/org/libremail/data/sync/PruneWorkerTest.kt index 71fae4d..45fc95d 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/PruneWorkerTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/PruneWorkerTest.kt @@ -1,32 +1,60 @@ // SPDX-License-Identifier: GPL-3.0-or-later package org.libremail.data.sync +import android.util.Log import androidx.work.ListenableWorker.Result import dagger.Lazy import io.mockk.coEvery import io.mockk.coVerify import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import io.mockk.verify import kotlinx.coroutines.test.runTest +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.security.EncryptedCacheGuard +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import kotlin.test.assertEquals +import kotlin.test.assertFalse +import kotlin.test.assertTrue /** * [PruneWorker] must not touch the database while the encrypted cache is locked: opening it would park * this WorkManager thread on an unsatisfiable passphrase await (and wedge the shared serial executor). * It gates on [EncryptedCacheGuard] and only resolves the (`Lazy`) [MailPruner] once unlocked — the - * invariant every pre-auth DB entry point shares with `SyncWorker`/`SendWorker`. + * invariant every pre-auth DB entry point shares with `SyncWorker`/`SendWorker`. Also covers issue + * #329's AppLog breadcrumbs on the deferred/success/retry outcomes. */ class PruneWorkerTest { private val pruner = mockk() private val lazyPruner = mockk> { every { get() } returns pruner } private val cacheGuard = mockk() + private val logBuffer = RingLogBuffer() private fun worker() = PruneWorker(mockk(relaxed = true), mockk(relaxed = true), lazyPruner, cacheGuard) + @Before + fun setUp() { + // `android.util.Log` is a no-op stub under plain JVM unit tests, so it is statically mocked here, + // mirroring org.libremail.reporting.AppLogTest — doWork() now breadcrumbs through AppLog. + 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() = unmockkAll() + @Test fun `retries without resolving the pruner when the cache is locked`() = runTest { coEvery { cacheGuard.isCacheLocked() } returns true @@ -55,4 +83,43 @@ class PruneWorkerTest { assertEquals(Result.retry(), worker().doWork()) } + + // --- issue #329: AppLog breadcrumbs --------------------------------------------------------- + + @Test + fun `logs a deferred breadcrumb when the cache is locked, without touching the pruner`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns true + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("prune deferred: cache locked", entry.message) + } + + @Test + fun `logs a success breadcrumb when pruning succeeds`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns false + coEvery { pruner.prune(any()) } returns 5 + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("prune worker: success", entry.message) + } + + @Test + fun `logs a scrubbed retry breadcrumb when pruning throws`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns false + coEvery { pruner.prune(any()) } throws IllegalStateException("auth failed for a@example.org") + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('W', entry.level) + assertTrue(entry.message.startsWith("prune worker: retry"), entry.message) + assertTrue(entry.message.contains("IllegalStateException"), entry.message) + assertFalse(entry.message.contains("a@example.org"), entry.message) + } } diff --git a/app/src/test/kotlin/org/libremail/data/sync/SyncLoggingTest.kt b/app/src/test/kotlin/org/libremail/data/sync/SyncLoggingTest.kt new file mode 100644 index 0000000..1faf89d --- /dev/null +++ b/app/src/test/kotlin/org/libremail/data/sync/SyncLoggingTest.kt @@ -0,0 +1,57 @@ +// SPDX-License-Identifier: GPL-3.0-or-later +package org.libremail.data.sync + +import org.junit.Test +import kotlin.test.assertEquals + +/** + * [logSafeFolderLabel] is the PII gate between a raw IMAP folder path and an [org.libremail.reporting.AppLog] + * breadcrumb (issue #329's folder-name caveat): a known system folder logs by name, anything else logs + * as the fixed placeholder — never the real name, regardless of nesting or delimiter. + */ +class SyncLoggingTest { + + @Test + fun `a top-level system folder logs verbatim`() { + assertEquals("INBOX", logSafeFolderLabel("INBOX")) + assertEquals("Sent", logSafeFolderLabel("Sent")) + assertEquals("Drafts", logSafeFolderLabel("Drafts")) + assertEquals("Trash", logSafeFolderLabel("Trash")) + assertEquals("Archive", logSafeFolderLabel("Archive")) + } + + @Test + fun `matching is case-insensitive but preserves the server's own casing`() { + assertEquals("JUNK", logSafeFolderLabel("JUNK")) + assertEquals("sent items", logSafeFolderLabel("sent items")) + } + + @Test + fun `a system folder nested under a Gmail-style slash path logs only its leaf name`() { + assertEquals("Sent Mail", logSafeFolderLabel("[Gmail]/Sent Mail")) + assertEquals("All Mail", logSafeFolderLabel("[Gmail]/All Mail")) + } + + @Test + fun `a system folder nested under a Dovecot-style dot path logs only its leaf name`() { + assertEquals("Trash", logSafeFolderLabel("INBOX.Trash")) + } + + @Test + fun `a user-created top-level folder never logs its real name`() { + assertEquals("", logSafeFolderLabel("Projects")) + assertEquals("", logSafeFolderLabel("Invoice from Acme Corp")) + } + + @Test + fun `a user-created nested folder logs the placeholder, never its name or its parent`() { + assertEquals("", logSafeFolderLabel("Work/Reports")) + assertEquals("", logSafeFolderLabel("Clients/Acme Corp")) + } + + @Test + fun `a folder that merely shares a system folder's leaf name still logs only that leaf`() { + // Even a custom parent is never exposed — only the recognized leaf is ever logged, by design. + assertEquals("Archive", logSafeFolderLabel("Clients/Archive")) + } +} diff --git a/app/src/test/kotlin/org/libremail/data/sync/SyncWorkerTest.kt b/app/src/test/kotlin/org/libremail/data/sync/SyncWorkerTest.kt index f0b96a1..17faa97 100644 --- a/app/src/test/kotlin/org/libremail/data/sync/SyncWorkerTest.kt +++ b/app/src/test/kotlin/org/libremail/data/sync/SyncWorkerTest.kt @@ -1,31 +1,59 @@ // SPDX-License-Identifier: GPL-3.0-or-later package org.libremail.data.sync +import android.util.Log import androidx.work.ListenableWorker import dagger.Lazy import io.mockk.coEvery import io.mockk.coVerify import io.mockk.every import io.mockk.mockk +import io.mockk.mockkStatic +import io.mockk.unmockkAll import io.mockk.verify import kotlinx.coroutines.test.runTest +import org.junit.After +import org.junit.Before import org.junit.Test import org.libremail.data.security.EncryptedCacheGuard +import org.libremail.reporting.AppLog +import org.libremail.reporting.RingLogBuffer import kotlin.test.assertEquals +import kotlin.test.assertFalse +import kotlin.test.assertTrue /** * [SyncWorker] already gates on [EncryptedCacheGuard]; this locks that invariant in as regression * cover for the class of bug fixed in PruneWorker/BackfillWorker — while the cache is locked it must - * defer without resolving the (`Lazy`) [MailSyncer] (whose construction opens the Room DB). + * defer without resolving the (`Lazy`) [MailSyncer] (whose construction opens the Room DB). Also covers + * issue #329's AppLog breadcrumbs on the deferred/success/retry outcomes. */ class SyncWorkerTest { private val mailSyncer = mockk() private val lazySyncer = mockk> { every { get() } returns mailSyncer } private val cacheGuard = mockk() + private val logBuffer = RingLogBuffer() private fun worker() = SyncWorker(mockk(relaxed = true), mockk(relaxed = true), lazySyncer, cacheGuard) + @Before + fun setUp() { + // `android.util.Log` is a no-op stub under plain JVM unit tests, so it is statically mocked here, + // mirroring org.libremail.reporting.AppLogTest — doWork() now breadcrumbs through AppLog. + 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() = unmockkAll() + @Test fun `retries without resolving the syncer when the cache is locked`() = runTest { coEvery { cacheGuard.isCacheLocked() } returns true @@ -53,4 +81,43 @@ class SyncWorkerTest { assertEquals(ListenableWorker.Result.retry(), worker().doWork()) } + + // --- issue #329: AppLog breadcrumbs --------------------------------------------------------- + + @Test + fun `logs a deferred breadcrumb when the cache is locked, without touching the syncer`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns true + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("sync deferred: cache locked", entry.message) + } + + @Test + fun `logs a success breadcrumb when syncing succeeds`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns false + coEvery { mailSyncer.syncAll() } returns Result.success(3) + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('I', entry.level) + assertEquals("sync worker: success", entry.message) + } + + @Test + fun `logs a scrubbed retry breadcrumb when syncing fails`() = runTest { + coEvery { cacheGuard.isCacheLocked() } returns false + coEvery { mailSyncer.syncAll() } returns Result.failure(IllegalStateException("auth failed for a@example.org")) + + worker().doWork() + + val entry = logBuffer.snapshot().single() + assertEquals('W', entry.level) + assertTrue(entry.message.startsWith("sync worker: retry"), entry.message) + assertTrue(entry.message.contains("IllegalStateException"), entry.message) + assertFalse(entry.message.contains("a@example.org"), entry.message) + } }