diff --git a/app/src/main/java/org/thoughtcrime/securesms/backup/ArchiveUploadProgress.kt b/app/src/main/java/org/thoughtcrime/securesms/backup/ArchiveUploadProgress.kt index aff106637b..b8fe2d3ec7 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/backup/ArchiveUploadProgress.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/backup/ArchiveUploadProgress.kt @@ -15,8 +15,10 @@ import kotlinx.coroutines.flow.map import kotlinx.coroutines.flow.onEach import kotlinx.coroutines.flow.onStart import kotlinx.coroutines.withContext +import org.signal.core.util.bytes import org.signal.core.util.logging.Log import org.signal.core.util.throttleLatest +import org.thoughtcrime.securesms.BuildConfig import org.thoughtcrime.securesms.attachments.AttachmentId import org.thoughtcrime.securesms.backup.v2.BackupRepository import org.thoughtcrime.securesms.database.SignalDatabase @@ -27,11 +29,13 @@ import org.thoughtcrime.securesms.jobs.BackupMessagesJob import org.thoughtcrime.securesms.jobs.UploadAttachmentToArchiveJob import org.thoughtcrime.securesms.keyvalue.SignalStore import org.thoughtcrime.securesms.keyvalue.protos.ArchiveUploadProgressState +import org.thoughtcrime.securesms.util.SignalLocalMetrics import org.whispersystems.signalservice.api.messages.AttachmentTransferProgress import java.util.concurrent.ConcurrentHashMap import kotlin.math.max import kotlin.time.Duration.Companion.milliseconds import kotlin.time.Duration.Companion.seconds +import kotlin.time.DurationUnit /** * Tracks the progress of uploading your message archive and provides an observable stream of results. @@ -48,7 +52,11 @@ object ArchiveUploadProgress { private var uploadProgress: ArchiveUploadProgressState = SignalStore.backup.archiveUploadState ?: PROGRESS_NONE - private val partialMediaProgress: MutableMap = ConcurrentHashMap() + private val attachmentProgress: MutableMap = ConcurrentHashMap() + + private var debugAttachmentStartTime: Long = 0 + private var debugTotalAttachments: Int = 0 + private var debugTotalBytes: Long = 0 /** * Observe this to get updates on the current upload progress. @@ -69,9 +77,10 @@ object ArchiveUploadProgress { return@map PROGRESS_NONE } - val pendingMediaUploadBytes = SignalDatabase.attachments.getPendingArchiveUploadBytes() - partialMediaProgress.values.sum() + val pendingMediaUploadBytes = SignalDatabase.attachments.getPendingArchiveUploadBytes() - attachmentProgress.values.sumOf { it.bytesUploaded } if (pendingMediaUploadBytes <= 0) { Log.i(TAG, "No more pending bytes. Done!") + Log.d(TAG, buildDebugStats(debugAttachmentStartTime, debugTotalAttachments, debugTotalBytes)) return@map PROGRESS_NONE } @@ -155,7 +164,8 @@ object ArchiveUploadProgress { } } - fun onAttachmentsStarted(totalAttachmentBytes: Long) { + fun onAttachmentSectionStarted(totalAttachmentBytes: Long) { + debugAttachmentStartTime = System.currentTimeMillis() updateState { it.copy( state = ArchiveUploadProgressState.State.UploadMedia, @@ -165,13 +175,28 @@ object ArchiveUploadProgress { } } + fun onAttachmentStarted(attachmentId: AttachmentId, sizeBytes: Long) { + SignalLocalMetrics.ArchiveAttachmentUpload.start(attachmentId) + attachmentProgress[attachmentId] = AttachmentProgressDetails(startTimeMs = System.currentTimeMillis(), totalBytes = sizeBytes) + _progress.tryEmit(Unit) + } + fun onAttachmentProgress(attachmentId: AttachmentId, bytesUploaded: Long) { - partialMediaProgress[attachmentId] = bytesUploaded + attachmentProgress.getOrPut(attachmentId) { AttachmentProgressDetails() }.bytesUploaded = bytesUploaded _progress.tryEmit(Unit) } fun onAttachmentFinished(attachmentId: AttachmentId) { - partialMediaProgress.remove(attachmentId) + SignalLocalMetrics.ArchiveAttachmentUpload.end(attachmentId) + debugTotalAttachments++ + + attachmentProgress[attachmentId]?.let { + if (BuildConfig.DEBUG) { + Log.d(TAG, "Attachment finished: $it") + } + debugTotalBytes += it.totalBytes + } + attachmentProgress.remove(attachmentId) _progress.tryEmit(Unit) } @@ -265,4 +290,32 @@ object ArchiveUploadProgress { } } } + + private fun buildDebugStats(startTimeMs: Long, totalAttachments: Int, totalBytes: Long): String { + if (debugAttachmentStartTime <= 0 || debugTotalAttachments <= 0 || debugTotalBytes <= 0) { + return "Insufficient data to print debug stats." + } + + val seconds: Double = (System.currentTimeMillis() - startTimeMs).milliseconds.toDouble(DurationUnit.SECONDS) + val bytesPerSecond: Long = (totalBytes / seconds).toLong() + + return "TotalAttachments=$totalAttachments, TotalBytes=$totalBytes (${totalBytes.bytes.toUnitString()}), Rate=$bytesPerSecond bytes/sec (${bytesPerSecond.bytes.toUnitString()}/sec)" + } + + private class AttachmentProgressDetails( + val startTimeMs: Long = 0, + val totalBytes: Long = 0, + var bytesUploaded: Long = 0 + ) { + override fun toString(): String { + if (startTimeMs == 0L || totalBytes == 0L) { + return "N/A" + } + + val seconds: Double = (System.currentTimeMillis() - startTimeMs).milliseconds.toDouble(DurationUnit.SECONDS) + val bytesPerSecond: Long = (bytesUploaded / seconds).toLong() + + return "Duration=${System.currentTimeMillis() - startTimeMs}ms, TotalBytes=$totalBytes (${totalBytes.bytes.toUnitString()}), Rate=$bytesPerSecond bytes/sec (${bytesPerSecond.bytes.toUnitString()}/sec)" + } + } } diff --git a/app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt b/app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt index fa6f5949ee..90150fb4c1 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt @@ -61,7 +61,6 @@ import org.signal.core.util.requireString import org.signal.core.util.select import org.signal.core.util.toInt import org.signal.core.util.update -import org.signal.core.util.updateAll import org.signal.core.util.withinTransaction import org.thoughtcrime.securesms.attachments.ArchivedAttachment import org.thoughtcrime.securesms.attachments.Attachment @@ -2011,11 +2010,13 @@ class AttachmentTable( fun clearAllArchiveData() { writableDatabase - .updateAll(TABLE_NAME) + .update(TABLE_NAME) .values( ARCHIVE_CDN to null, - ARCHIVE_TRANSFER_STATE to ArchiveTransferState.NONE.value + ARCHIVE_TRANSFER_STATE to ArchiveTransferState.NONE.value, + UPLOAD_TIMESTAMP to 0 ) + .where("$ARCHIVE_CDN NOT NULL") .run() } diff --git a/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentBackfillJob.kt b/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentBackfillJob.kt index 61cfbcb28a..c8a3b9640a 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentBackfillJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentBackfillJob.kt @@ -47,7 +47,7 @@ class ArchiveAttachmentBackfillJob private constructor(parameters: Parameters) : SignalDatabase.attachments.createRemoteKeyForAttachmentsThatNeedArchiveUpload() - ArchiveUploadProgress.onAttachmentsStarted(SignalDatabase.attachments.getPendingArchiveUploadBytes()) + ArchiveUploadProgress.onAttachmentSectionStarted(SignalDatabase.attachments.getPendingArchiveUploadBytes()) if (!isCanceled) { Log.i(TAG, "Adding ${jobs.size} jobs to backfill attachments.") diff --git a/app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt b/app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt index cd14a232f4..ca33298ace 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt @@ -188,6 +188,8 @@ class UploadAttachmentToArchiveJob private constructor( null } + ArchiveUploadProgress.onAttachmentStarted(attachmentId, attachment.size) + val attachmentStream = try { AttachmentUploadUtil.buildSignalServiceAttachmentStream( context = context, diff --git a/app/src/main/java/org/thoughtcrime/securesms/util/SignalLocalMetrics.java b/app/src/main/java/org/thoughtcrime/securesms/util/SignalLocalMetrics.java index 0f68b11ab7..b9bcf0669d 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/util/SignalLocalMetrics.java +++ b/app/src/main/java/org/thoughtcrime/securesms/util/SignalLocalMetrics.java @@ -6,6 +6,8 @@ import androidx.annotation.MainThread; import androidx.annotation.NonNull; import androidx.annotation.Nullable; +import org.thoughtcrime.securesms.attachments.AttachmentId; + import java.util.HashMap; import java.util.Map; import java.util.concurrent.atomic.AtomicInteger; @@ -497,4 +499,21 @@ public final class SignalLocalMetrics { } } } + + /** + * Tracks how long it took to upload an attachment to the archive CDN. + */ + public static final class ArchiveAttachmentUpload { + private static final String NAME = "archive-attachment-upload"; + + /** When the attachment begins uploading. */ + public static void start(AttachmentId id) { + LocalMetrics.getInstance().start(NAME, NAME + id); + } + + /** When the attachment finishes uploading. */ + public static void end(AttachmentId id) { + LocalMetrics.getInstance().end(NAME + id); + } + } }