feat(logs): give the default log a boot narrative

The INFO default landed a readable log but an incomplete one: only the boot
census came from our own code, so the default read as "warnings + census" with
nothing between process start and the 20s mark. The first four seconds — the
expensive part — were silent.

Adds the missing spine, ten INFO lines a boot:

- `AmethystApp`: version, process and effective log level at start. The
  napplet-sandbox skip is promoted too — it is the one line that explains why
  `instance` is unset and `LocalCache` empty in that process, which otherwise
  reads as a broken app rather than a deliberately secret-free sandbox.
- `LocalPreferences`: how many accounts are saved (nearly every per-account
  subsystem multiplies by this), then each account's load with its elapsed ms.
  Decrypting one account's settings is among the most expensive things a cold
  start does and "which account was slow" is the first question when a boot
  drags. The six intermediate steps stay at DEBUG.
- `TorService`: every status transition, with time since bootstrap started. All
  status writes now go through one `setStatus` helper instead of nine scattered
  assignments, so a transition is logged exactly once; self-transitions are
  skipped because the reset paths reassign `Off` defensively. A stuck
  `Connecting`, an `Active` that took 40s and a silent drop to `Off` are three
  different bugs that used to look identical.
- `BootRelayDiagnostics`: adds a census at 5s. The pool is assembled and
  dialling well before 20s, and the early datapoint is what separates "slow to
  connect" from "connected fine, slow to serve" — on device it reads pool=21
  at 5s against pool=359 at 20s. Paid for by folding the `=====` banners down
  to DEBUG, so a census is 3 INFO lines instead of 5.

Reads on device as:

    I AmethystApp: Amethyst 1.13.1-DEBUG starting in main process (log level INFO)
    I TorService: Off -> Connecting
    I LocalPreferences: Found 4 saved account(s)
    I LocalPreferences: Loaded account npub1gcx… in 394ms
    I LocalPreferences: Loaded account npub142g… in 760ms
    I BootRelayDiag: census @5s pool=21 opened=17 served_events=14 …
    I TorService: Connecting -> Active after 9910ms
    I BootRelayDiag: census @20s pool=359 opened=158 served_events=78 …

Verified by tag on a cold start: +10 INFO lines from our code, no other change
to volume. (Raw totals moved more, but that run happened to autoplay video, so
15 extra INFO lines came from Android's media/codec stack — not from this.)

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

amethyst/src/main/java/com/vitorpamplona/amethyst/Amethyst.kt

@@ -108,10 +108,15 @@ class Amethyst : Application() {
         // is self-contained (WebView + IPC), so we skip all app init there and
         // leave `instance` unset; any accidental use fails fast.
         if (isNappletSandbox) {
-            Log.d("AmethystApp") { "Skipping AppModules init in sandbox process" }
+            // Milestone, not chatter: this is the one line that explains why `instance` is unset
+            // and `LocalCache` is empty in this process. Without it a napplet-process log looks
+            // like a broken app rather than a deliberately secret-free sandbox.
+            Log.i("AmethystApp") { "Napplet sandbox process starting — no account, no AppModules" }
             return
         }
 
+        Log.i("AmethystApp") { "Amethyst ${BuildConfig.VERSION_NAME} starting in main process (log level ${Log.minLevel})" }
+
         instance = AppModules(this)
 
         // Hydrate the device-local favorite-apps list (main process only; the sandbox never reads it).

amethyst/src/main/java/com/vitorpamplona/amethyst/LocalPreferences.kt

@@ -73,6 +73,7 @@ import com.vitorpamplona.quartz.nip78AppData.AppSpecificDataEvent
 import com.vitorpamplona.quartz.nip85TrustedAssertions.list.TrustProviderListEvent
 import com.vitorpamplona.quartz.nipB1Bolt12Zaps.offer.Bolt12OfferListEvent
 import com.vitorpamplona.quartz.utils.Log
+import com.vitorpamplona.quartz.utils.TimeUtils
 import kotlinx.coroutines.CancellationException
 import kotlinx.coroutines.Dispatchers
 import kotlinx.coroutines.async
@@ -325,6 +326,9 @@ object LocalPreferences {
                     }
 
                 if (!newSystemOfAccounts.isNullOrEmpty()) {
+                    // How many accounts are in play is the first thing you need when reading any
+                    // boot log: nearly every per-account subsystem below multiplies by this number.
+                    Log.i("LocalPreferences") { "Found ${newSystemOfAccounts.size} saved account(s)" }
                     newSystemOfAccounts
                 } else {
                     val oldAccounts = getString(PrefKeys.SAVED_ACCOUNTS, null)?.split(COMMA) ?: listOf()
@@ -712,6 +716,7 @@ object LocalPreferences {
 
     private suspend fun innerLoadCurrentAccountFromEncryptedStorage(npub: String?): AccountSettings? {
         Log.d("LocalPreferences") { "Load account from file $npub" }
+        val startedAtMs = TimeUtils.nowMillis()
         val result =
             withContext(Dispatchers.IO) {
                 return@withContext with(encryptedPreferences(npub)) {
@@ -1017,7 +1022,11 @@ object LocalPreferences {
                     )
                 }
             }
-        Log.d("LocalPreferences") { "Loaded account from file $npub" }
+        // Milestone with its cost attached. Decrypting and parsing one account's settings is one of
+        // the most expensive things a cold start does (it resolves a fan of backup events), it runs
+        // once per account, and "which account was slow" is the first question when a boot drags.
+        // The six intermediate steps above stay at DEBUG.
+        Log.i("LocalPreferences") { "Loaded account $npub in ${TimeUtils.nowMillis() - startedAtMs}ms" }
         return result
     }
 

amethyst/src/main/java/com/vitorpamplona/amethyst/service/relayClient/diagnostics/BootRelayDiagnostics.kt

@@ -56,7 +56,10 @@ import kotlin.concurrent.thread
  */
 class BootRelayDiagnostics(
     val client: INostrClient,
-    val dumpAtSeconds: List<Long> = listOf(20, 45, 90),
+    // 5s first: the pool is assembled and dialling well before 20s, and the early datapoint is what
+    // distinguishes "slow to connect" from "connected fine, slow to serve". Affordable because the
+    // rollup is now 3 INFO lines rather than 5 — the ===== banners moved to DEBUG.
+    val dumpAtSeconds: List<Long> = listOf(5, 20, 45, 90),
 ) {
     companion object {
         const val TAG = "BootRelayDiag"
@@ -219,17 +222,17 @@ class BootRelayDiagnostics(
             r.closed.forEach { (k, v) -> closedTotals[k] = (closedTotals[k] ?: 0) + v.get() }
         }
 
-        Log.i(TAG, "===== boot census @${atSeconds}s =====")
+        Log.d(TAG, "===== boot census @${atSeconds}s =====")
         Log.i(
             TAG,
-            "pool=${snapshot.size} opened=${opened.size} served_events=${served.size} never_opened=${neverOpened.size} " +
+            "census @${atSeconds}s pool=${snapshot.size} opened=${opened.size} served_events=${served.size} never_opened=${neverOpened.size} " +
                 "dials=${snapshot.values.sumOf { it.tentatives.get() }} " +
                 "events=${snapshot.values.sumOf { it.events.get() }} " +
                 "reqs=${snapshot.values.sumOf { it.reqsSent.get() }} " +
                 "auths=${snapshot.values.sumOf { it.authsSent.get() }}",
         )
-        Log.i(TAG, "failures_by_cause=" + causeTotals.entries.sortedByDescending { it.value }.joinToString { "${it.key}:${it.value}" })
-        Log.i(TAG, "closed_by_prefix=" + closedTotals.entries.sortedByDescending { it.value }.joinToString { "${it.key}:${it.value}" })
+        Log.i(TAG, "census @${atSeconds}s failures_by_cause=" + causeTotals.entries.sortedByDescending { it.value }.joinToString { "${it.key}:${it.value}" })
+        Log.i(TAG, "census @${atSeconds}s closed_by_prefix=" + closedTotals.entries.sortedByDescending { it.value }.joinToString { "${it.key}:${it.value}" })
 
         // Relays that cost us dials and gave nothing back, worst first: the wasted-effort list.
         Log.d(TAG, "--- top wasted dials (no events received) ---")
@@ -261,6 +264,6 @@ class BootRelayDiagnostics(
                         "openMs=${r.firstOpenAtMs.get()} eoseMs=${r.firstEoseAtMs.get()} dials=${r.tentatives.get()}",
                 )
             }
-        Log.i(TAG, "===== end census @${atSeconds}s =====")
+        Log.d(TAG, "===== end census @${atSeconds}s =====")
     }
 }

amethyst/src/main/java/com/vitorpamplona/amethyst/ui/tor/TorService.kt

@@ -98,6 +98,24 @@ class TorService(
     private val _status = MutableStateFlow<TorServiceStatus>(TorServiceStatus.Off)
     override val status: StateFlow<TorServiceStatus> = _status.asStateFlow()
 
+    /**
+     * Every status change goes through here so the transition is logged exactly once, at INFO, with
+     * the time since bootstrap started.
+     *
+     * Tor state is the single biggest determinant of whether a boot works — a stuck `Connecting`,
+     * an `Active` that took 40s, and a silent drop back to `Off` are three completely different
+     * bugs that used to look identical in the log, because the per-status detail lived only in
+     * Arti's own DEBUG chatter. Self-transitions are not logged: the reset paths reassign `Off`
+     * defensively and repeating it adds nothing.
+     */
+    private fun setStatus(next: TorServiceStatus) {
+        val prev = _status.value
+        _status.value = next
+        if (prev::class == next::class && prev.toString() == next.toString()) return
+        val since = if (bootstrapStartedAtMs > 0) " after ${System.currentTimeMillis() - bootstrapStartedAtMs}ms" else ""
+        Log.i("TorService") { "${prev::class.simpleName} -> ${next::class.simpleName}$since" }
+    }
+
     /**
      * Runtime detector for a rotten guard sample. Arti logs [ALL_GUARDS_DOWN_MARKER] every time it
      * fails to find a usable guard; [GUARDS_DOWN_THRESHOLD] of those inside [GUARDS_DOWN_WINDOW_MS]
@@ -218,11 +236,11 @@ class TorService(
         lifecycleMutex.withLock {
             if (proxyRunning.get()) {
                 if (_status.value is TorServiceStatus.Active) return@withLock
-                _status.value = TorServiceStatus.Connecting
+                setStatus(TorServiceStatus.Connecting)
                 return@withLock
             }
 
-            _status.value = TorServiceStatus.Connecting
+            setStatus(TorServiceStatus.Connecting)
 
             withContext(Dispatchers.IO) {
                 // Initialize TorClient once — this bootstraps the Tor network.
@@ -292,7 +310,7 @@ class TorService(
                     if (initResult != 0) {
                         Log.e("TorService") { "Failed to initialize Arti on retry: error $initResult" }
                         initialized.set(false)
-                        _status.value = TorServiceStatus.Off
+                        setStatus(TorServiceStatus.Off)
                         return@withContext
                     }
                 }
@@ -313,7 +331,7 @@ class TorService(
 
                 if (!started) {
                     Log.e("TorService") { "Failed to start SOCKS proxy after $MAX_PORT_RETRIES attempts" }
-                    _status.value = TorServiceStatus.Off
+                    setStatus(TorServiceStatus.Off)
                     return@withContext
                 }
 
@@ -332,7 +350,7 @@ class TorService(
                 // reset/stop can't clobber it.
                 val startedAt = bootstrapStartedAtMs
                 val elapsed = if (startedAt > 0) System.currentTimeMillis() - startedAt else -1
-                _status.value = TorServiceStatus.Active(socksPort)
+                setStatus(TorServiceStatus.Active(socksPort))
                 Log.d("TorService") { "Arti SOCKS proxy active on port $socksPort (bootstrap took ${elapsed}ms)" }
             }
         }
@@ -350,7 +368,7 @@ class TorService(
                 Log.d("TorService") { "SOCKS proxy stopped" }
             }
 
-            _status.value = TorServiceStatus.Off
+            setStatus(TorServiceStatus.Off)
         }
     }
 
@@ -365,7 +383,7 @@ class TorService(
         lifecycleMutex.withLock {
             resetLocked()
         }
-        _status.value = TorServiceStatus.Off
+        setStatus(TorServiceStatus.Off)
     }
 
     /**
@@ -381,7 +399,7 @@ class TorService(
                 clearAllArtiData()
             }
         }
-        _status.value = TorServiceStatus.Off
+        setStatus(TorServiceStatus.Off)
     }
 
     /**