logging: add release-visible breadcrumbs and a verbose toggle

Playback now logs each track transition and end at info (title/artist/album/source/reason), sync logs per-entity counts and pruned rows, and the Subsonic client logs server error codes and the token-auth fallback. Add a Verbose logging setting that drops the file level to debug at runtime (persisted) so a support session can capture full detail without flooding normal release logs.

app/src/main/kotlin/com/subtracks/data/prefs/UserPreferences.kt

@@ -121,6 +121,14 @@ class UserPreferences(
 
     private val offlineModeKey = booleanPreferencesKey("offline_mode")
 
+    fun verboseLogging(): Flow<Boolean> = store.data.map { prefs -> prefs[verboseLoggingKey] ?: false }
+
+    suspend fun setVerboseLogging(enabled: Boolean) {
+        store.edit { prefs -> prefs[verboseLoggingKey] = enabled }
+    }
+
+    private val verboseLoggingKey = booleanPreferencesKey("verbose_logging")
+
     suspend fun lastSeed(): ArtworkSeedValue? {
         val prefs = store.data.first()
         val cacheKey = prefs[lastSeedKey] ?: return null

app/src/main/kotlin/com/subtracks/data/repo/SourceRepository.kt

@@ -111,7 +111,10 @@ class SourceRepository(
                 active = config?.let { ActiveSource(it.id, it.toMusicSource(quality, concurrency)) }
                 _quality.value = quality
                 if (sourceChanged && config != null && config.useTokenAuth && !_offline.value) {
-                    scope.launch { runCatching { config.toClient().check("ping") } }
+                    scope.launch {
+                        runCatching { config.toClient().check("ping") }
+                            .onSuccess { Log.i("net", "connected (ping ok)") }
+                    }
                 }
             }
         }

app/src/main/kotlin/com/subtracks/data/source/subsonic/SubsonicClient.kt

@@ -2,6 +2,7 @@ package com.subtracks.data.source.subsonic
 
 import com.subtracks.R
 import com.subtracks.UiMessage
+import com.subtracks.log.Log
 import okhttp3.HttpUrl
 import okhttp3.OkHttpClient
 import okhttp3.Request
@@ -60,7 +61,11 @@ class SubsonicClient(
         return try {
             execute(method, params, body)
         } catch (failure: SubsonicException) {
-            if (failure.code !in TOKEN_AUTH_UNSUPPORTED_CODES || !usedTokenAuth) throw failure
+            if (failure.code !in TOKEN_AUTH_UNSUPPORTED_CODES || !usedTokenAuth) {
+                Log.w("http", "$method failed: server code ${failure.code} \"${failure.message}\"")
+                throw failure
+            }
+            Log.w("http", "$method: token auth unsupported (server code ${failure.code}), retrying with plaintext")
             disableTokenAuth()
             execute(method, params, body)
         }

app/src/main/kotlin/com/subtracks/data/sync/SyncManager.kt

@@ -65,8 +65,8 @@ class SyncManager(
                 val source = sourceRepository.activeMusicSource() ?: throw NoServerException()
                 Log.i("sync", "started (source ${source.id})")
                 serverActions.flush()
-                SyncService(db, source).sync()
+                val summary = SyncService(db, source).sync()
-                Log.i("sync", "finished in ${elapsedMs(startedAt)}ms")
+                Log.i("sync", "finished in ${elapsedMs(startedAt)}ms: $summary")
                 SyncStatus.Success
             } catch (cancellation: CancellationException) {
                 throw cancellation

app/src/main/kotlin/com/subtracks/data/sync/SyncService.kt

@@ -20,13 +20,21 @@ class SyncService(
     private val db: SubtracksDatabase,
     private val source: MusicSource,
 ) {
-    suspend fun sync() {
+    private var artistsSynced = 0
+    private var albumsSynced = 0
+    private var songsSynced = 0
+    private var playlistsSynced = 0
+    private var playlistSongsSynced = 0
+    private var pruned = 0
+
+    suspend fun sync(): SyncSummary {
         syncArtists()
         syncAlbums()
         syncSongs()
         aggregatePlayData()
         syncPlaylists()
         syncPlaylistSongs()
+        return SyncSummary(artistsSynced, albumsSynced, songsSynced, playlistsSynced, playlistSongsSynced, pruned)
     }
 
     private suspend fun syncArtists() {
@@ -36,8 +44,9 @@ class SyncService(
             if (batch.isEmpty()) return@collect
             write("artists", artistColumns, primaryKey, batch) { it.values() }
             batch.forEach { seen.add(idHash(it.id)) }
+            artistsSynced += batch.size
         }
-        pruneStaleIds(seen, { library.artistIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deleteArtists(source.id, it) })
+        pruned += pruneStaleIds(seen, { library.artistIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deleteArtists(source.id, it) })
     }
 
     private suspend fun syncAlbums() {
@@ -53,8 +62,10 @@ class SyncService(
             writeAlbumsAndDiscs(batch, discs)
             batch.forEach { seenAlbums.add(idHash(it.id)) }
             discs.forEach { seenDiscs.add(discHash(it.albumId, it.disc)) }
+            albumsSynced += batch.size
         }
-        pruneStaleIds(seenAlbums, { library.albumIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deleteAlbums(source.id, it) })
+        pruned += pruneStaleIds(seenAlbums, { library.albumIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deleteAlbums(source.id, it) })
+        pruned +=
             pruneStaleDiscs(seenDiscs, { albumId, disc -> library.discKeysAfter(source.id, albumId, disc, PRUNE_PAGE) }) {
                 deleteStaleDiscs(it)
             }
@@ -67,8 +78,9 @@ class SyncService(
             if (batch.isEmpty()) return@collect
             writeSongs(batch)
             batch.forEach { seen.add(idHash(it.id)) }
+            songsSynced += batch.size
         }
-        pruneStaleIds(seen, { library.songIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deleteSongs(source.id, it) })
+        pruned += pruneStaleIds(seen, { library.songIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deleteSongs(source.id, it) })
     }
 
     private suspend fun writeSongs(batch: List<Song>) {
@@ -106,8 +118,9 @@ class SyncService(
             if (batch.isEmpty()) return@collect
             write("playlists", playlistColumns, primaryKey, batch) { it.values() }
             batch.forEach { seen.add(idHash(it.id)) }
+            playlistsSynced += batch.size
         }
-        pruneStaleIds(seen, { library.playlistIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deletePlaylists(source.id, it) })
+        pruned += pruneStaleIds(seen, { library.playlistIdsAfter(source.id, it, PRUNE_PAGE) }, { library.deletePlaylists(source.id, it) })
     }
 
     private suspend fun syncPlaylistSongs() {
@@ -118,6 +131,7 @@ class SyncService(
             if (batch.isEmpty()) return@collect
             write("playlist_songs", playlistSongColumns, playlistSongKey, batch) { it.values() }
             batch.forEach { counts[it.playlistId] = (counts[it.playlistId] ?: 0L) + 1L }
+            playlistSongsSynced += batch.size
         }
         playlistIds.forEach { library.deletePlaylistSongsFrom(source.id, it, counts[it] ?: 0L) }
         library.deleteOrphanPlaylistSongs(source.id)
@@ -173,15 +187,17 @@ class SyncService(
         seen: HashedIds,
         pageOf: suspend (afterId: String) -> List<String>,
         delete: suspend (Collection<String>) -> Unit,
-    ) {
+    ): Int {
         seen.freeze()
         var afterId = ""
+        var pruned = 0
         while (true) {
             val ids = pageOf(afterId)
-            if (ids.isEmpty()) return
+            if (ids.isEmpty()) return pruned
             val stale = ids.filterNot { seen.contains(idHash(it)) }
             stale.chunked(DELETE_CHUNK).forEach { delete(it) }
-            if (ids.size < PRUNE_PAGE) return
+            pruned += stale.size
+            if (ids.size < PRUNE_PAGE) return pruned
             afterId = ids.last()
         }
     }
@@ -190,22 +206,33 @@ class SyncService(
         seen: HashedIds,
         pageOf: suspend (afterAlbumId: String, afterDisc: Long) -> List<DiscKey>,
         delete: suspend (Collection<DiscKey>) -> Unit,
-    ) {
+    ): Int {
         seen.freeze()
         var afterAlbumId = ""
         var afterDisc = 0L
+        var pruned = 0
         while (true) {
             val keys = pageOf(afterAlbumId, afterDisc)
-            if (keys.isEmpty()) return
+            if (keys.isEmpty()) return pruned
             val stale = keys.filterNot { seen.contains(discHash(it.albumId, it.disc)) }
             stale.chunked(DELETE_CHUNK).forEach { delete(it) }
-            if (keys.size < PRUNE_PAGE) return
+            pruned += stale.size
+            if (keys.size < PRUNE_PAGE) return pruned
             afterAlbumId = keys.last().albumId
             afterDisc = keys.last().disc
         }
     }
 }
 
+data class SyncSummary(
+    val artists: Int,
+    val albums: Int,
+    val songs: Int,
+    val playlists: Int,
+    val playlistSongs: Int,
+    val pruned: Int,
+)
+
 private const val DELETE_CHUNK = 500
 private const val PRUNE_PAGE = 500
 private const val INITIAL_HASH_CAPACITY = 256

app/src/main/kotlin/com/subtracks/di/AppModule.kt

@@ -28,6 +28,7 @@ import com.subtracks.data.repo.QueueRepository
 import com.subtracks.data.repo.SourceRepository
 import com.subtracks.data.source.ServerActionSink
 import com.subtracks.data.sync.SyncManager
+import com.subtracks.log.Log
 import com.subtracks.playback.MediaSessionConnection
 import com.subtracks.playback.PlaybackController
 import com.subtracks.playback.PlayerConnection
@@ -48,6 +49,8 @@ import com.subtracks.ui.settings.SettingsViewModel
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Dispatchers
 import kotlinx.coroutines.SupervisorJob
+import kotlinx.coroutines.flow.launchIn
+import kotlinx.coroutines.flow.onEach
 import okhttp3.OkHttpClient
 import org.koin.core.module.dsl.viewModel
 import org.koin.core.qualifier.named
@@ -68,6 +71,7 @@ fun appModule(
     single { CoroutineScope(SupervisorJob() + Dispatchers.Default) }
     single(named("io")) { CoroutineScope(SupervisorJob() + Dispatchers.IO) }
     single(named("playback")) { CoroutineScope(SupervisorJob() + Dispatchers.Main.immediate) }
+    single(createdAtStart = true) { get<UserPreferences>().verboseLogging().onEach(Log::setVerbose).launchIn(get()) }
     single {
         SourceRepository(
             get(),

app/src/main/kotlin/com/subtracks/log/Log.kt

@@ -21,19 +21,24 @@ object Log {
     private var fileStore: LogFileStore? = null
     private var appContext: Context? = null
     private var consoleLevel = LogLevel.DEBUG
+    private var defaultFileLevel = LogLevel.INFO
     private var crashHandlerInstalled = false
 
     fun init(context: Context) {
         val app = context.applicationContext
         appContext = app
         consoleLevel = if (BuildConfig.DEBUG) LogLevel.VERBOSE else LogLevel.INFO
-        val fileLevel = if (BuildConfig.DEBUG) LogLevel.DEBUG else LogLevel.INFO
+        defaultFileLevel = if (BuildConfig.DEBUG) LogLevel.DEBUG else LogLevel.INFO
         fileStore?.shutdown()
-        fileStore = LogFileStore(File(app.filesDir, "logs"), fileLevel)
+        fileStore = LogFileStore(File(app.filesDir, "logs"), defaultFileLevel)
         installCrashHandler()
         i("app", "started ${BuildConfig.VERSION_NAME} (${BuildConfig.VERSION_CODE}) on Android ${Build.VERSION.SDK_INT} ${Build.MODEL}")
     }
 
+    fun setVerbose(enabled: Boolean) {
+        fileStore?.setMinLevel(if (enabled) LogLevel.DEBUG else defaultFileLevel)
+    }
+
     fun v(
         tag: String,
         message: String,

app/src/main/kotlin/com/subtracks/log/LogFileStore.kt

@@ -12,7 +12,7 @@ enum class LogLevel { VERBOSE, DEBUG, INFO, WARN, ERROR }
 
 class LogFileStore(
     private val rootDir: File,
-    private val minLevel: LogLevel,
+    @Volatile private var minLevel: LogLevel,
     private val maxFileBytes: Long = DEFAULT_MAX_FILE_BYTES,
     private val maxFiles: Int = DEFAULT_MAX_FILES,
 ) {
@@ -55,6 +55,10 @@ class LogFileStore(
         runCatching { executor.submit {}.get() }
     }
 
+    fun setMinLevel(level: LogLevel) {
+        minLevel = level
+    }
+
     fun shutdown() {
         executor.shutdownNow()
     }

app/src/main/kotlin/com/subtracks/playback/Media3PlayerHandle.kt

@@ -141,7 +141,7 @@ class Media3PlayerHandle(
                     mediaItem: MediaItem?,
                     reason: Int,
                 ) {
-                    Log.d("playback", "${describe(mediaItem)} transition=${transitionReason(reason)}")
+                    Log.i("playback", "${describe(mediaItem)} transition=${transitionReason(reason)}")
                     listener.onTransition()
                 }
 
@@ -166,6 +166,9 @@ class Media3PlayerHandle(
                         "state=$playbackState position=${controller.currentPosition} " +
                             "duration=${duration(controller.duration)} itemDuration=${currentItem?.durationMs}",
                     )
+                    if (playbackState == Player.STATE_ENDED) {
+                        Log.i("playback", "ended ${describe(controller.currentMediaItem)}")
+                    }
                 }
             },
         )

app/src/main/kotlin/com/subtracks/ui/settings/SettingsScreen.kt

@@ -103,6 +103,7 @@ fun SettingsRoute(
     val downloadOverMetered by viewModel.downloadOverMetered.collectAsStateWithLifecycle()
     val scrobbling by viewModel.scrobbling.collectAsStateWithLifecycle()
     val offline by viewModel.offline.collectAsStateWithLifecycle()
+    val verboseLogging by viewModel.verboseLogging.collectAsStateWithLifecycle()
     val context = LocalContext.current
     val scope = rememberCoroutineScope()
     SettingsScreen(
@@ -115,6 +116,7 @@ fun SettingsRoute(
         downloadOverMetered = downloadOverMetered,
         scrobbling = scrobbling,
         offline = offline,
+        verboseLogging = verboseLogging,
         onSelectSource = viewModel::selectSource,
         onEditServer = onEditServer,
         onWifiQualityChange = viewModel::setWifiQuality,
@@ -124,6 +126,7 @@ fun SettingsRoute(
         onDownloadOverMeteredChange = viewModel::setDownloadOverMetered,
         onScrobblingChange = viewModel::setScrobbling,
         onOfflineChange = viewModel::setOfflineMode,
+        onVerboseLoggingChange = viewModel::setVerboseLogging,
         onAddServer = onAddServer,
         onOpenDownloads = onOpenDownloads,
         onOpenLicenses = onOpenLicenses,
@@ -162,6 +165,7 @@ fun SettingsScreen(
     scrobbling: Boolean,
     modifier: Modifier = Modifier,
     offline: Boolean = false,
+    verboseLogging: Boolean = false,
     onSelectSource: (Long) -> Unit,
     onEditServer: (Long) -> Unit,
     onWifiQualityChange: (StreamQuality) -> Unit,
@@ -171,6 +175,7 @@ fun SettingsScreen(
     onDownloadOverMeteredChange: (Boolean) -> Unit,
     onScrobblingChange: (Boolean) -> Unit,
     onOfflineChange: (Boolean) -> Unit = {},
+    onVerboseLoggingChange: (Boolean) -> Unit = {},
     onAddServer: () -> Unit,
     onOpenDownloads: () -> Unit,
     onOpenLicenses: () -> Unit,
@@ -400,6 +405,26 @@ fun SettingsScreen(
                     colors = ListItemDefaults.colors(containerColor = Color.Transparent),
                 )
             }
+            item {
+                ListItem(
+                    headlineContent = { Text(stringResource(R.string.settings_about_verbose_logging)) },
+                    supportingContent = { Text(stringResource(R.string.settings_about_verbose_logging_description)) },
+                    trailingContent = {
+                        Switch(
+                            checked = verboseLogging,
+                            onCheckedChange = onVerboseLoggingChange,
+                            colors =
+                                SwitchDefaults.colors(
+                                    uncheckedThumbColor = MaterialTheme.colorScheme.onSurfaceVariant,
+                                    uncheckedTrackColor = MaterialTheme.colorScheme.surfaceVariant,
+                                    uncheckedBorderColor = MaterialTheme.colorScheme.outline,
+                                ),
+                        )
+                    },
+                    modifier = Modifier.clickable { onVerboseLoggingChange(!verboseLogging) },
+                    colors = ListItemDefaults.colors(containerColor = Color.Transparent),
+                )
+            }
             item { Spacer(Modifier.height(fill)) }
         }
     }

app/src/main/kotlin/com/subtracks/ui/settings/SettingsViewModel.kt

@@ -55,10 +55,19 @@ class SettingsViewModel(
 
     val offline: StateFlow<Boolean> = sourceRepository.offline
 
+    val verboseLogging: StateFlow<Boolean> =
+        userPreferences
+            .verboseLogging()
+            .stateIn(viewModelScope, SharingStarted.WhileSubscribed(5_000), false)
+
     fun setOfflineMode(enabled: Boolean) {
         sourceRepository.setOfflineMode(enabled)
     }
 
+    fun setVerboseLogging(enabled: Boolean) {
+        viewModelScope.launch { userPreferences.setVerboseLogging(enabled) }
+    }
+
     fun selectSource(id: Long) {
         viewModelScope.launch { sourceRepository.selectSource(id) }
     }

app/src/main/res/values/strings.xml

@@ -63,6 +63,8 @@
     <string name="settings_about_share_logs_empty">No logs to send yet</string>
     <string name="settings_about_share_logs_failed">Couldn\'t prepare the logs</string>
     <string name="settings_about_share_logs_subject">Subtracks logs</string>
+    <string name="settings_about_verbose_logging">Verbose logging</string>
+    <string name="settings_about_verbose_logging_description">Log extra detail for troubleshooting. Log files get larger.</string>
     <string name="settings_about_version">Version %1$s</string>
     <string name="settings_music_name">Playback</string>
     <string name="settings_music_options_scrobble_description_on">Send now playing and play counts</string>