More AbsLogs and clean logs older than 48 hours on init

android/app/src/main/java/com/audiobookshelf/app/device/DeviceManager.kt

@@ -32,8 +32,8 @@ object DeviceManager {
   var deviceData: DeviceData = dbManager.getDeviceData()
   var serverConnectionConfig: ServerConnectionConfig? = null
 
-  val serverConnectionConfigId
+  val serverConnectionConfigId get() = serverConnectionConfig?.id ?: ""
-    get() = serverConnectionConfig?.id ?: ""
+  val serverConnectionConfigName get() = serverConnectionConfig?.name ?: ""
   val serverAddress
     get() = serverConnectionConfig?.address ?: ""
   val serverUserId

android/app/src/main/java/com/audiobookshelf/app/managers/DbManager.kt

@@ -5,6 +5,7 @@ import android.util.Log
 import com.audiobookshelf.app.data.*
 import com.audiobookshelf.app.models.DownloadItem
 import com.audiobookshelf.app.plugins.AbsLog
+import com.audiobookshelf.app.plugins.AbsLogger
 import io.paperdb.Paper
 import java.io.File
 
@@ -299,9 +300,24 @@ class DbManager {
         logs.add(it)
       }
     }
-    return logs
+    return logs.sortedBy { it.timestamp }
   }
   fun removeAllLogs() {
     Paper.book("log").destroy()
   }
+  fun cleanLogs() {
+    val numberOfHoursToKeep = 48
+    val keepLogCutoff = System.currentTimeMillis() - (3600000 * numberOfHoursToKeep)
+    val allLogs = getAllLogs()
+    var logsRemoved = 0
+    allLogs.forEach {
+      if (it.timestamp < keepLogCutoff) {
+        Paper.book("log").delete(it.id)
+        logsRemoved++
+      }
+    }
+    if (logsRemoved > 0) {
+      AbsLogger.info("[DbManager] cleanLogs: Removed $logsRemoved logs older than $numberOfHoursToKeep hours")
+    }
+  }
 }

android/app/src/main/java/com/audiobookshelf/app/media/MediaProgressSyncer.kt

@@ -8,6 +8,7 @@ import com.audiobookshelf.app.data.MediaProgress
 import com.audiobookshelf.app.data.PlaybackSession
 import com.audiobookshelf.app.device.DeviceManager
 import com.audiobookshelf.app.player.PlayerNotificationService
+import com.audiobookshelf.app.plugins.AbsLogger
 import com.audiobookshelf.app.server.ApiHandler
 import java.util.*
 import kotlin.concurrent.schedule
@@ -208,6 +209,7 @@ class MediaProgressSyncer(
     MediaEventManager.seekEvent(currentPlaybackSession!!, null)
   }
 
+  // Currently unused
   fun syncFromServerProgress(mediaProgress: MediaProgress) {
     currentPlaybackSession?.let {
       it.updatedAt = mediaProgress.lastUpdate
@@ -260,44 +262,46 @@ class MediaProgressSyncer(
                 tag,
                 "Sync local device current serverConnectionConfigId=${DeviceManager.serverConnectionConfig?.id}"
         )
+        AbsLogger.info("[MediaProgressSyncer] sync: Saved local progress (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: ${it.id})")
 
         // Local library item is linked to a server library item
         // Send sync to server also if connected to this server and local item belongs to this
         // server
+        val isConnectedToSameServer = it.serverConnectionConfigId != null && DeviceManager.serverConnectionConfig?.id == it.serverConnectionConfigId
         if (hasNetworkConnection &&
                         shouldSyncServer &&
                         !it.libraryItemId.isNullOrEmpty() &&
-                        it.serverConnectionConfigId != null &&
+                        isConnectedToSameServer
-                        DeviceManager.serverConnectionConfig?.id == it.serverConnectionConfigId
         ) {
           apiHandler.sendLocalProgressSync(it) { syncSuccess, errorMsg ->
             if (syncSuccess) {
               failedSyncs = 0
               playerNotificationService.alertSyncSuccess()
               DeviceManager.dbManager.removePlaybackSession(it.id) // Remove session from db
+              AbsLogger.info("[MediaProgressSyncer] sync: Successfully synced local progress (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: ${it.id})")
             } else {
               failedSyncs++
               if (failedSyncs == 2) {
                 playerNotificationService.alertSyncFailing() // Show alert in client
                 failedSyncs = 0
               }
-              Log.e(
+              AbsLogger.error("[MediaProgressSyncer] sync: Local progress sync failed (count: $failedSyncs) (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: ${it.id}) (${DeviceManager.serverConnectionConfigName})")
-                      tag,
-                      "Local Progress sync failed ($failedSyncs) to send to server $currentDisplayTitle for time $currentTime with session id=${it.id}"
-              )
             }
 
             cb(SyncResult(true, syncSuccess, errorMsg))
           }
         } else {
+          AbsLogger.info("[MediaProgressSyncer] sync: Not sending local progress to server (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: ${it.id}) (hasNetworkConnection: $hasNetworkConnection) (isConnectedToSameServer: $isConnectedToSameServer)")
           cb(SyncResult(false, null, null))
         }
       }
     } else if (hasNetworkConnection && shouldSyncServer) {
-      Log.d(tag, "sync: currentSessionId=$currentSessionId")
+      AbsLogger.info("[MediaProgressSyncer] sync: Sending progress sync to server (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: ${currentSessionId}) (${DeviceManager.serverConnectionConfigName})")
+
       apiHandler.sendProgressSync(currentSessionId, syncData) { syncSuccess, errorMsg ->
         if (syncSuccess) {
-          Log.d(tag, "Progress sync data sent to server $currentDisplayTitle for time $currentTime")
+          AbsLogger.info("[MediaProgressSyncer] sync: Successfully synced progress (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: ${currentSessionId}) (${DeviceManager.serverConnectionConfigName})")
+
           failedSyncs = 0
           playerNotificationService.alertSyncSuccess()
           lastSyncTime = System.currentTimeMillis()
@@ -308,14 +312,12 @@ class MediaProgressSyncer(
             playerNotificationService.alertSyncFailing() // Show alert in client
             failedSyncs = 0
           }
-          Log.e(
+          AbsLogger.error("[MediaProgressSyncer] sync: Progress sync failed (count: $failedSyncs) (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: $currentSessionId) (${DeviceManager.serverConnectionConfigName})")
-                  tag,
-                  "Progress sync failed ($failedSyncs) to send to server $currentDisplayTitle for time $currentTime with session id=${currentSessionId}"
-          )
         }
         cb(SyncResult(true, syncSuccess, errorMsg))
       }
     } else {
+      AbsLogger.info("[MediaProgressSyncer] sync: Not sending progress to server (title: \"$currentDisplayTitle\") (currentTime: $currentTime) (session id: $currentSessionId) (${DeviceManager.serverConnectionConfigName}) (hasNetworkConnection: $hasNetworkConnection)")
       cb(SyncResult(false, null, null))
     }
   }

android/app/src/main/java/com/audiobookshelf/app/player/PlayerNotificationService.kt

@@ -36,6 +36,7 @@ import com.audiobookshelf.app.media.MediaManager
 import com.audiobookshelf.app.media.MediaProgressSyncer
 import com.audiobookshelf.app.media.getUriToAbsIconDrawable
 import com.audiobookshelf.app.media.getUriToDrawable
+import com.audiobookshelf.app.plugins.AbsLogger
 import com.audiobookshelf.app.server.ApiHandler
 import com.google.android.exoplayer2.*
 import com.google.android.exoplayer2.audio.AudioAttributes
@@ -452,7 +453,7 @@ class PlayerNotificationService : MediaBrowserServiceCompat() {
             playbackSession
     ) // Save playback session to use when app is closed
 
-    Log.d(tag, "Set CurrentPlaybackSession MediaPlayer ${currentPlaybackSession?.mediaPlayer}")
+    AbsLogger.info("[PlayerNotificationService] preparePlayer: Started playback session for item ${currentPlaybackSession?.mediaItemId}. MediaPlayer ${currentPlaybackSession?.mediaPlayer}")
     // Notify client
     clientEventEmitter?.onPlaybackSession(playbackSession)
 
@@ -469,7 +470,7 @@ class PlayerNotificationService : MediaBrowserServiceCompat() {
       val mediaSource: MediaSource
 
       if (playbackSession.isLocal) {
-        Log.d(tag, "Playing Local Item")
+        AbsLogger.info("[PlayerNotificationService] preparePlayer: Playing local item ${currentPlaybackSession?.mediaItemId}.")
         val dataSourceFactory = DefaultDataSource.Factory(ctx)
 
         val extractorsFactory = DefaultExtractorsFactory()
@@ -483,7 +484,7 @@ class PlayerNotificationService : MediaBrowserServiceCompat() {
                 ProgressiveMediaSource.Factory(dataSourceFactory, extractorsFactory)
                         .createMediaSource(mediaItems[0])
       } else if (!playbackSession.isHLS) {
-        Log.d(tag, "Direct Playing Item")
+        AbsLogger.info("[PlayerNotificationService] preparePlayer: Direct playing item ${currentPlaybackSession?.mediaItemId}.")
         val dataSourceFactory = DefaultHttpDataSource.Factory()
 
         val extractorsFactory = DefaultExtractorsFactory()
@@ -498,7 +499,7 @@ class PlayerNotificationService : MediaBrowserServiceCompat() {
                 ProgressiveMediaSource.Factory(dataSourceFactory, extractorsFactory)
                         .createMediaSource(mediaItems[0])
       } else {
-        Log.d(tag, "Playing HLS Item")
+        AbsLogger.info("[PlayerNotificationService] preparePlayer: Playing HLS stream of item ${currentPlaybackSession?.mediaItemId}.")
         val dataSourceFactory = DefaultHttpDataSource.Factory()
         dataSourceFactory.setUserAgent(channelId)
         dataSourceFactory.setDefaultRequestProperties(

android/app/src/main/java/com/audiobookshelf/app/plugins/AbsAudioPlayer.kt

@@ -180,7 +180,8 @@ class AbsAudioPlayer : Plugin() {
     val playWhenReady = call.getBoolean("playWhenReady") == true
     val playbackRate = call.getFloat("playbackRate",1f) ?: 1f
     val startTimeOverride = call.getDouble("startTime")
-    Log.d(tag, "prepareLibraryItem lid=$libraryItemId, startTimeOverride=$startTimeOverride, playbackRate=$playbackRate")
+
+    AbsLogger.info("[AbsAudioPlayer] prepareLibraryItem: lid=$libraryItemId, startTimeOverride=$startTimeOverride, playbackRate=$playbackRate")
 
     if (libraryItemId.isEmpty()) {
       Log.e(tag, "Invalid call to play library item no library item id")

android/app/src/main/java/com/audiobookshelf/app/plugins/AbsDatabase.kt

@@ -36,6 +36,7 @@ class AbsDatabase : Plugin() {
 
     DeviceManager.dbManager.cleanLocalMediaProgress()
     DeviceManager.dbManager.cleanLocalLibraryItems()
+    DeviceManager.dbManager.cleanLogs()
   }
 
   @PluginMethod
@@ -219,15 +220,12 @@ class AbsDatabase : Plugin() {
 
   @PluginMethod
   fun syncLocalSessionsWithServer(call:PluginCall) {
-    AbsLogger.info("[AbsDatabase] syncLocalSessionsWithServer")
     if (DeviceManager.serverConnectionConfig == null) {
-      Log.e(tag, "syncLocalSessionsWithServer not connected to server")
+      AbsLogger.error("[AbsDatabase] syncLocalSessionsWithServer: not connected to server")
       return call.resolve()
     }
 
     apiHandler.syncLocalMediaProgressForUser {
-      Log.d(tag, "Finished syncing local media progress for user")
-      AbsLogger.info("[AbsDatabase] Finished syncing local media progress for user")
       val savedSessions = DeviceManager.dbManager.getPlaybackSessions().filter { it.serverConnectionConfigId == DeviceManager.serverConnectionConfigId }
 
       if (savedSessions.isNotEmpty()) {
@@ -235,6 +233,7 @@ class AbsDatabase : Plugin() {
           if (!success) {
             call.resolve(JSObject("{\"error\":\"$errorMsg\"}"))
           } else {
+            AbsLogger.info("[AbsDatabase] syncLocalSessionsWithServer: Finished sending local playback sessions to server. Removing ${savedSessions.size} saved sessions.")
             // Remove all local sessions
             savedSessions.forEach {
               DeviceManager.dbManager.removePlaybackSession(it.id)
@@ -243,6 +242,7 @@ class AbsDatabase : Plugin() {
           }
         }
       } else {
+        AbsLogger.info("[AbsDatabase] syncLocalSessionsWithServer: No saved local playback sessions to send to server.")
         call.resolve()
       }
     }

android/app/src/main/java/com/audiobookshelf/app/server/ApiHandler.kt

@@ -13,6 +13,7 @@ import com.audiobookshelf.app.media.MediaProgressSyncData
 import com.audiobookshelf.app.media.SyncResult
 import com.audiobookshelf.app.models.User
 import com.audiobookshelf.app.BuildConfig
+import com.audiobookshelf.app.plugins.AbsLogger
 import com.fasterxml.jackson.annotation.JsonIgnoreProperties
 import com.fasterxml.jackson.core.json.JsonReadFeature
 import com.fasterxml.jackson.module.kotlin.jacksonObjectMapper
@@ -468,22 +469,27 @@ class ApiHandler(var ctx:Context) {
     val deviceInfo = DeviceInfo(deviceId, Build.MANUFACTURER, Build.MODEL, Build.VERSION.SDK_INT, BuildConfig.VERSION_NAME)
 
     val payload = JSObject(jacksonMapper.writeValueAsString(LocalSessionsSyncRequestPayload(playbackSessions, deviceInfo)))
-    Log.d(tag, "Sending ${playbackSessions.size} saved local playback sessions to server")
+    AbsLogger.info("[ApiHandler] sendSyncLocalSessions: Sending ${playbackSessions.size} saved local playback sessions to server (${DeviceManager.serverConnectionConfigName})")
+
     postRequest("/api/session/local-all", payload, null) {
       if (!it.getString("error").isNullOrEmpty()) {
-        Log.e(tag, "Failed to sync local sessions")
+        AbsLogger.error("[ApiHandler] sendSyncLocalSessions: Failed to sync local sessions. (${it.getString("error")})")
         cb(false, it.getString("error"))
       } else {
         val response = jacksonMapper.readValue<LocalSessionsSyncResponsePayload>(it.toString())
         response.results.forEach { localSessionSyncResult ->
           Log.d(tag, "Synced session result ${localSessionSyncResult.id}|${localSessionSyncResult.progressSynced}|${localSessionSyncResult.success}")
+
           playbackSessions.find { ps -> ps.id == localSessionSyncResult.id }?.let { session ->
             if (localSessionSyncResult.progressSynced == true) {
               val syncResult = SyncResult(true, true, "Progress synced on server")
               MediaEventManager.saveEvent(session, syncResult)
-              Log.i(tag, "Successfully synced session ${session.displayTitle} with server")
+
+              AbsLogger.info("[ApiHandler] sendSyncLocalSessions: Synced session \"${session.displayTitle}\" with server, server progress was updated for item ${session.mediaItemId}")
             } else if (!localSessionSyncResult.success) {
-              Log.e(tag, "Failed to sync session ${session.displayTitle} with server. Error: ${localSessionSyncResult.error}")
+              AbsLogger.error("[ApiHandler] sendSyncLocalSessions: Failed to sync session \"${session.displayTitle}\" with server. Error: ${localSessionSyncResult.error}")
+            } else {
+              AbsLogger.info("[ApiHandler] sendSyncLocalSessions: Synced session \"${session.displayTitle}\" with server. Server progress was up-to-date for item ${session.mediaItemId}")
             }
           }
         }
@@ -493,37 +499,52 @@ class ApiHandler(var ctx:Context) {
   }
 
   fun syncLocalMediaProgressForUser(cb: () -> Unit) {
+    AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: Server connection ${DeviceManager.serverConnectionConfigName}")
+
     // Get all local media progress for this server
     val allLocalMediaProgress = DeviceManager.dbManager.getAllLocalMediaProgress().filter { it.serverConnectionConfigId == DeviceManager.serverConnectionConfigId }
     if (allLocalMediaProgress.isEmpty()) {
-      Log.d(tag, "No local media progress to sync")
+      AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: No local media progress to sync")
       return cb()
     }
 
-    getCurrentUser { _user ->
+    AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: Found ${allLocalMediaProgress.size} local media progress")
-      _user?.let { user->
+
+    getCurrentUser { user ->
+      if (user == null) {
+        AbsLogger.error("[ApiHandler] syncLocalMediaProgressForUser: Failed to load user from server (${DeviceManager.serverConnectionConfigName})")
+      } else {
+        var numLocalMediaProgressUptToDate = 0
+        var numLocalMediaProgressUpdated = 0
+
         // Compare server user progress with local progress
         user.mediaProgress.forEach { mediaProgress ->
           // Get matching local media progress
           allLocalMediaProgress.find { it.isMatch(mediaProgress) }?.let { localMediaProgress ->
             if (mediaProgress.lastUpdate > localMediaProgress.lastUpdate) {
-              Log.d(tag, "Server progress for media item id=\"${mediaProgress.mediaItemId}\" is more recent then local. Updating local current time ${localMediaProgress.currentTime} to ${mediaProgress.currentTime}")
+              AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: Server progress for item \"${mediaProgress.mediaItemId}\" is more recent than local. Local progress last updated ${localMediaProgress.lastUpdate}, server progress last updated ${mediaProgress.lastUpdate}. Updating local current time ${localMediaProgress.currentTime} to ${mediaProgress.currentTime}")
               localMediaProgress.updateFromServerMediaProgress(mediaProgress)
               MediaEventManager.syncEvent(mediaProgress, "Sync on server connection")
               DeviceManager.dbManager.saveLocalMediaProgress(localMediaProgress)
+              numLocalMediaProgressUpdated++
             } else if (localMediaProgress.lastUpdate > mediaProgress.lastUpdate && localMediaProgress.ebookLocation != null && localMediaProgress.ebookLocation != mediaProgress.ebookLocation) {
               // Patch ebook progress to server
+              AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: Local progress for ebook item \"${mediaProgress.mediaItemId}\" is more recent than server progress. Local progress last updated ${localMediaProgress.lastUpdate}, server progress last updated ${mediaProgress.lastUpdate}. Sending server request to update ebook progress from ${mediaProgress.ebookProgress} to ${localMediaProgress.ebookProgress}")
               val endpoint = "/api/me/progress/${localMediaProgress.libraryItemId}"
               val updatePayload = JSObject()
               updatePayload.put("ebookLocation", localMediaProgress.ebookLocation)
               updatePayload.put("ebookProgress", localMediaProgress.ebookProgress)
               updatePayload.put("lastUpdate", localMediaProgress.lastUpdate)
               patchRequest(endpoint,updatePayload) {
-                Log.d(tag, "syncLocalMediaProgressForUser patched ebook progress")
+                AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: Successfully updated server ebook progress for item item \"${mediaProgress.mediaItemId}\"")
               }
+            } else {
+              numLocalMediaProgressUptToDate++
             }
           }
         }
+
+        AbsLogger.info("[ApiHandler] syncLocalMediaProgressForUser: Finishing syncing local media progress with server. $numLocalMediaProgressUptToDate up-to-date, $numLocalMediaProgressUpdated updated")
       }
       cb()
     }

components/app/AudioPlayerContainer.vue

@@ -9,7 +9,7 @@
 </template>
 
 <script>
-import { AbsAudioPlayer } from '@/plugins/capacitor'
+import { AbsAudioPlayer, AbsLogger } from '@/plugins/capacitor'
 import { Dialog } from '@capacitor/dialog'
 import CellularPermissionHelpers from '@/mixins/cellularPermissionHelpers'
 
@@ -190,6 +190,7 @@ export default {
         })
     },
     async playLibraryItem(payload) {
+      await AbsLogger.info({ message: `[AudioPlayerContainer] playLibraryItem: Received play request for library item ${payload.libraryItemId} ${payload.episodeId ? `episode ${payload.episodeId}` : ''}` })
       const libraryItemId = payload.libraryItemId
       const episodeId = payload.episodeId
       const startTime = payload.startTime

layouts/default.vue

@@ -221,12 +221,12 @@ export default {
     },
     async userMediaProgressUpdated(payload) {
       const prog = payload.data // MediaProgress
-      console.log(`[default] userMediaProgressUpdate checking for local media progress ${payload.id}`)
+      await AbsLogger.info({ message: `[default] userMediaProgressUpdate: Received updated media progress for current user from socket event. Media item id ${payload.id}` })
 
       // Check if this media item is currently open in the player, paused, and this progress update is coming from a different session
       const isMediaOpenInPlayer = this.$store.getters['getIsMediaStreaming'](prog.libraryItemId, prog.episodeId)
       if (isMediaOpenInPlayer && this.$store.getters['getCurrentPlaybackSessionId'] !== payload.sessionId && !this.$store.state.playerIsPlaying) {
-        console.log('[default] userMediaProgressUpdated for current open media item', payload.data.currentTime)
+        await AbsLogger.info({ message: `[default] userMediaProgressUpdate: Item is currently open in player, paused and this progress update is coming from a different session. Updating playback time to ${payload.data.currentTime}` })
         this.$eventBus.$emit('playback-time-update', payload.data.currentTime)
       }
 
@@ -237,12 +237,12 @@ export default {
       // Progress update is more recent then local progress
       if (localProg && localProg.lastUpdate < prog.lastUpdate) {
         if (localProg.currentTime == prog.currentTime && localProg.isFinished == prog.isFinished) {
-          console.log('[default] syncing progress server lastUpdate > local lastUpdate but currentTime and isFinished is equal')
+          await AbsLogger.info({ message: `[default] userMediaProgressUpdate: server lastUpdate is more recent but progress is up-to-date (libraryItemId: ${prog.libraryItemId}${prog.episodeId ? ` episodeId: ${prog.episodeId}` : ''})` })
           return
         }
 
         // Server progress is more up-to-date
-        console.log(`[default] syncing progress from server with local item for "${prog.libraryItemId}" ${prog.episodeId ? `episode ${prog.episodeId}` : ''} | server lastUpdate=${prog.lastUpdate} > local lastUpdate=${localProg.lastUpdate}`)
+        await AbsLogger.info({ message: `[default] userMediaProgressUpdate: syncing progress from server with local item for "${prog.libraryItemId}" ${prog.episodeId ? `episode ${prog.episodeId}` : ''} | server lastUpdate=${prog.lastUpdate} > local lastUpdate=${localProg.lastUpdate}` })
         const payload = {
           localMediaProgressId: localProg.id,
           mediaProgress: prog
@@ -280,7 +280,7 @@ export default {
       }
 
       if (newLocalMediaProgress?.id) {
-        console.log(`[default] local media progress updated for ${newLocalMediaProgress.id}`)
+        await AbsLogger.info({ message: `[default] userMediaProgressUpdate: local media progress updated for ${newLocalMediaProgress.id}` })
         this.$store.commit('globals/updateLocalMediaProgress', newLocalMediaProgress)
       }
     },

pages/logs.vue

@@ -157,3 +157,4 @@ export default {
   }
 }
 </script>
+