Added a bunch of logs to the Jobs to better track the startup state

pull/751/head
Morgan Pretty 1 year ago
parent 3f362a71f3
commit 44824c8127

@ -26,6 +26,7 @@ public enum SyncPushTokensJob: JobExecutor {
(UserDefaults.sharedLokiProject?[.isMainAppActive]).defaulting(to: false),
Identity.userCompletedRequiredOnboarding()
else {
SNLog("[SyncPushTokensJob] Deferred due to incomplete registration")
deferred(job) // Don't need to do anything if it's not the main app
return
}
@ -62,6 +63,7 @@ public enum SyncPushTokensJob: JobExecutor {
!UIApplication.shared.isRegisteredForRemoteNotifications ||
Date().timeIntervalSince(lastPushNotificationSync) >= SyncPushTokensJob.maxFrequency
else {
SNLog("[SyncPushTokensJob] Deferred due to Fast Mode disabled or recent-enough registration")
deferred(job) // Don't need to do anything if push notifications are already registered
return
}
@ -86,9 +88,12 @@ public enum SyncPushTokensJob: JobExecutor {
.handleEvents(
receiveCompletion: { result in
switch result {
case .failure: break
case .failure(let error):
SNLog("[SyncPushTokensJob] Failed to register due to error: \(error)")
case .finished:
Logger.warn("Recording push tokens locally. pushToken: \(redact(pushToken)), voipToken: \(redact(voipToken))")
SNLog("[SyncPushTokensJob] Completed")
Storage.shared.write { db in
db[.lastRecordedPushToken] = pushToken

@ -31,6 +31,7 @@ public enum AttachmentUploadJob: JobExecutor {
return (attachment, try OpenGroup.fetchOne(db, id: threadId))
})
else {
SNLog("[AttachmentUploadJob] Failed due to missing details")
failure(job, JobRunnerError.missingRequiredDetails, true)
return
}
@ -38,12 +39,14 @@ public enum AttachmentUploadJob: JobExecutor {
// If the original interaction no longer exists then don't bother uploading the attachment (ie. the
// message was deleted before it even got sent)
guard Storage.shared.read({ db in try Interaction.exists(db, id: interactionId) }) == true else {
SNLog("[AttachmentUploadJob] Failed due to missing interaction")
failure(job, StorageError.objectNotFound, true)
return
}
// If the attachment is still pending download the hold off on running this job
guard attachment.state != .pendingDownload && attachment.state != .downloading else {
SNLog("[AttachmentUploadJob] Deferred as attachment is still being downloaded")
deferred(job)
return
}
@ -98,6 +101,7 @@ public enum AttachmentUploadJob: JobExecutor {
)
}
SNLog("[AttachmentUploadJob] Failed due to error: \(error)")
failure(job, error, false)
case .finished: success(job, false)

@ -49,6 +49,7 @@ public enum ConfigurationSyncJob: JobExecutor {
// If there are no pending changes then the job can just complete (next time something
// is updated we want to try and run immediately so don't scuedule another run in this case)
guard !pendingConfigChanges.isEmpty else {
SNLog("[ConfigurationSyncJob] Completed with no pending changes")
success(job, true)
return
}
@ -118,8 +119,10 @@ public enum ConfigurationSyncJob: JobExecutor {
.sinkUntilComplete(
receiveCompletion: { result in
switch result {
case .finished: break
case .failure(let error): failure(job, error, false)
case .finished: SNLog("[ConfigurationSyncJob] Completed")
case .failure(let error):
SNLog("[ConfigurationSyncJob] Failed due to error: \(error)")
failure(job, error, false)
}
},
receiveValue: { (configDumps: [ConfigDump]) in

@ -20,9 +20,10 @@ public enum DisappearingMessagesJob: JobExecutor {
// The 'backgroundTask' gets captured and cleared within the 'completion' block
let timestampNowMs: TimeInterval = TimeInterval(SnodeAPI.currentOffsetTimestampMs())
var backgroundTask: OWSBackgroundTask? = OWSBackgroundTask(label: #function)
var numDeleted: Int = -1
let updatedJob: Job? = Storage.shared.write { db in
_ = try Interaction
numDeleted = try Interaction
.filter(Interaction.Columns.expiresStartedAtMs != nil)
.filter((Interaction.Columns.expiresStartedAtMs + (Interaction.Columns.expiresInSeconds * 1000)) <= timestampNowMs)
.deleteAll(db)
@ -35,6 +36,7 @@ public enum DisappearingMessagesJob: JobExecutor {
.saved(db)
}
SNLog("[DisappearingMessagesJob] Deleted \(numDeleted) expired messages")
success(updatedJob ?? job, false)
// The 'if' is only there to prevent the "variable never read" warning from showing
@ -58,12 +60,16 @@ public extension DisappearingMessagesJob {
.asRequest(of: Double.self)
.fetchOne(db)
guard let nextExpirationTimestampMs: Double = nextExpirationTimestampMs else { return nil }
guard let nextExpirationTimestampMs: Double = nextExpirationTimestampMs else {
SNLog("[DisappearingMessagesJob] No remaining expiring messages")
return nil
}
/// The `expiresStartedAtMs` timestamp is now based on the `SnodeAPI.currentOffsetTimestampMs()` value
/// so we need to make sure offset the `nextRunTimestamp` accordingly to ensure it runs at the correct local time
let clockOffsetMs: Int64 = SnodeAPI.clockOffsetMs.wrappedValue
SNLog("[DisappearingMessagesJob] Scheduled future message expiration")
return try? Job
.filter(Job.Columns.variant == Job.Variant.disappearingMessages)
.fetchOne(db)?
@ -103,7 +109,7 @@ public extension DisappearingMessagesJob {
return updateNextRunIfNeeded(db, interactionIds: [interactionId], startedAtMs: startedAtMs)
}
catch {
SNLog("Failed to update the expiring messages timer on an interaction")
SNLog("[DisappearingMessagesJob] Failed to update the expiring messages timer on an interaction")
return nil
}
}

@ -17,15 +17,16 @@ public enum FailedAttachmentDownloadsJob: JobExecutor {
failure: @escaping (Job, Error?, Bool) -> (),
deferred: @escaping (Job) -> ()
) {
var changeCount: Int = -1
// Update all 'sending' message states to 'failed'
Storage.shared.write { db in
let changeCount: Int = try Attachment
changeCount = try Attachment
.filter(Attachment.Columns.state == Attachment.State.downloading)
.updateAll(db, Attachment.Columns.state.set(to: Attachment.State.failedDownload))
Logger.debug("Marked \(changeCount) attachments as failed")
}
SNLog("[FailedAttachmentDownloadsJob] Marked \(changeCount) attachments as failed")
success(job, false)
}
}

@ -16,6 +16,9 @@ public enum FailedMessageSendsJob: JobExecutor {
failure: @escaping (Job, Error?, Bool) -> (),
deferred: @escaping (Job) -> ()
) {
var changeCount: Int = -1
var attachmentChangeCount: Int = -1
// Update all 'sending' message states to 'failed'
Storage.shared.write { db in
let sendChangeCount: Int = try RecipientState
@ -24,14 +27,13 @@ public enum FailedMessageSendsJob: JobExecutor {
let syncChangeCount: Int = try RecipientState
.filter(RecipientState.Columns.state == RecipientState.State.syncing)
.updateAll(db, RecipientState.Columns.state.set(to: RecipientState.State.failedToSync))
let attachmentChangeCount: Int = try Attachment
attachmentChangeCount = try Attachment
.filter(Attachment.Columns.state == Attachment.State.uploading)
.updateAll(db, Attachment.Columns.state.set(to: Attachment.State.failedUpload))
let changeCount: Int = (sendChangeCount + syncChangeCount)
SNLog("Marked \(changeCount) message\(changeCount == 1 ? "" : "s") as failed (\(attachmentChangeCount) upload\(attachmentChangeCount == 1 ? "" : "s") cancelled)")
changeCount = (sendChangeCount + syncChangeCount)
}
SNLog("[FailedMessageSendsJob] Marked \(changeCount) message\(changeCount == 1 ? "" : "s") as failed (\(attachmentChangeCount) upload\(attachmentChangeCount == 1 ? "" : "s") cancelled)")
success(job, false)
}
}

@ -25,6 +25,7 @@ public enum GroupLeavingJob: JobExecutor {
let threadId: String = job.threadId,
let interactionId: Int64 = job.interactionId
else {
SNLog("[GroupLeavingJob] Failed due to missing details")
failure(job, JobRunnerError.missingRequiredDetails, true)
return
}
@ -34,10 +35,11 @@ public enum GroupLeavingJob: JobExecutor {
Storage.shared
.writePublisher { db in
guard (try? SessionThread.exists(db, id: threadId)) == true else {
SNLog("Can't update nonexistent closed group.")
SNLog("[GroupLeavingJob] Failed due to non-existent group conversation")
throw MessageSenderError.noThread
}
guard (try? ClosedGroup.exists(db, id: threadId)) == true else {
SNLog("[GroupLeavingJob] Failed due to non-existent group")
throw MessageSenderError.invalidClosedGroupUpdate
}

@ -23,6 +23,7 @@ public enum MessageSendJob: JobExecutor {
let detailsData: Data = job.details,
let details: Details = try? JSONDecoder().decode(Details.self, from: detailsData)
else {
SNLog("[MessageSendJob] Failing due to missing details")
failure(job, JobRunnerError.missingRequiredDetails, true)
return
}
@ -45,6 +46,7 @@ public enum MessageSendJob: JobExecutor {
let jobId: Int64 = job.id,
let interactionId: Int64 = job.interactionId
else {
SNLog("[MessageSendJob] Failing due to missing details")
failure(job, JobRunnerError.missingRequiredDetails, true)
return
}
@ -52,6 +54,7 @@ public enum MessageSendJob: JobExecutor {
// If the original interaction no longer exists then don't bother sending the message (ie. the
// message was deleted before it even got sent)
guard Storage.shared.read({ db in try Interaction.exists(db, id: interactionId) }) == true else {
SNLog("[MessageSendJob] Failing due to missing interaction")
failure(job, StorageError.objectNotFound, true)
return
}
@ -150,12 +153,14 @@ public enum MessageSendJob: JobExecutor {
// Note: If we have gotten to this point then any dependant attachment upload
// jobs will have permanently failed so this message send should also do so
guard attachmentState?.shouldFail == false else {
SNLog("[MessageSendJob] Failing due to failed attachment upload")
failure(job, AttachmentError.notUploaded, true)
return
}
// Defer the job if we found incomplete uploads
guard attachmentState?.shouldDefer == false else {
SNLog("[MessageSendJob] Deferring pending attachment uploads")
deferred(job)
return
}
@ -190,7 +195,7 @@ public enum MessageSendJob: JobExecutor {
switch result {
case .finished: success(job, false)
case .failure(let error):
SNLog("Couldn't send message due to error: \(error).")
SNLog("[MessageSendJob] Couldn't send message due to error: \(error).")
switch error {
case let senderError as MessageSenderError where !senderError.isRetryable:
@ -200,11 +205,11 @@ public enum MessageSendJob: JobExecutor {
failure(job, error, true)
case SnodeAPIError.clockOutOfSync:
SNLog("\(originalSentTimestamp != nil ? "Permanently Failing" : "Failing") to send \(type(of: details.message)) due to clock out of sync issue.")
SNLog("[MessageSendJob] \(originalSentTimestamp != nil ? "Permanently Failing" : "Failing") to send \(type(of: details.message)) due to clock out of sync issue.")
failure(job, error, (originalSentTimestamp != nil))
default:
SNLog("Failed to send \(type(of: details.message)).")
SNLog("[MessageSendJob] Failed to send \(type(of: details.message)).")
if details.message is VisibleMessage {
guard

@ -21,6 +21,7 @@ public enum NotifyPushServerJob: JobExecutor {
let detailsData: Data = job.details,
let details: Details = try? JSONDecoder().decode(Details.self, from: detailsData)
else {
SNLog("[NotifyPushServerJob] Failing due to missing details")
failure(job, JobRunnerError.missingRequiredDetails, true)
return
}

@ -47,8 +47,13 @@ public enum RetrieveDefaultOpenGroupRoomsJob: JobExecutor {
.sinkUntilComplete(
receiveCompletion: { result in
switch result {
case .finished: success(job, false)
case .failure(let error): failure(job, error, false)
case .finished:
SNLog("[RetrieveDefaultOpenGroupRoomsJob] Successfully retrieved default Community rooms")
success(job, false)
case .failure(let error):
SNLog("[RetrieveDefaultOpenGroupRoomsJob] Failed to get default Community rooms")
failure(job, error, false)
}
}
)

@ -55,10 +55,14 @@ public enum UpdateProfilePictureJob: JobExecutor {
// issue as it will write to the database and this closure is already called within
// another database write
queue.async {
SNLog("[UpdateProfilePictureJob] Profile successfully updated")
success(job, false)
}
},
failure: { error in failure(job, error, false) }
failure: { error in
SNLog("[UpdateProfilePictureJob] Failed to update profile")
failure(job, error, false)
}
)
}
}

@ -23,6 +23,7 @@ public enum GetSnodePoolJob: JobExecutor {
// to block if we have no Snode pool and prevent other jobs from failing but avoids having to
// wait if we already have a potentially valid snode pool
guard !SnodeAPI.hasCachedSnodesInclusingExpired() else {
SNLog("[GetSnodePoolJob] Has valid cached pool, running async instead")
SnodeAPI
.getSnodePool()
.subscribe(on: DispatchQueue.global(qos: .default))
@ -40,8 +41,13 @@ public enum GetSnodePoolJob: JobExecutor {
.sinkUntilComplete(
receiveCompletion: { result in
switch result {
case .finished: success(job, false)
case .failure(let error): failure(job, error, false)
case .finished:
SNLog("[GetSnodePoolJob] Completed")
success(job, false)
case .failure(let error):
SNLog("[GetSnodePoolJob] Failed due to error: \(error)")
failure(job, error, false)
}
}
)

Loading…
Cancel
Save