diff --git a/android/app/src/main/java/com/audiobookshelf/app/managers/DownloadItemManager.kt b/android/app/src/main/java/com/audiobookshelf/app/managers/DownloadItemManager.kt index b83ade16..7a25ddde 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/managers/DownloadItemManager.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/managers/DownloadItemManager.kt @@ -3,12 +3,14 @@ package com.audiobookshelf.app.managers import android.content.Context import android.net.Uri import android.os.StatFs -import android.util.Log import androidx.documentfile.provider.DocumentFile +import com.anggrayudi.storage.file.fullName import com.audiobookshelf.app.device.DeviceManager import com.audiobookshelf.app.device.FolderScanner import com.audiobookshelf.app.models.DownloadItem import com.audiobookshelf.app.models.DownloadItemPart +import com.audiobookshelf.app.plugins.AbsLogger +import com.audiobookshelf.app.server.ApiHandler import com.fasterxml.jackson.core.json.JsonReadFeature import com.fasterxml.jackson.module.kotlin.jacksonObjectMapper import com.getcapacitor.JSObject @@ -22,7 +24,6 @@ import kotlinx.coroutines.SupervisorJob import kotlinx.coroutines.cancel import kotlinx.coroutines.delay import kotlinx.coroutines.launch -import okhttp3.Call /** Manages the process-owned queue for app-managed downloads. */ class DownloadItemManager( @@ -32,10 +33,14 @@ class DownloadItemManager( ) { private val tag = "DownloadItemManager" private val scope = CoroutineScope(SupervisorJob() + Dispatchers.IO) - private val activeCalls = ConcurrentHashMap() + private val activeCalls = ConcurrentHashMap() private val safFolderLocks = ConcurrentHashMap() + private val scanLocks = ConcurrentHashMap() private val reservations = mutableMapOf() private val lastPersistTime = mutableMapOf() + private val finalizingItems = mutableSetOf() + private val refreshingServerIds = mutableSetOf() + private val apiHandler = ApiHandler(context) private var watcherRunning = false private val jacksonMapper = jacksonObjectMapper() @@ -54,12 +59,10 @@ class DownloadItemManager( } interface InternalProgressCallback { + fun onSizeResolved(totalBytes: Long) fun onProgress(totalBytesWritten: Long, progress: Long) fun onComplete(failed: Boolean) - } - - init { - IncompleteDownloadCleanup.cleanupExpired(context) + fun onAuthError() } @Synchronized @@ -73,26 +76,37 @@ class DownloadItemManager( fun restoreQueue() { if (downloadItemQueue.isNotEmpty()) return DeviceManager.dbManager.getDownloadItems().forEach { item -> + item.downloadItemParts.filter { it.moved }.forEach { part -> + if (!finalizedFileExists(part)) { + AbsLogger.error(tag, "Finalized file is missing; resetting ${part.filename}") + part.moved = false + part.completed = false + part.completedDestinationUri = null + part.downloadId = null + part.reusedExistingFile = false + } + } if (item.isDownloadFinished) { downloadItemQueue.add(item) checkDownloadItemFinished(item) return@forEach } + var resetFailed = false item.downloadItemParts.forEach { part -> if (part.moved) return@forEach - if (item.terminalFailureAt != null && part.failed) return@forEach - part.downloadId = null - part.isMoving = false - part.failed = false - part.completed = false - part.waitingForSpace = false - part.bytesDownloaded = File(part.destinationPath).takeIf(File::exists)?.length() ?: 0L + if (!resetPartForFreshDownload(part)) resetFailed = true + } + if (resetFailed) { + item.terminalFailureAt = item.terminalFailureAt ?: System.currentTimeMillis() + item.stagingCleanupAt = null + } + if (item.terminalFailureAt != null) { + item.downloadItemParts.filter { !it.moved }.forEach { it.failed = true } } downloadItemQueue.add(item) if (item.terminalFailureAt != null) IncompleteDownloadCleanup.schedule(context, item) clientEventEmitter.onDownloadItem(item) } - checkUpdateDownloadQueue() notifyQueueChanged() } @@ -100,39 +114,68 @@ class DownloadItemManager( fun addDownloadItem(downloadItem: DownloadItem) { val existingItem = downloadItemQueue.find { it.id == downloadItem.id } if (existingItem != null) { - if (existingItem.terminalFailureAt != null) { - retryDownloadItem(existingItem) - checkUpdateDownloadQueue() - notifyQueueChanged() - } return } persist(downloadItem, force = true) downloadItemQueue.add(downloadItem) clientEventEmitter.onDownloadItem(downloadItem) + notifyQueueChanged() + } + + @Synchronized + fun retryDownloadItem(downloadItemId: String): Boolean { + val item = downloadItemQueue.find { it.id == downloadItemId } ?: return false + if (item.downloadItemParts.any { it in currentDownloadItemParts }) return false + if (item.isDownloadFinished) return false + synchronized(IncompleteDownloadCleanup) { + var resetFailed = false + item.downloadItemParts.filter { !it.moved }.forEach { part -> + if (!resetPartForFreshDownload(part)) resetFailed = true + } + if (resetFailed) { + item.downloadItemParts.filter { !it.moved }.forEach { it.failed = true } + persist(item, force = true) + return false + } + item.terminalFailureAt = null + item.stagingCleanupAt = null + IncompleteDownloadCleanup.cancel(context, item.id) + persist(item, force = true) + } + clientEventEmitter.onDownloadItem(item) + notifyQueueChanged() + return true + } + + @Synchronized + fun resumeWork() { checkUpdateDownloadQueue() notifyQueueChanged() } - private fun retryDownloadItem(item: DownloadItem) { - item.terminalFailureAt = null - IncompleteDownloadCleanup.cancel(context, item.id) - item.downloadItemParts.filter { it.failed }.forEach { part -> - part.failed = false - part.completed = false - part.isMoving = false - part.downloadId = null - part.retryCount = 0 - } - persist(item, force = true) - } - @Synchronized fun cancelAll() { - activeCalls.values.forEach(Call::cancel) + activeCalls.values.forEach(InternalDownloadManager.DownloadHandle::cancel) activeCalls.clear() downloadItemQueue.forEach { item -> - item.downloadItemParts.forEach { part -> File(part.destinationPath).delete() } + item.downloadItemParts.forEach { part -> + File(part.destinationPath).delete() + if (part.moved && !part.reusedExistingFile && part.isInternalStorage) { + File(part.finalDestinationPath).delete() + } else if (part.moved && !part.reusedExistingFile) { + part.completedDestinationUri?.let { uri -> + try { + DocumentFile.fromSingleUri(context, Uri.parse(uri))?.delete() + } catch (e: Exception) { + AbsLogger.error( + tag, + "Could not delete cancelled SAF file ${part.filename}: ${e.message}" + ) + } + } + } + } + IncompleteDownloadCleanup.cancel(context, item.id) DeviceManager.dbManager.removeDownloadItem(item.id) } currentDownloadItemParts.clear() @@ -143,16 +186,34 @@ class DownloadItemManager( @Synchronized fun hasWork(): Boolean = - downloadItemQueue.any { item -> - item.downloadItemParts.any { part -> - (!part.completed && !part.failed) || part.isMoving - } - } + finalizingItems.isNotEmpty() || + downloadItemQueue.any { item -> + item.downloadItemParts.any { part -> + (!part.moved && !part.failed) || part.isMoving + } + } @Synchronized private fun checkUpdateDownloadQueue() { downloadItemQueue.toList().forEach { item -> - val slots = MAX_SIMULTANEOUS_DOWNLOADS - currentDownloadItemParts.size + var slots = MAX_SIMULTANEOUS_DOWNLOADS - currentDownloadItemParts.size + if (slots <= 0) return@forEach + item.downloadItemParts + .filter { part -> + part.completed && + !part.moved && + !part.failed && + !part.isMoving && + part !in currentDownloadItemParts && + File(part.destinationPath).exists() && + !hasActiveDestinationConflict(part) + } + .take(slots) + .forEach { part -> + currentDownloadItemParts.add(part) + part.downloadId = APP_MANAGED_DOWNLOAD_ID + } + slots = MAX_SIMULTANEOUS_DOWNLOADS - currentDownloadItemParts.size if (slots <= 0) return@forEach item.getNextDownloadItemParts(slots).forEach { part -> val existingFile = findSharedStorageFile(part) @@ -160,9 +221,17 @@ class DownloadItemManager( part.bytesDownloaded = existingFile.length() part.progress = 100L part.completedDestinationUri = existingFile.uri.toString() + part.reusedExistingFile = true File(part.destinationPath).delete() completePart(item, part) clientEventEmitter.onDownloadItemPartUpdate(part) + return@forEach + } + if (completeFromExistingInternalCover(item, part)) return@forEach + if (hasActiveDestinationConflict(part)) { + leaveQueued(item, part) + } else if (part.fileSize <= 0L && currentDownloadItemParts.any { it.fileSize <= 0L }) { + leaveQueued(item, part) } else if (tryReserve(part)) startDownload(item, part) else { part.waitingForSpace = true @@ -183,17 +252,33 @@ class DownloadItemManager( part.lastUpdateTime = System.currentTimeMillis() currentDownloadItemParts.add(part) persist(item, force = true) + AbsLogger.info(tag, "Starting download for ${part.filename}") val activeConfig = DeviceManager.serverConnectionConfig val token = if (activeConfig?.id == item.serverConnectionConfigId) activeConfig.token else DeviceManager.getServerConnectionConfig(item.serverConnectionConfigId)?.token ?: DeviceManager.token - activeCalls[part.id] = + val handle = InternalDownloadManager( stagingFile, part.fileSize, object : InternalProgressCallback { + override fun onSizeResolved(totalBytes: Long) { + synchronized(this@DownloadItemManager) { + if (part !in currentDownloadItemParts || totalBytes < 0L) return + if (part.fileSize == totalBytes) return + AbsLogger.info( + tag, + "Using server size $totalBytes instead of metadata size ${part.fileSize} for ${part.filename}" + ) + part.fileSize = totalBytes + part.lastUpdateTime = System.currentTimeMillis() + persist(item, force = true) + clientEventEmitter.onDownloadItemPartUpdate(part) + } + } + override fun onProgress(totalBytesWritten: Long, progress: Long) { synchronized(this@DownloadItemManager) { if (part !in currentDownloadItemParts) return @@ -214,10 +299,20 @@ class DownloadItemManager( persist(item, force = true) } } + + override fun onAuthError() { + synchronized(this@DownloadItemManager) { + if (part !in currentDownloadItemParts) return + handleAuthError(item, part) + } + } }, { hasAvailableSpace(part) } ) .download(serverUrl(item, part), token) + if (part in currentDownloadItemParts && !part.completed && !part.failed) { + activeCalls[part.id] = handle + } } @Synchronized @@ -253,7 +348,7 @@ class DownloadItemManager( if (!part.completed && !part.failed) { val lastUpdate = part.lastUpdateTime ?: return if (System.currentTimeMillis() - lastUpdate > STALL_TIMEOUT_MS) { - Log.w(tag, "Download stalled: ${part.filename}") + AbsLogger.error(tag, "Download stalled: ${part.filename}") activeCalls.remove(part.id)?.cancel() failOrRetry(item, part, "Download stalled") } @@ -272,14 +367,7 @@ class DownloadItemManager( part.retryCount += 1 reservations.remove(part.destinationPath) if (part.retryCount > MAX_RETRIES) { - Log.e(tag, "$reason after $MAX_RETRIES retries: ${part.filename}") - part.failed = true - part.completed = false - part.downloadId = null - item.terminalFailureAt = item.terminalFailureAt ?: System.currentTimeMillis() - persist(item, force = true) - IncompleteDownloadCleanup.schedule(context, item) - notifyQueueChanged() + markTerminalFailure(item, part, "$reason after $MAX_RETRIES retries") return } part.failed = false @@ -287,6 +375,94 @@ class DownloadItemManager( part.downloadId = null part.isMoving = false persist(item, force = true) + clientEventEmitter.onDownloadItemPartUpdate(part) + } + + /** A 401 refreshes the token for this queued item's server without consuming transfer retries. */ + @Synchronized + private fun handleAuthError(item: DownloadItem, part: DownloadItemPart) { + removeActivePart(part) + reservations.remove(part.destinationPath) + part.downloadId = null + part.isMoving = false + part.failed = false + part.completed = false + part.authRetryCount += 1 + part.lastUpdateTime = System.currentTimeMillis() + if (part.authRetryCount > MAX_AUTH_RETRIES) { + markTerminalFailure(item, part, "Unauthorized after $MAX_AUTH_RETRIES token refresh attempts") + return + } + + AbsLogger.info( + tag, + "Refreshing token after 401 for ${part.filename} (attempt ${part.authRetryCount})" + ) + persist(item, force = true) + clientEventEmitter.onDownloadItemPartUpdate(part) + refreshTokenThenResume(item.serverConnectionConfigId) + } + + private fun refreshTokenThenResume(serverConnectionConfigId: String) { + if (!refreshingServerIds.add(serverConnectionConfigId)) return + apiHandler.refreshAuthTokens(serverConnectionConfigId) { result -> + synchronized(this@DownloadItemManager) { + refreshingServerIds.remove(serverConnectionConfigId) + when (result) { + is ApiHandler.RefreshResult.Success -> { + AbsLogger.info( + tag, + "Token refresh succeeded; resuming downloads for $serverConnectionConfigId" + ) + checkUpdateDownloadQueue() + } + ApiHandler.RefreshResult.Rejected -> failParkedAuthParts(serverConnectionConfigId) + // Parked parts are still queued, so MAX_AUTH_RETRIES bounds the reattempts. + ApiHandler.RefreshResult.Transient -> { + AbsLogger.info( + tag, + "Token refresh could not be completed; retrying downloads for $serverConnectionConfigId" + ) + checkUpdateDownloadQueue() + } + } + } + } + } + + @Synchronized + private fun failParkedAuthParts(serverConnectionConfigId: String) { + downloadItemQueue.toList().forEach { item -> + if (item.serverConnectionConfigId != serverConnectionConfigId) return@forEach + item.downloadItemParts + .filter { + it.authRetryCount > 0 && + !it.completed && + !it.failed && + it.downloadId == null && + it !in currentDownloadItemParts + } + .forEach { part -> + markTerminalFailure(item, part, "Unable to refresh download authorization") + } + } + } + + @Synchronized + private fun markTerminalFailure(item: DownloadItem, part: DownloadItemPart, reason: String) { + AbsLogger.error(tag, "$reason: ${part.filename}") + removeActivePart(part) + reservations.remove(part.destinationPath) + part.failed = true + part.completed = false + part.downloadId = null + part.isMoving = false + item.terminalFailureAt = item.terminalFailureAt ?: System.currentTimeMillis() + item.stagingCleanupAt = null + persist(item, force = true) + IncompleteDownloadCleanup.schedule(context, item) + clientEventEmitter.onDownloadItemPartUpdate(part) + notifyQueueChanged() } private fun finalizeInternalFile(item: DownloadItem, part: DownloadItemPart) { @@ -305,6 +481,7 @@ class DownloadItemManager( throw IllegalStateException("Could not finalize internal staging file") } backup.delete() + AbsLogger.info(tag, "Move completed for ${part.filename} to ${finalFile.absolutePath}") completePart(item, part) } catch (e: Exception) { part.isMoving = false @@ -341,18 +518,19 @@ class DownloadItemManager( } if (temporary.length() != staging.length()) throw IllegalStateException("SAF copy size mismatch") - val existing = folder.findFile(part.filename) + val existing = findDocumentByFilename(folder, part) if (existing != null && !existing.delete()) throw IllegalStateException("Could not replace existing file") if (!temporary.renameTo(part.filename)) throw IllegalStateException("Could not finalize SAF temporary file") val destination = - folder.findFile(part.filename) + findDocumentByFilename(folder, part) ?: throw IllegalStateException("Could not reopen finalized SAF file") if (destination.length() != staging.length()) throw IllegalStateException("SAF final size mismatch") - if (!staging.delete()) Log.w(tag, "Could not remove staging file ${staging.name}") + if (!staging.delete()) AbsLogger.error(tag, "Could not remove staging file ${staging.name}") part.completedDestinationUri = destination.uri.toString() + AbsLogger.info(tag, "Move completed for ${part.filename} to ${destination.uri}") completePart(item, part) } catch (e: Exception) { failFinalization(item, part, "SAF copy failed: ${e.message}") @@ -362,7 +540,7 @@ class DownloadItemManager( @Synchronized private fun failFinalization(item: DownloadItem, part: DownloadItemPart, message: String) { - Log.e(tag, message) + AbsLogger.error(tag, message) part.isMoving = false part.failed = true failOrRetry(item, part, message) @@ -380,25 +558,39 @@ class DownloadItemManager( checkDownloadItemFinished(item) } + @Synchronized private fun checkDownloadItemFinished(item: DownloadItem) { - if (!item.isDownloadFinished) return + if (!item.isDownloadFinished || !finalizingItems.add(item.id)) return + IncompleteDownloadCleanup.cancel(context, item.id) scope.launch { - folderScanner.scanDownloadItem(item) { scanResult -> - val event = - JSObject().apply { - put("libraryItemId", item.id) - put("localFolderId", item.localFolder.id) - scanResult?.localLibraryItem?.let { - put("localLibraryItem", JSObject(jacksonMapper.writeValueAsString(it))) - } - scanResult?.localMediaProgress?.let { - put("localMediaProgress", JSObject(jacksonMapper.writeValueAsString(it))) - } - } - clientEventEmitter.onDownloadItemComplete(event) + try { + val scanLock = scanLocks.computeIfAbsent(scanDestinationKey(item)) { Any() } + synchronized(scanLock) { + folderScanner.scanDownloadItem(item) { scanResult -> + val event = + JSObject().apply { + put("libraryItemId", item.id) + put("localFolderId", item.localFolder.id) + scanResult?.localLibraryItem?.let { + put("localLibraryItem", JSObject(jacksonMapper.writeValueAsString(it))) + } + scanResult?.localMediaProgress?.let { + put("localMediaProgress", JSObject(jacksonMapper.writeValueAsString(it))) + } + } + clientEventEmitter.onDownloadItemComplete(event) + synchronized(this@DownloadItemManager) { + downloadItemQueue.remove(item) + DeviceManager.dbManager.removeDownloadItem(item.id) + } + } + } + } catch (e: Exception) { + // The files are already in place, so leave the item queued for restoreQueue to rescan. + AbsLogger.error(tag, "Could not finalize download item ${item.id}: ${e.message}") + } finally { synchronized(this@DownloadItemManager) { - downloadItemQueue.remove(item) - DeviceManager.dbManager.removeDownloadItem(item.id) + finalizingItems.remove(item.id) notifyQueueChanged() } } @@ -406,7 +598,6 @@ class DownloadItemManager( } private fun tryReserve(part: DownloadItemPart): Boolean { - if (part.fileSize <= 0L && currentDownloadItemParts.any { it.fileSize <= 0L }) return false val staging = File(part.destinationPath) staging.parentFile?.mkdirs() val expectedSize = if (part.fileSize > 0L) part.fileSize else UNKNOWN_PART_RESERVATION_BYTES @@ -457,7 +648,7 @@ class DownloadItemManager( } fun destroy() { - activeCalls.values.forEach(Call::cancel) + activeCalls.values.forEach(InternalDownloadManager.DownloadHandle::cancel) activeCalls.clear() scope.cancel() } @@ -479,13 +670,103 @@ class DownloadItemManager( if (segment == "." || segment == "..") return null folder = folder.findFile(segment) ?: return null } - val file = folder.findFile(part.filename) ?: return null + val file = findDocumentByFilename(folder, part) ?: return null if (!file.isFile) return null if (part.fileSize > 0L && file.length() != part.fileSize) return null if (part.fileSize <= 0L && file.length() <= 0L) return null return file } + private fun completeFromExistingInternalCover( + item: DownloadItem, + part: DownloadItemPart + ): Boolean { + if (!part.isInternalStorage || !part.serverPath.endsWith("/cover")) return false + val file = File(part.finalDestinationPath) + if (!file.isFile || file.length() <= 0L) return false + if (part.fileSize > 0L && file.length() != part.fileSize) return false + part.bytesDownloaded = file.length() + part.progress = 100L + part.reusedExistingFile = true + AbsLogger.info(tag, "Reusing existing cover ${part.filename}") + File(part.destinationPath).delete() + completePart(item, part) + clientEventEmitter.onDownloadItemPartUpdate(part) + return true + } + + private fun hasActiveDestinationConflict(part: DownloadItemPart): Boolean = + currentDownloadItemParts.any { activePart -> + activePart !== part && + activePart.localFolderId == part.localFolderId && + activePart.finalDestinationPath == part.finalDestinationPath + } + + private fun leaveQueued(item: DownloadItem, part: DownloadItemPart) { + if (!part.waitingForSpace) return + part.waitingForSpace = false + part.downloadId = null + persist(item) + clientEventEmitter.onDownloadItemPartUpdate(part) + } + + private fun scanDestinationKey(item: DownloadItem): String = + "${item.localFolder.id}:${item.itemFolderPath}" + + private fun finalizedFileExists(part: DownloadItemPart): Boolean { + if (part.isInternalStorage) { + val file = File(part.finalDestinationPath) + return file.isFile && + if (part.fileSize > 0L) file.length() == part.fileSize else file.length() > 0L + } + part.completedDestinationUri?.let { uri -> + try { + val file = DocumentFile.fromSingleUri(context, Uri.parse(uri)) + if (file?.isFile == true && (part.fileSize <= 0L || file.length() == part.fileSize)) + return true + } catch (e: Exception) { + AbsLogger.error(tag, "Could not validate SAF file ${part.filename}: ${e.message}") + } + } + return findSharedStorageFile(part) != null + } + + /** Resets an unmoved part when recovery crosses a service-session boundary. */ + private fun resetPartForFreshDownload(part: DownloadItemPart): Boolean { + val stagingFile = File(part.destinationPath) + if (stagingFile.exists() && !stagingFile.delete()) { + AbsLogger.error(tag, "Could not delete staging file ${part.filename}") + part.failed = true + return false + } + part.completed = false + part.bytesDownloaded = 0L + part.progress = 0L + part.failed = false + part.isMoving = false + part.downloadId = null + part.retryCount = 0 + part.authRetryCount = 0 + part.waitingForSpace = false + part.reusedExistingFile = false + return true + } + + private fun findDocumentByFilename(folder: DocumentFile, part: DownloadItemPart): DocumentFile? { + folder.findFile(part.filename)?.let { + return it + } + val expectedBaseName = part.filename.substringBeforeLast('.') + return folder.listFiles().firstOrNull { document -> + document.name == part.filename || + document.fullName == part.filename || + (part.audioTrack != null && + document.isFile && + ((document.name ?: "").substringBeforeLast('.') == expectedBaseName || + document.fullName.substringBeforeLast('.') == expectedBaseName)) + } + } + private fun mimeTypeFor(part: DownloadItemPart): String = part.audioTrack?.mimeType ?: when (part.ebookFile?.ebookFormat?.lowercase()) { @@ -505,6 +786,7 @@ class DownloadItemManager( const val WATCH_INTERVAL_MS = 1_000L const val STALL_TIMEOUT_MS = 60_000L const val MAX_RETRIES = 5 + const val MAX_AUTH_RETRIES = 2 const val PERSIST_INTERVAL_MS = 2_000L const val MIN_FREE_SPACE_BYTES = 100L * 1024L * 1024L const val UNKNOWN_PART_RESERVATION_BYTES = 100L * 1024L * 1024L diff --git a/android/app/src/main/java/com/audiobookshelf/app/managers/IncompleteDownloadCleanup.kt b/android/app/src/main/java/com/audiobookshelf/app/managers/IncompleteDownloadCleanup.kt index 4fd89085..fdb90a4f 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/managers/IncompleteDownloadCleanup.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/managers/IncompleteDownloadCleanup.kt @@ -1,9 +1,6 @@ package com.audiobookshelf.app.managers import android.content.Context -import android.net.Uri -import android.util.Log -import androidx.documentfile.provider.DocumentFile import androidx.work.ExistingWorkPolicy import androidx.work.OneTimeWorkRequestBuilder import androidx.work.WorkManager @@ -11,10 +8,11 @@ import androidx.work.Worker import androidx.work.WorkerParameters import com.audiobookshelf.app.device.DeviceManager import com.audiobookshelf.app.models.DownloadItem +import com.audiobookshelf.app.plugins.AbsLogger import java.io.File import java.util.concurrent.TimeUnit -/** Removes terminally failed downloads after their retention window elapses. */ +/** Removes only staging data for terminally failed downloads after their retention window. */ object IncompleteDownloadCleanup { private const val tag = "IncompleteDownloadCleanup" private const val RETENTION_MS = 24L * 60L * 60L * 1000L @@ -22,6 +20,7 @@ object IncompleteDownloadCleanup { fun schedule(context: Context, item: DownloadItem) { val failedAt = item.terminalFailureAt ?: return + if (item.stagingCleanupAt != null) return val delay = (failedAt + RETENTION_MS - System.currentTimeMillis()).coerceAtLeast(0L) val request = OneTimeWorkRequestBuilder() .setInitialDelay(delay, TimeUnit.MILLISECONDS) @@ -34,7 +33,8 @@ object IncompleteDownloadCleanup { WorkManager.getInstance(context).cancelUniqueWork(WORK_PREFIX + itemId) } - /** Removes failures retained longer than 24 hours when scheduled work did not run. */ + /** Cleans staging data retained longer than 24 hours when scheduled work did not run. */ + @Synchronized fun cleanupExpired(context: Context) { val now = System.currentTimeMillis() DeviceManager.dbManager.getDownloadItems() @@ -46,6 +46,7 @@ object IncompleteDownloadCleanup { private fun isEligible(item: DownloadItem, now: Long): Boolean { val failedAt = item.terminalFailureAt ?: return false + if (item.stagingCleanupAt != null) return false if (now - failedAt < RETENTION_MS) return false return item.downloadItemParts.all { part -> part.moved || (part.failed && !part.isMoving) @@ -55,21 +56,15 @@ object IncompleteDownloadCleanup { private fun deleteItem(context: Context, item: DownloadItem) { item.downloadItemParts.forEach { part -> deleteAppOwnedFile(context, File(part.destinationPath)) - if (part.isInternalStorage && part.moved) { - deleteAppOwnedFile(context, File(part.finalDestinationPath)) - } else if (!part.isInternalStorage && part.moved) { - part.completedDestinationUri?.let { uriString -> - try { - DocumentFile.fromSingleUri(context, Uri.parse(uriString))?.delete() - } catch (e: Exception) { - Log.w(tag, "Could not delete expired SAF document for ${part.filename}", e) - } - } + if (!part.moved) { + part.bytesDownloaded = 0L + part.completed = false } } - DeviceManager.dbManager.removeDownloadItem(item.id) + item.stagingCleanupAt = System.currentTimeMillis() + DeviceManager.dbManager.saveDownloadItem(item) cancel(context, item.id) - Log.i(tag, "Deleted terminally failed download item ${item.id}") + AbsLogger.info(tag, "Deleted staging files for terminally failed download item ${item.id}") } private fun deleteAppOwnedFile(context: Context, file: File) { @@ -77,10 +72,10 @@ object IncompleteDownloadCleanup { val internal = context.filesDir.absolutePath val external = context.getExternalFilesDir(null)?.absolutePath if (path.startsWith(internal) || (external != null && path.startsWith(external))) { - if (file.exists() && !file.delete()) Log.w(tag, "Could not delete expired staging file $path") + if (file.exists() && !file.delete()) AbsLogger.error(tag, "Could not delete expired staging file $path") file.parentFile?.takeIf { it.isDirectory && it.list()?.isEmpty() == true }?.delete() } else { - Log.w(tag, "Refusing to delete non-app-owned path $path") + AbsLogger.error(tag, "Refusing to delete non-app-owned path $path") } } } diff --git a/android/app/src/main/java/com/audiobookshelf/app/managers/InternalDownloadManager.kt b/android/app/src/main/java/com/audiobookshelf/app/managers/InternalDownloadManager.kt index 59dc6026..f9a2217c 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/managers/InternalDownloadManager.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/managers/InternalDownloadManager.kt @@ -1,9 +1,11 @@ package com.audiobookshelf.app.managers -import android.util.Log +import com.audiobookshelf.app.plugins.AbsLogger import java.io.File import java.io.FileOutputStream import java.io.IOException +import java.util.concurrent.atomic.AtomicBoolean +import java.util.concurrent.atomic.AtomicReference import java.util.concurrent.TimeUnit import okhttp3.Call import okhttp3.Callback @@ -19,16 +21,49 @@ class InternalDownloadManager( private val hasAvailableSpace: () -> Boolean ) { private val tag = "InternalDownloadManager" + + interface DownloadHandle { + fun cancel() + } + + private class ActiveDownloadHandle : DownloadHandle { + private val cancelled = AtomicBoolean(false) + private val activeCall = AtomicReference() + + fun setCall(call: Call) { + activeCall.set(call) + if (cancelled.get()) call.cancel() + } + + override fun cancel() { + cancelled.set(true) + activeCall.get()?.cancel() + } + } /** * Starts or resumes a download. * * @param url download URL * @param token access token sent in the Authorization header - * @return active call, used to cancel a stalled transfer + * @return logical handle used to cancel the active request, including a restarted request */ - fun download(url: String, token: String): Call { + fun download(url: String, token: String): DownloadHandle { destinationFile.parentFile?.mkdirs() - val existingBytes = destinationFile.takeIf { it.exists() }?.length() ?: 0L + val handle = ActiveDownloadHandle() + startRequest(url, token, handle, allowRestart = true) + return handle + } + + private fun startRequest( + url: String, + token: String, + handle: ActiveDownloadHandle, + allowRestart: Boolean + ) { + var existingBytes = destinationFile.takeIf { it.exists() }?.length() ?: 0L + AbsLogger.info( + tag, + "Starting ${if (existingBytes > 0L) "resumed" else "new"} download for ${destinationFile.name} at byte $existingBytes") val request = Request.Builder() .url(url) @@ -37,20 +72,39 @@ class InternalDownloadManager( .apply { if (existingBytes > 0L) header("Range", "bytes=$existingBytes-") } .build() val call = client.newCall(request) + handle.setCall(call) call.enqueue( object : Callback { override fun onFailure(call: Call, e: IOException) { - Log.e(tag, "Download URL failed", e) + AbsLogger.error(tag, "Download request failed for ${destinationFile.name}: ${e.message}") progressCallback.onComplete(true) } override fun onResponse(call: Call, response: Response) { response.use { try { - if (response.code == 416 && expectedSize > 0L && existingBytes == expectedSize - ) { - progressCallback.onProgress(existingBytes, 100L) - progressCallback.onComplete(false) + if (response.code == 401) { + AbsLogger.error(tag, "Download unauthorized (401) for ${destinationFile.name}") + progressCallback.onAuthError() + return + } + if (response.code == 416) { + val serverSize = + response.header("Content-Range") + ?.removePrefix("bytes */") + ?.toLongOrNull() + if (serverSize != null) progressCallback.onSizeResolved(serverSize) + if (serverSize != null && existingBytes == serverSize) { + progressCallback.onProgress(existingBytes, 100L) + AbsLogger.info(tag, "Download completed for ${destinationFile.name} ($existingBytes bytes)") + progressCallback.onComplete(false) + } else if (allowRestart && destinationFile.delete()) { + AbsLogger.info(tag, "Restarting stale range from byte zero for ${destinationFile.name}") + startRequest(url, token, handle, allowRestart = false) + } else { + AbsLogger.error(tag, "Could not recover invalid range for ${destinationFile.name} at byte $existingBytes") + progressCallback.onComplete(true) + } return } val append = @@ -58,24 +112,27 @@ class InternalDownloadManager( response.code == 206 && hasExpectedRange(response, existingBytes) if (existingBytes > 0L && !append && response.code != 200) { - Log.e( + AbsLogger.error( tag, - "Invalid resume response ${response.code} for offset $existingBytes" + "Invalid resume response ${response.code} for ${destinationFile.name} at byte $existingBytes" ) progressCallback.onComplete(true) return } if (!response.isSuccessful || response.body == null) { - Log.e(tag, "Download HTTP failure ${response.code}") + AbsLogger.error(tag, "Download HTTP failure ${response.code} for ${destinationFile.name}") progressCallback.onComplete(true) return } val startingBytes = if (append) existingBytes else 0L val responseLength = response.body!!.contentLength() + val serverSize = + if (append) contentRangeTotal(response) + else responseLength.takeIf { it >= 0L } + if (serverSize != null) progressCallback.onSizeResolved(serverSize) val totalLength = - if (expectedSize > 0L) expectedSize - else if (responseLength >= 0L) startingBytes + responseLength else 0L + serverSize ?: if (expectedSize > 0L) expectedSize else 0L FileOutputStream(destinationFile, append).use { output -> response.body!!.byteStream().use { input -> @@ -95,24 +152,28 @@ class InternalDownloadManager( } } - if (expectedSize > 0L && destinationFile.length() != expectedSize) { - Log.e( + val downloadedSize = destinationFile.length() + if (serverSize != null && downloadedSize != serverSize) { + AbsLogger.error( tag, - "Downloaded size ${destinationFile.length()} did not match $expectedSize" + "Downloaded size for ${destinationFile.name} was $downloadedSize, expected server size $serverSize" ) progressCallback.onComplete(true) } else { + AbsLogger.info( + tag, + "Download completed for ${destinationFile.name} ($downloadedSize bytes)" + ) progressCallback.onComplete(false) } } catch (e: IOException) { - Log.e(tag, "Could not write staging file", e) + AbsLogger.error(tag, "Could not write staging file ${destinationFile.name}: ${e.message}") progressCallback.onComplete(true) } } } } ) - return call } private fun hasExpectedRange(response: Response, offset: Long): Boolean { @@ -122,9 +183,16 @@ class InternalDownloadManager( match.groupValues[2].toLongOrNull()?.let { it >= offset } == true } + private fun contentRangeTotal(response: Response): Long? = + CONTENT_RANGE.matchEntire(response.header("Content-Range") ?: "") + ?.groupValues + ?.get(3) + ?.takeUnless { it == "*" } + ?.toLongOrNull() + private companion object { const val CHUNK_SIZE = 512 * 1024 // 512 KB - val CONTENT_RANGE = Regex("bytes (\\d+)-(\\d+)/(?:\\d+|\\*)") + val CONTENT_RANGE = Regex("bytes (\\d+)-(\\d+)/(\\d+|\\*)") val client = OkHttpClient.Builder() .connectTimeout(30, TimeUnit.SECONDS) diff --git a/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItem.kt b/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItem.kt index af1657b7..cfab08d1 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItem.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItem.kt @@ -20,7 +20,8 @@ data class DownloadItem( val itemSubfolder: String, val media: MediaType, val downloadItemParts: MutableList, - @JsonIgnore var terminalFailureAt: Long? = null + @JsonIgnore var terminalFailureAt: Long? = null, + @JsonIgnore var stagingCleanupAt: Long? = null ) { @get:JsonIgnore val isInternalStorage @@ -28,7 +29,9 @@ data class DownloadItem( @get:JsonIgnore val isDownloadFinished - get() = !downloadItemParts.any { !it.completed || it.isMoving || it.failed } + get() = downloadItemParts.isNotEmpty() && downloadItemParts.all { + it.completed && it.moved && !it.isMoving && !it.failed + } @JsonIgnore fun getNextDownloadItemParts(limit: Int): MutableList { diff --git a/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItemPart.kt b/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItemPart.kt index 7dadbca8..a1e60f74 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItemPart.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/models/DownloadItemPart.kt @@ -14,7 +14,7 @@ data class DownloadItemPart( val id: String, val downloadItemId: String, val filename: String, - val fileSize: Long, + var fileSize: Long, @JsonIgnore val destinationPath: String, val finalDestinationPath:String, val serverPath: String, @@ -38,7 +38,9 @@ data class DownloadItemPart( var progress: Long, var bytesDownloaded: Long, @JsonIgnore var retryCount: Int = 0, - @JsonIgnore var waitingForSpace: Boolean = false + @JsonIgnore var authRetryCount: Int = 0, + @JsonIgnore var waitingForSpace: Boolean = false, + @JsonIgnore var reusedExistingFile: Boolean = false ) { companion object { fun make(downloadItemId:String, filename:String, fileSize: Long, destinationFile: File, finalDestinationFile: File, subfolder:String, serverPath:String, localFolder: LocalFolder, ebookFile: EBookFile?, audioTrack: AudioTrack?, episode: PodcastEpisode?) :DownloadItemPart { @@ -74,7 +76,8 @@ data class DownloadItemPart( downloadId = null, lastUpdateTime = null, progress = 0, - bytesDownloaded = 0 + bytesDownloaded = 0, + reusedExistingFile = false ) } } diff --git a/android/app/src/main/java/com/audiobookshelf/app/plugins/AbsDownloader.kt b/android/app/src/main/java/com/audiobookshelf/app/plugins/AbsDownloader.kt index d9dde269..cd678a18 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/plugins/AbsDownloader.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/plugins/AbsDownloader.kt @@ -1,7 +1,6 @@ package com.audiobookshelf.app.plugins import android.os.Environment -import android.util.Log import com.audiobookshelf.app.MainActivity import com.audiobookshelf.app.data.* import com.audiobookshelf.app.device.DeviceManager @@ -84,57 +83,60 @@ class AbsDownloader : Plugin() { var episodeId = call.data.getString("episodeId").toString() if (episodeId == "null") episodeId = "" var localFolderId = call.data.getString("localFolderId", "").toString() - Log.d(tag, "Download library item $libraryItemId to folder $localFolderId / episode: $episodeId") + AbsLogger.info(tag, "Requested download for item $libraryItemId${if (episodeId.isEmpty()) "" else " / episode $episodeId"}") val downloadId = if (episodeId.isEmpty()) libraryItemId else "$libraryItemId-$episodeId" - if (downloadItemManager.downloadItemQueue.find { it.id == downloadId } != null) { - Log.d(tag, "Download already started for this media entity $downloadId") - return call.resolve(JSObject("{\"error\":\"Download already started for this media entity\"}")) - } - - apiHandler.getLibraryItemWithProgress(libraryItemId, episodeId) { libraryItem -> - if (libraryItem == null) { - call.resolve(JSObject("{\"error\":\"Server request failed\"}")) - } else { - Log.d(tag, "Got library item from server ${libraryItem.id}") - - if (localFolderId == "") { - localFolderId = "internal-${libraryItem.mediaType}" + DownloadServiceHost.retryExisting(mainActivity, downloadId) { result -> + when (result) { + DownloadServiceHost.ExistingDownloadResult.RETRIED -> call.resolve() + DownloadServiceHost.ExistingDownloadResult.ACTIVE -> { + AbsLogger.info(tag, "Download already active for $downloadId") + call.resolve(JSObject("{\"error\":\"Download already started for this media entity\"}")) } - var localFolder = DeviceManager.dbManager.getLocalFolder(localFolderId) - - if (localFolder == null && localFolderId.startsWith("internal-")) { - Log.d(tag, "Creating new App Storage internal LocalFolder $localFolderId") - localFolder = LocalFolder(localFolderId, "Internal App Storage", "", "", "", "internal", libraryItem.mediaType) - DeviceManager.dbManager.saveLocalFolder(localFolder) - } - - if (localFolder != null) { - if (episodeId.isNotEmpty() && libraryItem.mediaType != "podcast") { - Log.e(tag, "Library item is not a podcast but episode was requested") - call.resolve(JSObject("{\"error\":\"Invalid library item not a podcast\"}")) - } else if (episodeId.isNotEmpty()) { - val podcast = libraryItem.media as Podcast - val episode = podcast.episodes?.find { podcastEpisode -> - podcastEpisode.id == episodeId - } - if (episode == null) { - call.resolve(JSObject("{\"error\":\"Invalid podcast episode not found\"}")) + DownloadServiceHost.ExistingDownloadResult.SERVICE_START_FAILED -> + call.resolve(JSObject("{\"error\":\"Unable to start the Android download service\"}")) + DownloadServiceHost.ExistingDownloadResult.NOT_FOUND -> { + apiHandler.getLibraryItemWithProgress(libraryItemId, episodeId) { libraryItem -> + if (libraryItem == null) { + call.resolve(JSObject("{\"error\":\"Server request failed\"}")) } else { - startLibraryItemDownload(libraryItem, localFolder, episode) - call.resolve() + AbsLogger.info(tag, "Preparing download for ${libraryItem.id}") + + if (localFolderId == "") localFolderId = "internal-${libraryItem.mediaType}" + var localFolder = DeviceManager.dbManager.getLocalFolder(localFolderId) + if (localFolder == null && localFolderId.startsWith("internal-")) { + AbsLogger.info(tag, "Creating internal download folder $localFolderId") + localFolder = LocalFolder(localFolderId, "Internal App Storage", "", "", "", "internal", libraryItem.mediaType) + DeviceManager.dbManager.saveLocalFolder(localFolder) + } + + if (localFolder == null) { + call.resolve(JSObject("{\"error\":\"Local Folder Not Found\"}")) + } else if (episodeId.isNotEmpty() && libraryItem.mediaType != "podcast") { + call.resolve(JSObject("{\"error\":\"Invalid library item not a podcast\"}")) + } else if (episodeId.isNotEmpty()) { + val podcast = libraryItem.media as Podcast + val episode = podcast.episodes?.find { it.id == episodeId } + if (episode == null) { + call.resolve(JSObject("{\"error\":\"Invalid podcast episode not found\"}")) + } else { + startLibraryItemDownload(libraryItem, localFolder, episode) { error -> resolveDownloadCall(call, error) } + } + } else { + startLibraryItemDownload(libraryItem, localFolder, null) { error -> resolveDownloadCall(call, error) } + } } - } else { - startLibraryItemDownload(libraryItem, localFolder, null) - call.resolve() } - } else { - call.resolve(JSObject("{\"error\":\"Local Folder Not Found\"}")) } } } } + private fun resolveDownloadCall(call: PluginCall, error: String?) { + if (error == null) call.resolve() + else call.resolve(JSObject().put("error", error)) + } + // Item filenames could be the same if they are in sub-folders, this will make them unique private fun getFilenameFromRelPath(relPath: String): String { var cleanedRelPath = relPath.replace("\\", "_").replace("/", "_") @@ -155,7 +157,12 @@ class AbsDownloader : Plugin() { return newTitle } - private fun startLibraryItemDownload(libraryItem: LibraryItem, localFolder: LocalFolder, episode:PodcastEpisode?) { + private fun startLibraryItemDownload( + libraryItem: LibraryItem, + localFolder: LocalFolder, + episode: PodcastEpisode?, + callback: (String?) -> Unit + ) { val isInternal = localFolder.id.startsWith("internal-") val finalInternalFolderPath = "${mainActivity.filesDir}/downloads/${libraryItem.id}" @@ -166,14 +173,13 @@ class AbsDownloader : Plugin() { "${mainActivity.getExternalFilesDir(Environment.DIRECTORY_DOWNLOADS) ?: mainActivity.filesDir}/download-staging/${libraryItem.id}" } - Log.d(tag, "downloadCacheDirectory=$tempFolderPath") if (libraryItem.mediaType == "book") { val bookTitle = cleanStringForFileSystem(libraryItem.media.metadata.title) val bookAuthor = cleanStringForFileSystem(libraryItem.media.metadata.getAuthorDisplayName()) val tracks = libraryItem.media.getAudioTracks() - Log.d(tag, "Starting library item download with ${tracks.size} tracks") + AbsLogger.info(tag, "Queueing library item download with ${tracks.size} files") val itemSubfolder = "$bookAuthor/$bookTitle" val itemFolderPath = if (isInternal) finalInternalFolderPath else "${localFolder.absolutePath}/$itemSubfolder" val downloadItem = DownloadItem(libraryItem.id, libraryItem.id, null, libraryItem.userMediaProgress,DeviceManager.serverConnectionConfig?.id ?: "", DeviceManager.serverAddress, DeviceManager.serverUserId, libraryItem.mediaType, itemFolderPath, localFolder, bookTitle, itemSubfolder, libraryItem.media, mutableListOf()) @@ -200,7 +206,6 @@ class AbsDownloader : Plugin() { val serverPath = "/api/items/${libraryItem.id}/file/${audioFileIno}/download" val destinationFilename = getFilenameFromRelPath(audioTrack.relPath) - Log.d(tag, "Audio File Server Path $serverPath | AF RelPath ${audioTrack.relPath} | LocalFolder Path ${localFolder.absolutePath} | DestName $destinationFilename") val finalDestinationFile = File("$itemFolderPath/$destinationFilename") val destinationFile = File("$tempFolderPath/$destinationFilename.part") @@ -224,8 +229,8 @@ class AbsDownloader : Plugin() { downloadItem.downloadItemParts.add(downloadItemPart) } - DownloadServiceHost.enqueue(mainActivity, downloadItem) - } + DownloadServiceHost.enqueue(mainActivity, downloadItem, callback) + } else callback("No downloadable files found") } else { // Podcast episode download val podcastTitle = cleanStringForFileSystem(libraryItem.media.metadata.title) @@ -234,14 +239,13 @@ class AbsDownloader : Plugin() { val audioFileIno = episode?.audioFile?.ino val fileSize = audioTrack?.metadata?.size ?: 0 - Log.d(tag, "Starting podcast episode download") + AbsLogger.info(tag, "Queueing podcast episode download") val itemFolderPath = if (isInternal) finalInternalFolderPath else "${localFolder.absolutePath}/$podcastTitle" val downloadItemId = "${libraryItem.id}-${episode?.id}" val downloadItem = DownloadItem(downloadItemId, libraryItem.id, episode?.id, libraryItem.userMediaProgress, DeviceManager.serverConnectionConfig?.id ?: "", DeviceManager.serverAddress, DeviceManager.serverUserId, libraryItem.mediaType, itemFolderPath, localFolder, podcastTitle, podcastTitle, libraryItem.media, mutableListOf()) var serverPath = "/api/items/${libraryItem.id}/file/${audioFileIno}/download" var destinationFilename = getFilenameFromRelPath(audioTrack?.relPath ?: "") - Log.d(tag, "Audio File Server Path $serverPath | AF RelPath ${audioTrack?.relPath} | LocalFolder Path ${localFolder.absolutePath} | DestName $destinationFilename") var destinationFile = File("$tempFolderPath/$destinationFilename.part") var finalDestinationFile = File("$itemFolderPath/$destinationFilename") @@ -262,7 +266,7 @@ class AbsDownloader : Plugin() { downloadItem.downloadItemParts.add(downloadItemPart) } - DownloadServiceHost.enqueue(mainActivity, downloadItem) + DownloadServiceHost.enqueue(mainActivity, downloadItem, callback) } } } diff --git a/android/app/src/main/java/com/audiobookshelf/app/server/ApiHandler.kt b/android/app/src/main/java/com/audiobookshelf/app/server/ApiHandler.kt index 9e123d8f..2ad61a73 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/server/ApiHandler.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/server/ApiHandler.kt @@ -167,105 +167,116 @@ class ApiHandler(var ctx:Context) { * 2. Make a request to /auth/refresh endpoint with the refresh token * 3. Update the stored tokens with the new access token * 4. Retry the original request with the new access token - * 5. If refresh fails, handle logout + * 5. If refresh fails, fail the request ([refreshAuthTokens] owns clearing the session) * * @param originalRequest The original request that failed with 401 * @param httpClient The HTTP client to use for the request * @param callback The callback to return the response */ private fun handleTokenRefresh(originalRequest: Request, httpClient: OkHttpClient?, callback: (JSObject) -> Unit) { - try { - AbsLogger.info(tag, "handleTokenRefresh: Attempting to refresh auth tokens for server ${DeviceManager.serverConnectionConfigString}") + val serverConnectionConfigId = DeviceManager.serverConnectionConfigId + refreshAuthTokens(serverConnectionConfigId, httpClient) { result -> + if (result is RefreshResult.Success) { + retryOriginalRequest(originalRequest, result.accessToken, httpClient, callback) + } else { + callback(JSObject().put("error", "Authentication failed - login again")) + } + } + } - // Get current server connection config ID - val serverConnectionConfigId = DeviceManager.serverConnectionConfigId - if (serverConnectionConfigId.isEmpty()) { - AbsLogger.error(tag, "handleTokenRefresh: Unable to refresh auth tokens. No server connection config ID") - val errorObj = JSObject() - errorObj.put("error", "No server connection available") - callback(errorObj) - return + sealed interface RefreshResult { + data class Success(val accessToken: String) : RefreshResult + + /** The server rejected the refresh token, so the session has already been cleared. */ + data object Rejected : RefreshResult + + /** The refresh could not be completed. Credentials are untouched and the caller may retry. */ + data object Transient : RefreshResult + } + + /** Refreshes tokens for a specific saved server, including downloads queued while another server is active. */ + fun refreshAuthTokens( + serverConnectionConfigId: String, + httpClient: OkHttpClient? = null, + onResult: (RefreshResult) -> Unit + ) { + val config = DeviceManager.getServerConnectionConfig(serverConnectionConfigId) + val refreshToken = secureStorage.getRefreshToken(serverConnectionConfigId) + if (config == null || refreshToken.isNullOrEmpty()) { + AbsLogger.error(tag, "No refresh token or server configuration for $serverConnectionConfigId") + handleRefreshRejected(serverConnectionConfigId) + onResult(RefreshResult.Rejected) + return + } + val request = try { + Request.Builder() + .url("${config.address}/auth/refresh") + .addHeader("x-refresh-token", refreshToken) + .addHeader("Content-Type", "application/json") + .post(EMPTY_REQUEST) + .build() + } catch (e: Exception) { + AbsLogger.error(tag, "Could not create refresh request for ${config.name}: ${e.message}") + onResult(RefreshResult.Transient) + return + } + (httpClient ?: defaultClient).newCall(request).enqueue(object : Callback { + override fun onFailure(call: Call, e: IOException) { + AbsLogger.error(tag, "Token refresh failed for ${config.name}: ${e.message}") + onResult(RefreshResult.Transient) } - // Get refresh token from secure storage - val refreshToken = secureStorage.getRefreshToken(serverConnectionConfigId) - if (refreshToken.isNullOrEmpty()) { - AbsLogger.error(tag, "handleTokenRefresh: Unable to refresh auth tokens. No refresh token available for server ${DeviceManager.serverConnectionConfigString}") - val errorObj = JSObject() - errorObj.put("error", "No refresh token available") - callback(errorObj) - return - } - - Log.d(tag, "handleTokenRefresh: Retrieved refresh token, attempting to refresh access token") - - // Create refresh token request - val refreshEndpoint = "${DeviceManager.serverAddress}/auth/refresh" - val refreshRequest = Request.Builder() - .url(refreshEndpoint) - .addHeader("x-refresh-token", refreshToken) - .addHeader("Content-Type", "application/json") - .post(EMPTY_REQUEST) - .build() - - // Make the refresh request - val client = httpClient ?: defaultClient - client.newCall(refreshRequest).enqueue(object : Callback { - override fun onFailure(call: Call, e: IOException) { - Log.e(tag, "handleTokenRefresh: Failed to connect to refresh endpoint", e) - AbsLogger.error(tag, "handleTokenRefresh: Failed to connect to refresh endpoint for server ${DeviceManager.serverConnectionConfigString} (error: ${e.message})") - handleRefreshFailure(callback) - } - - override fun onResponse(call: Call, response: Response) { - response.use { - if (!it.isSuccessful) { - AbsLogger.error(tag, "handleTokenRefresh: Refresh request failed with status ${it.code} for server ${DeviceManager.serverConnectionConfigString}") - handleRefreshFailure(callback) + override fun onResponse(call: Call, response: Response) { + response.use { + if (!it.isSuccessful) { + AbsLogger.error(tag, "Token refresh returned ${it.code} for ${config.name}") + if (it.code != 401 && it.code != 403) { + onResult(RefreshResult.Transient) return } - - val bodyString = it.body!!.string() - try { - val responseJson = JSONObject(bodyString) - val userObj = responseJson.optJSONObject("user") - - if (userObj == null) { - AbsLogger.error(tag, "handleTokenRefresh: No user object in refresh response for server ${DeviceManager.serverConnectionConfigString}") - handleRefreshFailure(callback) - return - } - - val newAccessToken = userObj.optString("accessToken") - val newRefreshToken = userObj.optString("refreshToken") - - if (newAccessToken.isEmpty()) { - AbsLogger.error(tag, "handleTokenRefresh: No access token in refresh response for server ${DeviceManager.serverConnectionConfigString}") - handleRefreshFailure(callback) - return - } - - Log.d(tag, "handleTokenRefresh: Successfully obtained new access token") - - // Update tokens in secure storage and device manager - updateTokens(newAccessToken, newRefreshToken.ifEmpty { refreshToken }, serverConnectionConfigId) - - // Retry the original request with the new access token - Log.d(tag, "handleTokenRefresh: Retrying original request with new token") - retryOriginalRequest(originalRequest, newAccessToken, httpClient, callback) - - } catch (e: Exception) { - Log.e(tag, "handleTokenRefresh: Failed to parse refresh response", e) - AbsLogger.error(tag, "handleTokenRefresh: Failed to parse refresh response for server ${DeviceManager.serverConnectionConfigString} (error: ${e.message})") - handleRefreshFailure(callback) + handleRefreshRejected(serverConnectionConfigId) + onResult(RefreshResult.Rejected) + return + } + try { + val user = JSONObject(it.body!!.string()).optJSONObject("user") + val accessToken = user?.optString("accessToken").orEmpty() + if (accessToken.isEmpty()) { + AbsLogger.error(tag, "Refresh response had no access token for ${config.name}") + onResult(RefreshResult.Transient) + return } + updateTokens(accessToken, user?.optString("refreshToken").orEmpty().ifEmpty { refreshToken }, serverConnectionConfigId) + onResult(RefreshResult.Success(accessToken)) + } catch (e: Exception) { + AbsLogger.error(tag, "Could not parse refresh response for ${config.name}: ${e.message}") + onResult(RefreshResult.Transient) } } - }) + } + }) + } + /** + * Clears only the server that rejected the refresh token; queued downloads can target a non-active server. + * + * Only call this when the server explicitly rejected the refresh token. Transient failures should not log the user out + */ + private fun handleRefreshRejected(serverConnectionConfigId: String) { + // Must not throw: callers still have to report the refresh result to an in-flight request or download. + try { + secureStorage.removeRefreshToken(serverConnectionConfigId) + if (DeviceManager.serverConnectionConfigId != serverConnectionConfigId) return + DeviceManager.serverConnectionConfig = null + DeviceManager.deviceData.lastServerConnectionConfigId = null + DeviceManager.dbManager.saveDeviceData(DeviceManager.deviceData) + if (checkAbsDatabaseNotifyListenersInitted()) { + absDatabaseNotifyListeners( + "onTokenRefreshFailure", + JSObject().put("error", "Token refresh failed").put("serverConnectionConfigId", serverConnectionConfigId)) + } } catch (e: Exception) { - Log.e(tag, "handleTokenRefresh: Unexpected error during token refresh", e) - handleRefreshFailure(callback) + AbsLogger.error(tag, "Could not clear session for $serverConnectionConfigId: ${e.message}") } } @@ -283,15 +294,15 @@ class ApiHandler(var ctx:Context) { Log.d(tag, "updateTokens: Updated refresh token in secure storage") } - // Update the access token in the current server connection config - DeviceManager.serverConnectionConfig?.let { config -> + // The refreshed connection may be queued in the downloader rather than currently active. + DeviceManager.getServerConnectionConfig(serverConnectionConfigId)?.let { config -> config.token = newAccessToken DeviceManager.dbManager.saveDeviceData(DeviceManager.deviceData) Log.d(tag, "updateTokens: Updated access token in server connection config") } // Send access token to Webview frontend - if (checkAbsDatabaseNotifyListenersInitted()) { + if (DeviceManager.serverConnectionConfigId == serverConnectionConfigId && checkAbsDatabaseNotifyListenersInitted()) { val tokenJsObject = JSObject() tokenJsObject.put("accessToken", newAccessToken) absDatabaseNotifyListeners("onTokenRefresh", tokenJsObject) @@ -379,50 +390,6 @@ class ApiHandler(var ctx:Context) { } } - /** - * Handles the case when token refresh fails - * This will clear the current session and notify the callback - * - * @param callback The callback to return the error - */ - private fun handleRefreshFailure(callback: (JSObject) -> Unit) { - try { - Log.d(tag, "handleRefreshFailure: Token refresh failed, clearing session") - - // Clear the current server connection - DeviceManager.serverConnectionConfig = null - DeviceManager.deviceData.lastServerConnectionConfigId = null - DeviceManager.dbManager.saveDeviceData(DeviceManager.deviceData) - - // Remove refresh token from secure storage - val serverConnectionConfigId = DeviceManager.serverConnectionConfigId - if (serverConnectionConfigId.isNotEmpty()) { - secureStorage.removeRefreshToken(serverConnectionConfigId) - } - - val errorObj = JSObject() - errorObj.put("error", "Authentication failed - please login again") - callback(errorObj) - - if (checkAbsDatabaseNotifyListenersInitted()) { - val tokenJsObject = JSObject() - tokenJsObject.put("error", "Token refresh failed") - if (serverConnectionConfigId.isNotEmpty()) { - tokenJsObject.put("serverConnectionConfigId", serverConnectionConfigId) - } - absDatabaseNotifyListeners("onTokenRefreshFailure", tokenJsObject) - } else { - // Can happen if Webview is never run - Log.i(tag, "AbsDatabaseNotifyListeners is not initialized so cannot send token refresh failure notification") - } - } catch (e: Exception) { - Log.e(tag, "handleRefreshFailure: Error during failure handling", e) - val errorObj = JSObject() - errorObj.put("error", "Authentication failed") - callback(errorObj) - } - } - fun getCurrentUser(cb: (User?) -> Unit) { getRequest("/api/me", null, null) { if (it.has("error")) { diff --git a/android/app/src/main/java/com/audiobookshelf/app/services/DownloadService.kt b/android/app/src/main/java/com/audiobookshelf/app/services/DownloadService.kt index 51e9ae31..3ee79eaf 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/services/DownloadService.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/services/DownloadService.kt @@ -28,7 +28,7 @@ class DownloadService : Service() { ACTION_CANCEL -> DownloadServiceHost.cancelAll(this) else -> { startForegroundWithType(DownloadServiceHost.notificationStrings(this).preparing) - DownloadServiceHost.ensure(this) + DownloadServiceHost.startWork(this) } } return START_STICKY diff --git a/android/app/src/main/java/com/audiobookshelf/app/services/DownloadServiceHost.kt b/android/app/src/main/java/com/audiobookshelf/app/services/DownloadServiceHost.kt index 38f64a74..1bf1f8c3 100644 --- a/android/app/src/main/java/com/audiobookshelf/app/services/DownloadServiceHost.kt +++ b/android/app/src/main/java/com/audiobookshelf/app/services/DownloadServiceHost.kt @@ -5,12 +5,21 @@ import androidx.core.content.ContextCompat import com.audiobookshelf.app.device.FolderScanner import com.audiobookshelf.app.managers.DbManager import com.audiobookshelf.app.managers.DownloadItemManager +import com.audiobookshelf.app.managers.IncompleteDownloadCleanup import com.audiobookshelf.app.models.DownloadItem +import com.audiobookshelf.app.plugins.AbsLogger import com.getcapacitor.JSObject import java.util.Collections +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.Job +import kotlinx.coroutines.SupervisorJob +import kotlinx.coroutines.launch /** Shared process owner used by the foreground service and the Capacitor bridge. */ object DownloadServiceHost { + enum class ExistingDownloadResult { NOT_FOUND, ACTIVE, RETRIED, SERVICE_START_FAILED } + data class NotificationStrings( val preparing: String, val downloadingFile: String, @@ -21,9 +30,11 @@ object DownloadServiceHost { private var manager: DownloadItemManager? = null private var bridgeEmitter: DownloadItemManager.DownloadEventEmitter = NoopEmitter - private var service: DownloadService? = null + @Volatile private var service: DownloadService? = null @Volatile private var bridgeReady = false private val deferredCompletions = Collections.synchronizedList(mutableListOf()) + private val scope = CoroutineScope(SupervisorJob() + Dispatchers.IO) + private var restoreJob: Job? = null @Synchronized fun ensure(context: Context): DownloadItemManager { @@ -31,7 +42,11 @@ object DownloadServiceHost { val appContext = context.applicationContext DbManager.initialize(appContext) manager = DownloadItemManager(FolderScanner(appContext), appContext, ForwardingEmitter) - manager!!.restoreQueue() + restoreJob = scope.launch { + IncompleteDownloadCleanup.cleanupExpired(appContext) + manager!!.restoreQueue() + onRestoreComplete(appContext) + } } return manager!! } @@ -41,14 +56,12 @@ object DownloadServiceHost { fun attachBridge(context: Context, emitter: DownloadItemManager.DownloadEventEmitter) { bridgeReady = false bridgeEmitter = emitter - val queue = ensure(context) - queue.setEventEmitter(ForwardingEmitter) + ensure(context).setEventEmitter(ForwardingEmitter) bridgeReady = true val completions = synchronized(deferredCompletions) { deferredCompletions.toList().also { deferredCompletions.clear() } } completions.forEach(bridgeEmitter::onDownloadItemComplete) - if (queue.hasWork()) startService(context) } @Synchronized @@ -57,14 +70,44 @@ object DownloadServiceHost { bridgeEmitter = NoopEmitter } - @Synchronized - fun enqueue(context: Context, item: DownloadItem) { - ensure(context).addDownloadItem(item) - startService(context) + fun enqueue(context: Context, item: DownloadItem, callback: (String?) -> Unit) { + val queue = ensure(context) + scope.launch { + restoreJob?.join() + queue.addDownloadItem(item) + if (startService(context)) callback(null) + else callback("Unable to start the Android download service") + } } - @Synchronized - fun cancelAll(context: Context) { ensure(context).cancelAll() } + fun retryExisting( + context: Context, + downloadItemId: String, + callback: (ExistingDownloadResult) -> Unit + ) { + val queue = ensure(context) + scope.launch { + restoreJob?.join() + val existing = queue.downloadItemQueue.find { it.id == downloadItemId } + if (existing == null) { + callback(ExistingDownloadResult.NOT_FOUND) + } else if (!queue.retryDownloadItem(downloadItemId)) { + callback(ExistingDownloadResult.ACTIVE) + } else if (startService(context)) { + callback(ExistingDownloadResult.RETRIED) + } else { + callback(ExistingDownloadResult.SERVICE_START_FAILED) + } + } + } + + fun cancelAll(context: Context) { + val queue = ensure(context) + scope.launch { + restoreJob?.join() + queue.cancelAll() + } + } fun setNotificationStrings( context: Context, @@ -96,10 +139,9 @@ object DownloadServiceHost { preferences.getString(KEY_CANCEL, DEFAULT_CANCEL) ?: DEFAULT_CANCEL) } - @Synchronized fun attachService(downloadService: DownloadService) { - service = downloadService - service?.onQueueChanged(ensure(downloadService).hasWork()) + synchronized(this) { service = downloadService } + startWork(downloadService) } @Synchronized @@ -107,8 +149,31 @@ object DownloadServiceHost { if (service === downloadService) service = null } - private fun startService(context: Context) { - ContextCompat.startForegroundService(context, DownloadService.intent(context)) + fun startWork(context: Context) { + val queue = ensure(context) + scope.launch { + restoreJob?.join() + queue.resumeWork() + } + } + + private fun onRestoreComplete(context: Context) { + val attachedService = synchronized(this) { service } + if (attachedService != null) { + manager?.resumeWork() + } else if (bridgeReady && manager?.hasWork() == true) { + startService(context) + } + } + + private fun startService(context: Context): Boolean { + return try { + ContextCompat.startForegroundService(context, DownloadService.intent(context)) + true + } catch (e: RuntimeException) { + AbsLogger.error(TAG, "Could not start download foreground service: ${e.message}") + false + } } private object ForwardingEmitter : DownloadItemManager.DownloadEventEmitter { @@ -144,4 +209,5 @@ object DownloadServiceHost { private const val DEFAULT_WAITING_FOR_STORAGE = "Waiting for available storage" private const val DEFAULT_DOWNLOADS = "Downloads" private const val DEFAULT_CANCEL = "Cancel" + private const val TAG = "DownloadServiceHost" } diff --git a/ios/App/App/plugins/AbsDownloader.swift b/ios/App/App/plugins/AbsDownloader.swift index 37f0a80c..19df4f93 100644 --- a/ios/App/App/plugins/AbsDownloader.swift +++ b/ios/App/App/plugins/AbsDownloader.swift @@ -78,6 +78,7 @@ public class AbsDownloader: CAPPlugin, CAPBridgedPlugin, URLSessionDownloadDeleg liveDownloadItemPart.progress = 100 liveDownloadItemPart.completed = true } + AbsLogger.info(message: "Download completed for \(liveDownloadItemPart.filename ?? partId)") do { // Move the downloaded file into place @@ -89,6 +90,7 @@ public class AbsDownloader: CAPPlugin, CAPBridgedPlugin, URLSessionDownloadDeleg try realm.write { liveDownloadItemPart.moved = true } + AbsLogger.info(message: "Move completed for \(liveDownloadItemPart.filename ?? partId) to \(destinationUrl.path)") } catch { try realm.write { liveDownloadItemPart.failed = true diff --git a/pages/downloading.vue b/pages/downloading.vue index 72415947..cd206e3a 100644 --- a/pages/downloading.vue +++ b/pages/downloading.vue @@ -4,7 +4,7 @@
No download item parts