From 79ed655f52bba235b0623612d4736ee294d35a80 Mon Sep 17 00:00:00 2001 From: Harry <109690906+harry-signal@users.noreply.github.com> Date: Tue, 21 Oct 2025 17:00:35 -0700 Subject: [PATCH] Add a bunch of attachment happy path logging --- .../BackupAttachmentDownloadQueueRunner.swift | 7 +- .../BackupAttachmentDownloadScheduler.swift | 12 +- .../BackupAttachmentDownloadStore.swift | 165 ++++++------------ .../BackupAttachmentDownloadStoreTests.swift | 4 +- .../BackupAttachmentUploadScheduler.swift | 128 +++++++++++--- .../BackupAttachmentUploadStore.swift | 78 ++++----- .../BackupAttachmentUploadStoreTests.swift | 4 +- .../BackupListMediaManagerTests.swift | 4 +- .../Backups/Settings/BackupPlanManager.swift | 5 + SignalServiceKit/Environment/AppSetup.swift | 4 +- 10 files changed, 220 insertions(+), 191 deletions(-) diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadQueueRunner.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadQueueRunner.swift index c0c8c61e53..7f256e0e63 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadQueueRunner.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadQueueRunner.swift @@ -122,12 +122,14 @@ public class BackupAttachmentDownloadQueueRunnerImpl: BackupAttachmentDownloadQu switch await statusManager.beginObservingIfNecessary(for: mode) { case .running: - break + logger.info("Starting \(logString) backup attachment downloads") case .suspended: // The queue will stop on its own if suspended + logger.info("Skipping \(logString) backup attachment downloads while suspended") return case .empty: // The queue will stop on its own if empty. + logger.info("\(logString) backup attachment download queue empty!") return case .notRegisteredAndReady: try await taskQueue.stop() @@ -179,6 +181,8 @@ public class BackupAttachmentDownloadQueueRunnerImpl: BackupAttachmentDownloadQu defer { backgroundTask.end() } try await taskQueue.loadAndRunTasks() + + logger.info("Finished \(logString) backup attachment downloads") } // MARK: - TaskRecordRunner @@ -354,6 +358,7 @@ public class BackupAttachmentDownloadQueueRunnerImpl: BackupAttachmentDownloadQu // got here but mark it ineligible in the queue now and return // a a "retryable" error so we don't wipe this row from the queue. // Since its now ineligible it will be skipped going forward. + Logger.info("Marking \(attachment.id) ineligible and skipping download") try? await db.awaitableWrite { tx in try backupAttachmentDownloadStore.markIneligible( attachmentId: attachment.id, diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadScheduler.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadScheduler.swift index a92086c3cc..30dfd2a66d 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadScheduler.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadScheduler.swift @@ -59,7 +59,11 @@ public class BackupAttachmentDownloadSchedulerImpl: BackupAttachmentDownloadSche canDownloadFromMediaTier: true, state: state, currentTimestamp: restoreStartTimestampMs, - tx: tx + tx: tx, + // Don't trigger per-item logs from backups; too noisy + file: nil, + function: nil, + line: nil ) } if @@ -72,7 +76,11 @@ public class BackupAttachmentDownloadSchedulerImpl: BackupAttachmentDownloadSche canDownloadFromMediaTier: eligibility.canDownloadMediaTierFullsize, state: state, currentTimestamp: restoreStartTimestampMs, - tx: tx + tx: tx, + // Don't trigger per-item logs from backups; too noisy + file: nil, + function: nil, + line: nil ) } } diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStore.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStore.swift index 32764756d8..f60705e562 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStore.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStore.swift @@ -6,7 +6,13 @@ import Foundation import GRDB -public protocol BackupAttachmentDownloadStore { +public class BackupAttachmentDownloadStore { + + private let kvStore: KeyValueStore + + public init() { + self.kvStore = KeyValueStore(collection: "BackupAttachmentDownloadStoreImpl") + } /// "Enqueue" an attachment from a backup for download (using its reference). /// @@ -15,116 +21,21 @@ public protocol BackupAttachmentDownloadStore { /// /// Doesn't actually trigger a download; callers must later call ``BackupAttachmentDownloadManager`` /// to actually kick off downloads. - func enqueue( - _ referencedAttachment: ReferencedAttachment, - thumbnail: Bool, - canDownloadFromMediaTier: Bool, - state: QueuedBackupAttachmentDownload.State, - currentTimestamp: UInt64, - tx: DBWriteTransaction - ) throws - - func getEnqueuedDownload( - attachmentRowId: Attachment.IDType, - thumbnail: Bool, - tx: DBReadTransaction - ) throws -> QueuedBackupAttachmentDownload? - - /// Read the next highest priority downloads off the queue, up to count. - /// Returns an empty array if nothing is left to download. - func peek( - count: UInt, - isThumbnail: Bool, - tx: DBReadTransaction - ) throws -> [QueuedBackupAttachmentDownload] - - /// Returns true if there are any rows in the ready state. - func hasAnyReadyDownloads( - isThumbnail: Bool, - tx: DBReadTransaction - ) throws -> Bool - - /// Mark a download as done. - /// If we mark a fullsize as done, the thumbnail is marked done too - /// (since we never need a thumbnail once we have a fullsize). - func markDone( - attachmentId: Attachment.IDType, - thumbnail: Bool, - tx: DBWriteTransaction - ) throws - - /// Mark a download as ineligible. - func markIneligible( - attachmentId: Attachment.IDType, - thumbnail: Bool, - tx: DBWriteTransaction - ) throws - - /// Delete a download. - /// WARNING: typically when a download finishes, we want to mark it done - /// rather than deleting, so that it still contributes to the total byte count. - /// Deleting is appropriate if we learn the upload is gone from the CDN, - /// the attachment is deleted, etc; things that mean we will never download. - func remove( - attachmentId: Attachment.IDType, - thumbnail: Bool, - tx: DBWriteTransaction - ) throws - - /// Mark all enqueued & ready media tier fullsize downloads from the table for attachments - /// older than the provided timestamp as ineligible. - /// Applies independently of whether that download is also eligible to download from the - /// transit tier; its assumed that anything on the media tier is stable and if its offloaded to - /// there we don't need to worry about downloading from transit tier before it expires. - func markAllMediaTierFullsizeDownloadsIneligible( - olderThan timestamp: UInt64, - tx: DBWriteTransaction - ) throws - - /// Marks all ineligible rows as ready (no filtering applied). - func markAllIneligibleReady(tx: DBWriteTransaction) throws - - /// Marks all ready rows as ineligible (no filtering applied). - func markAllReadyIneligible(tx: DBWriteTransaction) throws - - /// Remove all done rows (effectively resetting the total byte count). - func deleteAllDone(tx: DBWriteTransaction) throws - - /// Returns nil, NOT 0, if there are no rows. - func computeEstimatedFinishedFullsizeByteCount(tx: DBReadTransaction) throws -> UInt64? - - /// Returns nil, NOT 0, if there are no rows. - func computeEstimatedRemainingFullsizeByteCount(tx: DBReadTransaction) throws -> UInt64? - - // MARK: Banner state - - func getDownloadCompleteBannerByteCount(tx: DBReadTransaction) -> UInt64? - - /// Whether the banner for downloads being complete was dismissed. Reset when new downloads - /// are scheduled (when `setTotalPendingDownloadByteCount` is set.) - func getDidDismissDownloadCompleteBanner(tx: DBReadTransaction) -> Bool - - func setDidDismissDownloadCompleteBanner(tx: DBWriteTransaction) - - func resetDidDismissDownloadCompleteBanner(tx: DBWriteTransaction) -} - -public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { - - private let kvStore: KeyValueStore - - public init() { - self.kvStore = KeyValueStore(collection: "BackupAttachmentDownloadStoreImpl") - } - public func enqueue( _ referencedAttachment: ReferencedAttachment, thumbnail: Bool, canDownloadFromMediaTier: Bool, state: QueuedBackupAttachmentDownload.State, currentTimestamp: UInt64, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws { + if let file, let function, let line { + Logger.info("Enqueuing \(referencedAttachment.attachment.id) thumbnail? \(thumbnail) from \(file) \(line): \(function)") + } + if thumbnail { owsPrecondition(canDownloadFromMediaTier, "All thumbnails are media tier") } @@ -208,6 +119,8 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { .fetchOne(tx.database) } + /// Read the next highest priority downloads off the queue, up to count. + /// Returns an empty array if nothing is left to download. public func peek( count: UInt, isThumbnail: Bool, @@ -226,6 +139,7 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { .fetchAll(tx.database) } + /// Returns true if there are any rows in the ready state. public func hasAnyReadyDownloads( isThumbnail: Bool, tx: DBReadTransaction @@ -237,6 +151,9 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { .negated } + /// Mark a download as done. + /// If we mark a fullsize as done, the thumbnail is marked done too + /// (since we never need a thumbnail once we have a fullsize). public func markDone( attachmentId: Attachment.IDType, thumbnail: Bool, @@ -258,6 +175,7 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { ) } + /// Mark a download as ineligible. public func markIneligible( attachmentId: Attachment.IDType, thumbnail: Bool, @@ -274,21 +192,33 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { ) } + /// Delete a download. + /// WARNING: typically when a download finishes, we want to mark it done + /// rather than deleting, so that it still contributes to the total byte count. + /// Deleting is appropriate if we learn the upload is gone from the CDN, + /// the attachment is deleted, etc; things that mean we will never download. public func remove( attachmentId: Attachment.IDType, thumbnail: Bool, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws { + if let file, let function, let line { + Logger.info("Deleting \(attachmentId) thumbnail? \(thumbnail) from \(file) \(line): \(function)") + } try QueuedBackupAttachmentDownload .filter(Column(QueuedBackupAttachmentDownload.CodingKeys.attachmentRowId) == attachmentId) .filter(Column(QueuedBackupAttachmentDownload.CodingKeys.isThumbnail) == thumbnail) .deleteAll(tx.database) } - public func removeAll(tx: DBWriteTransaction) throws { - try QueuedBackupAttachmentDownload.deleteAll(tx.database) - } - + /// Mark all enqueued & ready media tier fullsize downloads from the table for attachments + /// older than the provided timestamp as ineligible. + /// Applies independently of whether that download is also eligible to download from the + /// transit tier; its assumed that anything on the media tier is stable and if its offloaded to + /// there we don't need to worry about downloading from transit tier before it expires. public func markAllMediaTierFullsizeDownloadsIneligible( olderThan timestamp: UInt64, tx: DBWriteTransaction @@ -307,6 +237,7 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { ) } + /// Marks all ineligible rows as ready (no filtering applied). public func markAllIneligibleReady(tx: DBWriteTransaction) throws { try QueuedBackupAttachmentDownload .filter(Column(QueuedBackupAttachmentDownload.CodingKeys.state) == @@ -319,6 +250,7 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { ) } + /// Marks all ready rows as ineligible (no filtering applied). public func markAllReadyIneligible(tx: DBWriteTransaction) throws { try QueuedBackupAttachmentDownload .filter(Column(QueuedBackupAttachmentDownload.CodingKeys.state) == @@ -331,7 +263,16 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { ) } - public func deleteAllDone(tx: DBWriteTransaction) throws { + /// Remove all done rows (effectively resetting the total byte count). + public func deleteAllDone( + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line + ) throws { + if let file, let function, let line { + Logger.info("Deleting all done rows from \(file) \(line): \(function)") + } if let byteCountSnapshot = try computeEstimatedFinishedFullsizeByteCount(tx: tx) { kvStore.setUInt64(byteCountSnapshot, key: self.downloadCompleteBannerByteCountSnapshotKey, transaction: tx) } @@ -342,6 +283,7 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { .deleteAll(tx.database) } + /// Returns nil, NOT 0, if there are no rows. public func computeEstimatedFinishedFullsizeByteCount(tx: DBReadTransaction) throws -> UInt64? { try UInt64.fetchOne(tx.database, sql: """ SELECT SUM(\(QueuedBackupAttachmentDownload.CodingKeys.estimatedByteCount.rawValue)) @@ -353,6 +295,7 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { ) } + /// Returns nil, NOT 0, if there are no rows. public func computeEstimatedRemainingFullsizeByteCount(tx: DBReadTransaction) throws -> UInt64? { try UInt64.fetchOne(tx.database, sql: """ SELECT SUM(\(QueuedBackupAttachmentDownload.CodingKeys.estimatedByteCount.rawValue)) @@ -374,6 +317,8 @@ public class BackupAttachmentDownloadStoreImpl: BackupAttachmentDownloadStore { return try? self.computeEstimatedFinishedFullsizeByteCount(tx: tx) } + /// Whether the banner for downloads being complete was dismissed. Reset when new downloads + /// are scheduled (when `setTotalPendingDownloadByteCount` is set.) public func getDidDismissDownloadCompleteBanner(tx: DBReadTransaction) -> Bool { return kvStore.getBool(didDismissDownloadCompleteBannerKey, defaultValue: false, transaction: tx) } diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStoreTests.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStoreTests.swift index 9903c4279c..6c26a4fe9d 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStoreTests.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentDownloadStoreTests.swift @@ -13,11 +13,11 @@ class BackupAttachmentDownloadStoreTests: XCTestCase { private var db: InMemoryDB! - private var store: BackupAttachmentDownloadStoreImpl! + private var store: BackupAttachmentDownloadStore! override func setUp() async throws { db = InMemoryDB() - store = BackupAttachmentDownloadStoreImpl() + store = BackupAttachmentDownloadStore() } func testEnqueue() throws { diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadScheduler.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadScheduler.swift index aed91f6a37..c920e46243 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadScheduler.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadScheduler.swift @@ -34,7 +34,10 @@ public protocol BackupAttachmentUploadScheduler { func enqueueUsingHighestPriorityOwnerIfNeeded( _ attachment: Attachment, mode: BackupAttachmentUploadEnqueueMode, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString?, + function: StaticString?, + line: UInt? ) throws /// "Enqueue" an attachment from a backup for upload, if needed and eligible via the provided @@ -48,7 +51,10 @@ public protocol BackupAttachmentUploadScheduler { func enqueueIfNeededWithOwner( _ attachment: Attachment, owner: AttachmentReference.Owner, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString?, + function: StaticString?, + line: UInt? ) throws } @@ -56,12 +62,37 @@ extension BackupAttachmentUploadScheduler { public func enqueueUsingHighestPriorityOwnerIfNeeded( _ attachment: Attachment, - tx: DBWriteTransaction + mode: BackupAttachmentUploadEnqueueMode = .fullsizeAndThumbnailAsNeeded, + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws { try enqueueUsingHighestPriorityOwnerIfNeeded( attachment, - mode: .fullsizeAndThumbnailAsNeeded, - tx: tx + mode: mode, + tx: tx, + file: file, + function: function, + line: line + ) + } + + func enqueueIfNeededWithOwner( + _ attachment: Attachment, + owner: AttachmentReference.Owner, + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line + ) throws { + try enqueueIfNeededWithOwner( + attachment, + owner: owner, + tx: tx, + file: file, + function: function, + line: line ) } } @@ -118,11 +149,17 @@ public class BackupAttachmentUploadSchedulerImpl: BackupAttachmentUploadSchedule public func enqueueUsingHighestPriorityOwnerIfNeeded( _ attachment: Attachment, mode: BackupAttachmentUploadEnqueueMode, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws { // Before we fetch references, check if the attachment is // eligible to begin with. guard let stream = attachment.asStream() else { + if let file, let function, let line { + Logger.info("Skipping enqueue of non-stream \(attachment.id) from \(file) \(line): \(function)") + } return } @@ -133,39 +170,65 @@ public class BackupAttachmentUploadSchedulerImpl: BackupAttachmentUploadSchedule currentUploadEra: currentUploadEra ) guard eligibility.needsUploadFullsize || eligibility.needsUploadThumbnail else { + if let file, let function, let line { + Logger.info("Skipping enqueue of fullsize+thumbnail \(attachment.id) from \(file) \(line): \(function)") + } return } guard let uploadOwnerType = try highestPriorityEligibleOwner(attachment, tx: tx) else { + if let file, let function, let line { + Logger.info("No eligible owners; skipping enqueue of \(attachment.id) from \(file) \(line): \(function)") + } return } - if mode != .thumbnailOnly, eligibility.needsUploadFullsize { - try backupAttachmentUploadStore.enqueue( - stream, - owner: uploadOwnerType, - fullsize: true, - tx: tx - ) + if mode != .thumbnailOnly { + if eligibility.needsUploadFullsize { + try backupAttachmentUploadStore.enqueue( + stream, + owner: uploadOwnerType, + fullsize: true, + tx: tx, + file: file, + function: function, + line: line + ) + } else if let file, let function, let line { + Logger.info("Skipping enqueue of fullsize \(attachment.id) from \(file) \(line): \(function)") + } } - if mode != .fullsizeOnly, eligibility.needsUploadThumbnail { - try backupAttachmentUploadStore.enqueue( - stream, - owner: uploadOwnerType, - fullsize: false, - tx: tx - ) + if mode != .fullsizeOnly { + if eligibility.needsUploadThumbnail { + try backupAttachmentUploadStore.enqueue( + stream, + owner: uploadOwnerType, + fullsize: false, + tx: tx, + file: file, + function: function, + line: line + ) + } else if let file, let function, let line { + Logger.info("Skipping enqueue of thumbnail \(attachment.id) from \(file) \(line): \(function)") + } } } public func enqueueIfNeededWithOwner( _ attachment: Attachment, owner: AttachmentReference.Owner, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws { guard let stream = attachment.asStream() else { + if let file, let function, let line { + Logger.info("Skipping enqueue of non-stream \(attachment.id) from \(file) \(line): \(function)") + } return } @@ -176,6 +239,9 @@ public class BackupAttachmentUploadSchedulerImpl: BackupAttachmentUploadSchedule currentUploadEra: currentUploadEra ) guard eligibility.needsUploadFullsize || eligibility.needsUploadThumbnail else { + if let file, let function, let line { + Logger.info("Skipping enqueue of fullsize+thumbnail \(attachment.id) from \(file) \(line): \(function)") + } return } @@ -184,6 +250,12 @@ public class BackupAttachmentUploadSchedulerImpl: BackupAttachmentUploadSchedule // be enqueued. We only care if this particular owner makes it newly eligible // (or it was eligible both before and now, but the enqueuing it idempotent). guard let uploadOwnerType = self.asEligibleUploadOwnerType(owner, tx: tx) else { + if let file, let function, let line { + Logger.info( + "Passed in owner not eligible (may be eligible with other owners);" + + " skipping enqueue of \(attachment.id) from \(file) \(line): \(function)" + ) + } return } @@ -194,6 +266,8 @@ public class BackupAttachmentUploadSchedulerImpl: BackupAttachmentUploadSchedule fullsize: true, tx: tx ) + } else if let file, let function, let line { + Logger.info("Skipping enqueue of fullsize \(attachment.id) from \(file) \(line): \(function)") } if eligibility.needsUploadThumbnail { try backupAttachmentUploadStore.enqueue( @@ -202,6 +276,8 @@ public class BackupAttachmentUploadSchedulerImpl: BackupAttachmentUploadSchedule fullsize: false, tx: tx ) + } else if let file, let function, let line { + Logger.info("Skipping enqueue of thumbnail \(attachment.id) from \(file) \(line): \(function)") } } @@ -352,7 +428,10 @@ open class BackupAttachmentUploadSchedulerMock: BackupAttachmentUploadScheduler public func enqueueUsingHighestPriorityOwnerIfNeeded( _ attachment: Attachment, mode: BackupAttachmentUploadEnqueueMode, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString?, + function: StaticString?, + line: UInt? ) throws { enqueuedAttachmentIds.append(attachment.id) } @@ -360,7 +439,10 @@ open class BackupAttachmentUploadSchedulerMock: BackupAttachmentUploadScheduler public func enqueueIfNeededWithOwner( _ attachment: Attachment, owner: AttachmentReference.Owner, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString?, + function: StaticString?, + line: UInt? ) throws { // Do nothing } diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStore.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStore.swift index 22fbf0db28..67a040ea3e 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStore.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStore.swift @@ -6,7 +6,9 @@ import Foundation import GRDB -public protocol BackupAttachmentUploadStore { +public class BackupAttachmentUploadStore { + + public init() {} /// "Enqueue" an attachment from a backup for upload. /// @@ -16,56 +18,19 @@ public protocol BackupAttachmentUploadStore { /// both the fullsize and thumbnail as needed, and then call `markUploadDone` once finished. /// Note that the upload operation can (and will) be separately durably enqueued in AttachmentUploadQueue, /// that's fine and doesn't change how this queue works. - func enqueue( - _ attachment: AttachmentStream, - owner: QueuedBackupAttachmentUpload.OwnerType, - fullsize: Bool, - tx: DBWriteTransaction - ) throws - - /// Read the next highest priority uploads off the queue, up to count. - /// Returns an empty array if nothing is left to upload. - /// Does NOT take into account minRetryTimestamp; callers are expected - /// to handle results with timestamps greater than the current time. - func fetchNextUploads( - count: UInt, - isFullsize: Bool, - tx: DBReadTransaction - ) throws -> [QueuedBackupAttachmentUpload] - - func getEnqueuedUpload( - for attachmentId: Attachment.IDType, - fullsize: Bool, - tx: DBReadTransaction - ) throws -> QueuedBackupAttachmentUpload? - - /// Remove the upload from the queue. Should be called once uploaded (or permanently failed). - /// - /// - Important - /// Once all `QueuedBackupAttachmentUpload` records are marked done, a SQL - /// trigger (`__BackupAttachmentUploadQueue_au`) will wipe them all. This - /// mitigates potential issues around long-completed upload records being - /// counted towards future progress. - /// - /// - returns the removed record, if any. - @discardableResult - func markUploadDone( - for attachmentId: Attachment.IDType, - fullsize: Bool, - tx: DBWriteTransaction - ) throws -> QueuedBackupAttachmentUpload? -} - -public class BackupAttachmentUploadStoreImpl: BackupAttachmentUploadStore { - - public init() {} - public func enqueue( _ attachment: AttachmentStream, owner: QueuedBackupAttachmentUpload.OwnerType, fullsize: Bool, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws { + if let file, let function, let line { + Logger.info("Enqueuing \(attachment.id) fullsize? \(fullsize) from \(file) \(line): \(function)") + } + let db = tx.database let unencryptedSize: UInt32 @@ -109,6 +74,10 @@ public class BackupAttachmentUploadStoreImpl: BackupAttachmentUploadStore { } } + /// Read the next highest priority uploads off the queue, up to count. + /// Returns an empty array if nothing is left to upload. + /// Does NOT take into account minRetryTimestamp; callers are expected + /// to handle results with timestamps greater than the current time. public func fetchNextUploads( count: UInt, isFullsize: Bool, @@ -144,12 +113,27 @@ public class BackupAttachmentUploadStoreImpl: BackupAttachmentUploadStore { .fetchOne(tx.database) } + /// Remove the upload from the queue. Should be called once uploaded (or permanently failed). + /// + /// - Important + /// Once all `QueuedBackupAttachmentUpload` records are marked done, a SQL + /// trigger (`__BackupAttachmentUploadQueue_au`) will wipe them all. This + /// mitigates potential issues around long-completed upload records being + /// counted towards future progress. + /// + /// - returns the removed record, if any. @discardableResult public func markUploadDone( for attachmentId: Attachment.IDType, fullsize: Bool, - tx: DBWriteTransaction + tx: DBWriteTransaction, + file: StaticString? = #file, + function: StaticString? = #function, + line: UInt? = #line ) throws -> QueuedBackupAttachmentUpload? { + if let file, let function, let line { + Logger.info("Marking \(attachmentId) done. fullsize? \(fullsize) from \(file) \(line): \(function)") + } var record = try QueuedBackupAttachmentUpload .filter(Column(QueuedBackupAttachmentUpload.CodingKeys.attachmentRowId) == attachmentId) .filter(Column(QueuedBackupAttachmentUpload.CodingKeys.isFullsize) == fullsize) diff --git a/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStoreTests.swift b/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStoreTests.swift index d339a2aadc..77c6399a68 100644 --- a/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStoreTests.swift +++ b/SignalServiceKit/Backups/Attachments/BackupAttachmentUploadStoreTests.swift @@ -13,11 +13,11 @@ class BackupAttachmentUploadStoreTests: XCTestCase { private var db: InMemoryDB! - private var store: BackupAttachmentUploadStoreImpl! + private var store: BackupAttachmentUploadStore! override func setUp() async throws { db = InMemoryDB() - store = BackupAttachmentUploadStoreImpl() + store = BackupAttachmentUploadStore() } func testEnqueue() throws { diff --git a/SignalServiceKit/Backups/Attachments/BackupListMediaManagerTests.swift b/SignalServiceKit/Backups/Attachments/BackupListMediaManagerTests.swift index 943e116988..1052d7e505 100644 --- a/SignalServiceKit/Backups/Attachments/BackupListMediaManagerTests.swift +++ b/SignalServiceKit/Backups/Attachments/BackupListMediaManagerTests.swift @@ -13,9 +13,9 @@ public class BackupListMediaManagerTests { let accountKeyStore: AccountKeyStore let attachmentStore = AttachmentStoreImpl() - let backupAttachmentDownloadStore = BackupAttachmentDownloadStoreImpl() + let backupAttachmentDownloadStore = BackupAttachmentDownloadStore() let backupAttachmentUploadScheduler = BackupAttachmentUploadSchedulerMock() - let backupAttachmentUploadStore = BackupAttachmentUploadStoreImpl() + let backupAttachmentUploadStore = BackupAttachmentUploadStore() fileprivate let backupRequestManager = BackupRequestManagerMock() let backupSettingsStore = BackupSettingsStore() let db = InMemoryDB() diff --git a/SignalServiceKit/Backups/Settings/BackupPlanManager.swift b/SignalServiceKit/Backups/Settings/BackupPlanManager.swift index b42e63d765..0a41b411e9 100644 --- a/SignalServiceKit/Backups/Settings/BackupPlanManager.swift +++ b/SignalServiceKit/Backups/Settings/BackupPlanManager.swift @@ -154,12 +154,14 @@ class BackupPlanManagerImpl: BackupPlanManager { // While in free tier, we may have been continuing downloads // from when you were previously paid tier. But that was nice // to have; now that we're disabling backups cancel them all. + Logger.info("Configuring downloads for disabling free backups") try backupAttachmentDownloadStore.markAllReadyIneligible(tx: tx) try backupAttachmentDownloadStore.deleteAllDone(tx: tx) case let (.paid(optimizeLocalStorage), .disabling), let (.paidExpiringSoon(optimizeLocalStorage), .disabling), let (.paidAsTester(optimizeLocalStorage), .disabling): + Logger.info("Configuring downloads for disabling paid backups") try backupAttachmentDownloadStore.deleteAllDone(tx: tx) // Unsuspend; this is the user opt-in to trigger downloads. backupSettingsStore.setIsBackupDownloadQueueSuspended(false, tx: tx) @@ -240,6 +242,7 @@ class BackupPlanManagerImpl: BackupPlanManager { } private func configureDownloadsForDisablingBackups(tx: DBWriteTransaction) throws { + Logger.info("Configuring downloads for disabled backups") // When we disable, we mark everything ineligible and delete all // done rows. If we ever re-enable, we will mark those rows // ready again. @@ -251,6 +254,7 @@ class BackupPlanManagerImpl: BackupPlanManager { } private func configureDownloadsForDidEnableOptimizeStorage(tx: DBWriteTransaction) throws { + Logger.info("Configuring downloads for optimize enabled") // When we turn on optimization, make all media tier fullsize downloads // from the queue that are past the optimization threshold ineligible. // If we downloaded them we'd offload them immediately anyway. @@ -270,6 +274,7 @@ class BackupPlanManagerImpl: BackupPlanManager { } private func configureDownloadsForDidDisableOptimizeStorage(tx: DBWriteTransaction) throws { + Logger.info("Configuring downloads for optimize disabled") // When we turn _off_ optimization, we want to make ready all the media tier downloads, // but suspend the queue so we don't immediately start downloading. try backupAttachmentDownloadStore.markAllIneligibleReady(tx: tx) diff --git a/SignalServiceKit/Environment/AppSetup.swift b/SignalServiceKit/Environment/AppSetup.swift index d8dfa73204..51a48fe741 100644 --- a/SignalServiceKit/Environment/AppSetup.swift +++ b/SignalServiceKit/Environment/AppSetup.swift @@ -430,14 +430,14 @@ extension AppSetup.GlobalsContinuation { twoFAManager: SVR2.Wrappers.OWS2FAManager(ows2FAManager) ) - let backupAttachmentDownloadStore = BackupAttachmentDownloadStoreImpl() + let backupAttachmentDownloadStore = BackupAttachmentDownloadStore() let backupAttachmentUploadEraStore = BackupAttachmentUploadEraStore() let backupAttachmentUploadProgress = BackupAttachmentUploadProgressImpl( attachmentStore: attachmentStore, backupSettingsStore: backupSettingsStore, db: db, ) - let backupAttachmentUploadStore = BackupAttachmentUploadStoreImpl() + let backupAttachmentUploadStore = BackupAttachmentUploadStore() let backupCDNCredentialStore = BackupCDNCredentialStore() let backupIdService = BackupIdServiceImpl(