From 3eb44dc8924d0b944089dd9d6731c9dbe476404b Mon Sep 17 00:00:00 2001
From: zarzet <42882290+zarzet@users.noreply.github.com>
Date: Thu, 17 Sep 2026 02:59:29 +0700
Subject: [PATCH] perf(downloads): log finalization stage durations

---
 .../zarz/spotiflac/NativeDownloadFinalizer.kt | 53 +++++++++++++------
 .../download_queue_provider_single_item.dart  | 19 +++++++
 2 files changed, 57 insertions(+), 15 deletions(-)

diff --git a/android/app/src/main/kotlin/com/zarz/spotiflac/NativeDownloadFinalizer.kt b/android/app/src/main/kotlin/com/zarz/spotiflac/NativeDownloadFinalizer.kt
index c2c538e2..6d8e09a0 100644
--- a/android/app/src/main/kotlin/com/zarz/spotiflac/NativeDownloadFinalizer.kt
+++ b/android/app/src/main/kotlin/com/zarz/spotiflac/NativeDownloadFinalizer.kt
@@ -171,6 +171,15 @@ object NativeDownloadFinalizer {
         }
     }
 
+    private inline fun <T> timedStage(name: String, block: () -> T): T {
+        val started = System.nanoTime()
+        try {
+            return block()
+        } finally {
+            Log.d(TAG, "Finalization stage $name took ${(System.nanoTime() - started) / 1_000_000}ms")
+        }
+    }
+
     fun finalize(
         context: Context,
         itemId: String,
@@ -230,19 +239,27 @@ object NativeDownloadFinalizer {
                 currentStatus("finalizing")
                 finalizeDecryption(context, effectiveInput, state, shouldCancel)
                 checkCancelled(shouldCancel)
-                finalizeContainerConversion(context, effectiveInput, state, shouldCancel)
+                timedStage("container conversion") {
+                    finalizeContainerConversion(context, effectiveInput, state, shouldCancel)
+                }
                 checkCancelled(shouldCancel)
-                finalizeMetadata(context, effectiveInput, state)
+                timedStage("metadata") {
+                    finalizeMetadata(context, effectiveInput, state)
+                }
                 checkCancelled(shouldCancel)
-                runPostProcessing(context, effectiveInput, state, shouldCancel)
+                timedStage("extension post-processing") {
+                    runPostProcessing(context, effectiveInput, state, shouldCancel)
+                }
                 checkCancelled(shouldCancel)
                 try {
-                    finalizeAutoConversion(
-                        context,
-                        effectiveInput,
-                        state,
-                        shouldCancel,
-                    )
+                    timedStage("automatic conversion") {
+                        finalizeAutoConversion(
+                            context,
+                            effectiveInput,
+                            state,
+                            shouldCancel,
+                        )
+                    }
                 } catch (e: CancellationException) {
                     throw e
                 } catch (e: Exception) {
@@ -253,7 +270,9 @@ object NativeDownloadFinalizer {
                 }
                 checkCancelled(shouldCancel)
                 try {
-                    val replayGain = writeReplayGain(context, effectiveInput, state, shouldCancel)
+                    val replayGain = timedStage("ReplayGain") {
+                        writeReplayGain(context, effectiveInput, state, shouldCancel)
+                    }
                     if (replayGain != null) result.put("replaygain", replayGain)
                 } catch (e: CancellationException) {
                     throw e
@@ -265,7 +284,9 @@ object NativeDownloadFinalizer {
                 }
                 checkCancelled(shouldCancel)
                 try {
-                    refreshFinalAudioQualityMetadata(context, result, state)
+                    timedStage("quality probe") {
+                        refreshFinalAudioQualityMetadata(context, result, state)
+                    }
                 } catch (e: Exception) {
                     android.util.Log.w(TAG, "Quality metadata refresh failed (non-fatal): ${e.message}")
                 }
@@ -282,10 +303,12 @@ object NativeDownloadFinalizer {
                     android.util.Log.w(TAG, "External LRC write failed (non-fatal): ${e.message}")
                 }
                 checkCancelled(shouldCancel)
-                if (isDeferredSafPublish(effectiveInput)) {
-                    publishDeferredSafOutput(context, effectiveInput, state)
-                } else {
-                    promoteStagedSafOutputIfNeeded(context, effectiveInput, state)
+                timedStage("publish") {
+                    if (isDeferredSafPublish(effectiveInput)) {
+                        publishDeferredSafOutput(context, effectiveInput, state)
+                    } else {
+                        promoteStagedSafOutputIfNeeded(context, effectiveInput, state)
+                    }
                 }
                 outputPublished = true
             } else {
diff --git a/lib/providers/download_queue_provider_single_item.dart b/lib/providers/download_queue_provider_single_item.dart
index e64d28e2..d12d58ae 100644
--- a/lib/providers/download_queue_provider_single_item.dart
+++ b/lib/providers/download_queue_provider_single_item.dart
@@ -667,6 +667,15 @@ class _DownloadRun {
   }
 
   Future<bool> _handleDownloadSuccess() async {
+    final stageWatch = LogBuffer.loggingEnabled ? (Stopwatch()..start()) : null;
+    void stageCompleted(String stage) {
+      if (stageWatch == null) return;
+      _log.d(
+        'Finalization [${item.id}] $stage: ${stageWatch.elapsedMilliseconds} ms',
+      );
+      stageWatch.reset();
+    }
+
     filePath = result['file_path'] as String?;
     final reportedFileName = result['file_name'] as String?;
     if (effectiveSafMode &&
@@ -728,7 +737,9 @@ class _DownloadRun {
     if (!await _decryptIfNeeded()) {
       return false;
     }
+    stageCompleted('decrypt');
     await _applyFormatHandling(actualService);
+    stageCompleted('format and metadata');
 
     if (await _shouldAbort(
       'during finalization',
@@ -745,6 +756,7 @@ class _DownloadRun {
     if (!deferredSafPublish) {
       await _recoverSafUriIfNeeded();
     }
+    stageCompleted('resolve storage');
 
     final hookInput = filePath;
     if (hookInput != null) {
@@ -776,6 +788,7 @@ class _DownloadRun {
     }
 
     final autoConvertInput = filePath;
+    stageCompleted('extension hooks');
     if (!wasExisting && autoConvertInput != null) {
       final outcome = await n._autoConvertDownloadedFile(
         itemId: item.id,
@@ -795,6 +808,7 @@ class _DownloadRun {
       actualQuality = outcome.quality;
       if (outcome.converted) probedFinalMetadata = null;
     }
+    stageCompleted('automatic conversion');
 
     final variantInput = filePath;
     if (variantInput != null && item.preserveQualityVariant) {
@@ -816,6 +830,7 @@ class _DownloadRun {
         probedFinalMetadata = variantOutcome.metadata;
       }
     }
+    stageCompleted('quality filename');
 
     if (normalizeOptionalString(filePath) == null) {
       throw StateError(
@@ -826,6 +841,7 @@ class _DownloadRun {
     if (deferredSafPublish && !await _publishDeferredSafOutputOnce()) {
       throw StateError('Failed to publish deferred SAF output');
     }
+    stageCompleted('publish audio');
 
     final lrcTarget = filePath;
     if (lrcTarget != null &&
@@ -855,6 +871,7 @@ class _DownloadRun {
     }
 
     final rgPath = filePath;
+    stageCompleted('external lyrics');
     // Album ReplayGain: update the accumulator path to the final file
     // location.  For SAF downloads the metadata was embedded on a temp
     // copy, so the stored path still points there.  Replace it with the
@@ -870,8 +887,10 @@ class _DownloadRun {
     } catch (e) {
       _log.w('Album ReplayGain check failed: $e');
     }
+    stageCompleted('album ReplayGain');
 
     await _persistCompletionAndNotify();
+    stageCompleted('quality probe, history and notification');
     return true;
   }