Signal/Android
1
0
Fork 0
mirror of https://github.com/signalapp/Signal-Android.git synced 2026-02-15 07:28:30 +00:00
Code Issues Packages Projects Releases Wiki Activity

Improve reconciliation logging and handling.

Browse Source
This commit is contained in:
Greyson Parrelli
2026-01-14 13:53:57 -05:00
parent 08beb7ff43
commit 43607edc1c
9 changed files with 199 additions and 86 deletions
Download Patch File Download Diff File Expand all files Collapse all files

12
app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt
View File

@@ -3426,7 +3426,7 @@ class AttachmentTable(
}
}
fun debugGetAttachmentDataForMediaIds(mediaIds: Collection<MediaId>): List<ArchiveAttachmentMatch> {
fun getAttachmentDataForMediaIds(mediaIds: Collection<MediaId>): List<ArchiveAttachmentMatch> {
if (mediaIds.isEmpty()) return emptyList()
val mediaIdByteStrings = mediaIds.map { it.value.toByteString() }.toSet()
@@ -3458,19 +3458,22 @@ class AttachmentTable(
if (mediaId in mediaIdByteStrings) {
val attachment = getAttachment(cursor)
val messageRecord = messages.getMessageRecordOrNull(messageId)
found.add(ArchiveAttachmentMatch(attachment = attachment, isThumbnail = false, isWallpaper = messageId == WALLPAPER_MESSAGE_ID, messageRecord = messageRecord))
found.add(ArchiveAttachmentMatch(attachment = attachment, mediaId = MediaId(mediaId.toByteArray()), isThumbnail = false, isWallpaper = messageId == WALLPAPER_MESSAGE_ID, messageRecord = messageRecord))
}
if (mediaIdThumbnail in mediaIdByteStrings) {
val attachment = getAttachment(cursor)
val messageRecord = messages.getMessageRecordOrNull(messageId)
found.add(ArchiveAttachmentMatch(attachment = attachment, isThumbnail = true, isWallpaper = messageId == WALLPAPER_MESSAGE_ID, messageRecord = messageRecord))
found.add(ArchiveAttachmentMatch(attachment = attachment, mediaId = MediaId(mediaIdThumbnail.toByteArray()), isThumbnail = true, isWallpaper = messageId == WALLPAPER_MESSAGE_ID, messageRecord = messageRecord))
}
}
return found
}
/**
* Given a set of media objects, this will return all of the items in the set that could not be found locally.
*/
fun getMediaObjectsThatCantBeFound(objects: Set<ArchivedMediaObject>): Set<ArchivedMediaObject> {
if (objects.isEmpty()) {
return emptySet()
@@ -4096,12 +4099,13 @@ class AttachmentTable(
data class ArchiveAttachmentMatch(
val attachment: DatabaseAttachment,
val mediaId: MediaId,
val isThumbnail: Boolean,
val isWallpaper: Boolean,
val messageRecord: MessageRecord?
) {
override fun toString(): String {
return "attachmentId=${attachment.attachmentId}, messageId=${attachment.mmsId}, isThumbnail=$isThumbnail, contentType=${attachment.contentType}, quote=${attachment.quote}, wallpaper=$isWallpaper, transferState=${attachment.transferState}, archiveTransferState=${attachment.archiveTransferState}, hasData=${attachment.hasData}, dateSent=${messageRecord?.dateSent}, messageType=${messageRecord?.type}, messageFrom=${messageRecord?.fromRecipient?.id}, messageTo=${messageRecord?.toRecipient?.id}, expiresIn=${messageRecord?.expiresIn}, expireStarted=${messageRecord?.expireStarted}"
return "attachmentId=${attachment.attachmentId}, mediaId=$mediaId, messageId=${attachment.mmsId}, isThumbnail=$isThumbnail, contentType=${attachment.contentType}, quote=${attachment.quote}, wallpaper=$isWallpaper, transferState=${attachment.transferState}, archiveTransferState=${attachment.archiveTransferState}, hasData=${attachment.hasData}, dateSent=${messageRecord?.dateSent}, messageType=${messageRecord?.type}, messageFrom=${messageRecord?.fromRecipient?.id}, messageTo=${messageRecord?.toRecipient?.id}, expiresIn=${messageRecord?.expiresIn}, expireStarted=${messageRecord?.expireStarted}"
}
}
}

64
app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentReconciliationJob.kt
View File

@@ -14,6 +14,7 @@ import androidx.core.app.NotificationCompat
import androidx.core.app.NotificationManagerCompat
import androidx.core.content.ContextCompat
import org.signal.core.models.backup.MediaId
import org.signal.core.util.Base64.decodeBase64
import org.signal.core.util.EventTimer
import org.signal.core.util.PendingIntentFlags
import org.signal.core.util.Stopwatch
@@ -23,6 +24,7 @@ import org.signal.core.util.nullIfBlank
import org.thoughtcrime.securesms.R
import org.thoughtcrime.securesms.backup.v2.ArchivedMediaObject
import org.thoughtcrime.securesms.backup.v2.BackupRepository
import org.thoughtcrime.securesms.database.AttachmentTable
import org.thoughtcrime.securesms.database.BackupMediaSnapshotTable
import org.thoughtcrime.securesms.database.SignalDatabase
import org.thoughtcrime.securesms.dependencies.AppDependencies
@@ -34,6 +36,7 @@ import org.thoughtcrime.securesms.logsubmit.SubmitDebugLogActivity
import org.thoughtcrime.securesms.notifications.NotificationChannels
import org.thoughtcrime.securesms.notifications.NotificationIds
import org.thoughtcrime.securesms.util.RemoteConfig
import org.thoughtcrime.securesms.wallpaper.WallpaperStorage
import org.whispersystems.signalservice.api.NetworkResult
import org.whispersystems.signalservice.api.archive.ArchiveGetMediaItemsResponse
import kotlin.time.Duration.Companion.days
@@ -216,23 +219,27 @@ class ArchiveAttachmentReconciliationJob private constructor(
mediaIdsThatNeedUpload += MediaId(entry.mediaId)
}
val mediaIdLog = if (internalUser) "[${MediaId(entry.mediaId)}]" else ""
if (entry.isThumbnail) {
thumbnailMismatchFound = true
val wasReset = SignalDatabase.attachments.resetArchiveThumbnailTransferStateByPlaintextHashAndRemoteKeyIfNecessary(entry.plaintextHash, entry.remoteKey)
if (wasReset) {
Log.w(TAG, "[Thumbnail]$mediaIdLog Reset transfer state by hash/key.", true)
newBackupJobRequired = true
bookkeepingErrorCount++
} else {
Log.w(TAG, "[Thumbnail] Did not need to reset the transfer state by hash/key because the thumbnail either no longer exists or the upload is already in-progress.", true)
Log.i(TAG, "[Thumbnail]$mediaIdLog Did not need to reset the transfer state by hash/key because the thumbnail either no longer exists or the upload is already in-progress.", true)
}
} else {
fullSizeMismatchFound = true
val wasReset = SignalDatabase.attachments.resetArchiveTransferStateByPlaintextHashAndRemoteKeyIfNecessary(entry.plaintextHash, entry.remoteKey)
if (wasReset) {
Log.w(TAG, "[Fullsize]$mediaIdLog Reset transfer state by hash/key.", true)
newBackupJobRequired = true
bookkeepingErrorCount++
} else {
Log.w(TAG, "[Fullsize] Did not need to reset the transfer state by hash/key because the attachment either no longer exists or the upload is already in-progress.", true)
Log.i(TAG, "[Fullsize]$mediaIdLog Did not need to reset the transfer state by hash/key because the attachment either no longer exists or the upload is already in-progress.", true)
}
}
}
@@ -248,12 +255,12 @@ class ArchiveAttachmentReconciliationJob private constructor(
stopwatch.split("stats-after")
if (internalUser && mediaIdsThatNeedUpload.isNotEmpty()) {
Log.w(TAG, "Starting internal-only lookup of matching attachments. May take a while!", true)
Log.w(TAG, "Starting internal-only lookup of matching attachments. Looking up (showing ${mediaIdsThatNeedUpload.size.coerceAtMost(250)}/${mediaIdsThatNeedUpload.size}): ${mediaIdsThatNeedUpload.take(250).joinToString()}", true)
val matchingAttachments = SignalDatabase.attachments.debugGetAttachmentDataForMediaIds(mediaIdsThatNeedUpload)
Log.w(TAG, "Found ${matchingAttachments.size} out of the ${mediaIdsThatNeedUpload.size} attachments we looked up (capped lookups to 10k).", true)
val matchingAttachments = SignalDatabase.attachments.getAttachmentDataForMediaIds(mediaIdsThatNeedUpload)
Log.w(TAG, "Found ${matchingAttachments.size} out of the ${mediaIdsThatNeedUpload.size} attachments we looked up (limiting log input to the first 250).", true)
matchingAttachments.forEach { match ->
matchingAttachments.take(250).forEach { match ->
if (match.isThumbnail) {
val thumbnailTransferState = SignalDatabase.attachments.getArchiveThumbnailTransferState(match.attachment.attachmentId)
Log.w(TAG, "[Thumbnail] Needed Upload: $match, archiveThumbnailTransferState: $thumbnailTransferState", true)
@@ -362,28 +369,51 @@ class ArchiveAttachmentReconciliationJob private constructor(
* @return A non-successful [Result] in the case of failure, otherwise null for success.
*/
private fun validateAndDeleteFromRemote(deletes: Set<ArchivedMediaObject>): Result? {
if (RemoteConfig.internalUser) {
val mediaIds = deletes.take(250).map { MediaId(it.mediaId.decodeBase64()!!) }
Log.w(TAG, "Want to delete (showing ${mediaIds.size}/${deletes.size}): ${mediaIds.take(250).joinToString() }")
}
val stopwatch = Stopwatch("remote-delete")
val validatedDeletes = SignalDatabase.attachments.getMediaObjectsThatCantBeFound(deletes)
Log.d(TAG, "Found that ${validatedDeletes.size}/${deletes.size} requested remote deletes were valid based on current attachment table state.", true)
val validatedDeletes: MutableSet<ArchivedMediaObject> = SignalDatabase.attachments.getMediaObjectsThatCantBeFound(deletes).toMutableSet()
Log.d(TAG, "Found that ${validatedDeletes.size}/${deletes.size} requested remote deletes have no data at all locally, and are therefore safe to delete.", true)
stopwatch.split("validate")
// Fix archive state for attachments that are found locally but weren't in the latest snapshot.
// This can happen when restoring from a backup that was made before archive upload completed. The files would be uploaded, but no CDN info would be in the backup.
val foundLocally = deletes - validatedDeletes
if (foundLocally.isNotEmpty()) {
val fixedCount = SignalDatabase.attachments.setArchiveFinishedForMatchingMediaObjects(foundLocally)
Log.w(TAG, "Starting lookup of attachments that we thought we could delete remotely, but still had record of locally. It may be that we can actually delete them.", true)
val matches = SignalDatabase.attachments.getAttachmentDataForMediaIds(foundLocally.map { MediaId(it.mediaId) })
for (match in matches) {
if (match.messageRecord?.fromRecipient != null && match.messageRecord.fromRecipient.id == SignalStore.releaseChannel.releaseChannelRecipientId) {
Log.i(TAG, "[${match.attachment.attachmentId}] Attachment is from the release channel. We can delete it remotely.")
val stringMediaId = match.mediaId.encode()
validatedDeletes += foundLocally.first { it.mediaId == stringMediaId }
} else if (match.attachment.mmsId == AttachmentTable.WALLPAPER_MESSAGE_ID && match.isThumbnail) {
Log.i(TAG, "[${match.attachment.attachmentId}] Attachment is a wallpaper thumbnail. We can delete it remotely.")
val stringMediaId = match.mediaId.encode()
validatedDeletes += foundLocally.first { it.mediaId == stringMediaId }
} else if (match.attachment.mmsId == AttachmentTable.WALLPAPER_MESSAGE_ID && !WallpaperStorage.isWallpaperUriUsed(match.attachment.uri!!)) {
Log.i(TAG, "[${match.attachment.attachmentId}] Attachment is an unused wallpaper. We can delete it remotely. We'll also delete it locally.")
val stringMediaId = match.mediaId.encode()
validatedDeletes += foundLocally.first { it.mediaId == stringMediaId }
SignalDatabase.attachments.deleteAttachment(match.attachment.attachmentId)
} else if (RemoteConfig.internalUser) {
Log.w(TAG, "[PreventedDelete] $match")
}
}
stopwatch.split("lookup")
}
val updatedFoundLocally = deletes - validatedDeletes
if (updatedFoundLocally.isNotEmpty()) {
val fixedCount = SignalDatabase.attachments.setArchiveFinishedForMatchingMediaObjects(updatedFoundLocally)
if (fixedCount > 0) {
Log.i(TAG, "Fixed archive transfer state for $fixedCount attachment groups that were found on CDN but had incorrect local state.", true)
}
}
stopwatch.split("fix-state")
if (RemoteConfig.internalUser && foundLocally.isNotEmpty()) {
Log.w(TAG, "Starting internal-only lookup of attachments that we thought we could delete remotely, but still had record of locally.", true)
val matches = SignalDatabase.attachments.debugGetAttachmentDataForMediaIds(foundLocally.map { MediaId(it.mediaId) })
for (match in matches) {
Log.w(TAG, "[PreventedDelete] $match")
}
}
if (validatedDeletes.isEmpty()) {

8
app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveCommitAttachmentDeletesJob.kt
View File

@@ -5,6 +5,8 @@
package org.thoughtcrime.securesms.jobs
import org.signal.core.models.backup.MediaId
import org.signal.core.util.Base64
import org.signal.core.util.logging.Log
import org.thoughtcrime.securesms.backup.v2.ArchivedMediaObject
import org.thoughtcrime.securesms.backup.v2.BackupRepository
@@ -12,6 +14,7 @@ import org.thoughtcrime.securesms.database.BackupMediaSnapshotTable
import org.thoughtcrime.securesms.database.SignalDatabase
import org.thoughtcrime.securesms.jobmanager.Job
import org.thoughtcrime.securesms.keyvalue.SignalStore
import org.thoughtcrime.securesms.util.RemoteConfig
import org.whispersystems.signalservice.api.NetworkResult
import java.lang.RuntimeException
import kotlin.time.Duration.Companion.days
@@ -38,6 +41,11 @@ class ArchiveCommitAttachmentDeletesJob private constructor(parameters: Paramete
* @return Null if successful, or a [Result] indicating the failure.
*/
fun deleteMediaObjectsFromCdn(tag: String, attachmentsToDelete: Set<ArchivedMediaObject>, backoffGenerator: () -> Long, cancellationSignal: () -> Boolean): Result? {
if (RemoteConfig.internalUser) {
val mediaIds = attachmentsToDelete.take(250).map { MediaId(Base64.decode(it.mediaId)) }
Log.w(TAG, "Deleting MediaIds (showing ${mediaIds.size}/${attachmentsToDelete.size}): ${mediaIds.joinToString() }")
}
attachmentsToDelete.chunked(REMOTE_DELETE_BATCH_SIZE).forEach { chunk ->
if (cancellationSignal()) {
Log.w(tag, "Job cancelled while deleting attachments from the CDN.", true)

56
app/src/main/java/org/thoughtcrime/securesms/jobs/CopyAttachmentToArchiveJob.kt
View File

@@ -1,6 +1,8 @@
package org.thoughtcrime.securesms.jobs
import kotlinx.coroutines.runBlocking
import org.signal.core.models.backup.MediaName
import org.signal.core.util.Base64.decodeBase64
import org.signal.core.util.ByteSize
import org.signal.core.util.bytes
import org.signal.core.util.logging.Log
@@ -21,6 +23,7 @@ import org.thoughtcrime.securesms.jobmanager.impl.NoRemoteArchiveGarbageCollecti
import org.thoughtcrime.securesms.jobs.protos.CopyAttachmentToArchiveJobData
import org.thoughtcrime.securesms.keyvalue.SignalStore
import org.thoughtcrime.securesms.util.MediaUtil
import org.thoughtcrime.securesms.util.RemoteConfig
import org.whispersystems.signalservice.api.NetworkResult
import java.util.concurrent.TimeUnit
@@ -89,96 +92,103 @@ class CopyAttachmentToArchiveJob private constructor(private val attachmentId: A
return Result.failure()
}
val mediaIdLog: String = if (RemoteConfig.internalUser && attachment.remoteKey != null && attachment.dataHash != null) {
val mediaId = MediaName.fromPlaintextHashAndRemoteKey(attachment.dataHash.decodeBase64()!!, attachment.remoteKey.decodeBase64()!!).toMediaId(SignalStore.backup.mediaRootBackupKey)
"[$mediaId]"
} else {
""
}
if (attachment.archiveTransferState == AttachmentTable.ArchiveTransferState.FINISHED) {
Log.i(TAG, "[$attachmentId] Already finished. Skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Already finished. Skipping.")
return Result.success()
}
if (attachment.archiveTransferState == AttachmentTable.ArchiveTransferState.PERMANENT_FAILURE) {
Log.i(TAG, "[$attachmentId] Already marked as a permanent failure. Skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Already marked as a permanent failure. Skipping.")
return Result.failure()
}
if (SignalDatabase.messages.isStory(attachment.mmsId)) {
Log.i(TAG, "[$attachmentId] Attachment is a story. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment is a story. Resetting transfer state to none and skipping.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
return Result.success()
}
if (SignalDatabase.messages.isViewOnce(attachment.mmsId)) {
Log.i(TAG, "[$attachmentId] Attachment is view-once. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment is view-once. Resetting transfer state to none and skipping.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
return Result.success()
}
if (SignalDatabase.messages.willMessageExpireBeforeCutoff(attachment.mmsId)) {
Log.i(TAG, "[$attachmentId] Message will expire in less than 24 hours. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Message will expire in less than 24 hours. Resetting transfer state to none and skipping.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
return Result.success()
}
if (attachment.contentType == MediaUtil.LONG_TEXT) {
Log.i(TAG, "[$attachmentId] Attachment is long text. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment is long text. Resetting transfer state to none and skipping.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
return Result.success()
}
if (attachment.cdn !in ALLOWED_SOURCE_CDNS) {
Log.i(TAG, "[$attachmentId] Attachment CDN (${attachment.cdn}) is not in allowed source CDNs. Enqueueing an upload job instead.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment CDN (${attachment.cdn}) is not in allowed source CDNs. Enqueueing an upload job instead.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
AppDependencies.jobManager.add(UploadAttachmentToArchiveJob(attachmentId, canReuseUpload = false))
return Result.success()
}
if (attachment.remoteLocation == null) {
Log.i(TAG, "[$attachmentId] Attachment has no remote location. Enqueueing an upload job instead.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment has no remote location. Enqueueing an upload job instead.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
AppDependencies.jobManager.add(UploadAttachmentToArchiveJob(attachmentId, canReuseUpload = false))
return Result.success()
}
if (attachment.archiveTransferState == AttachmentTable.ArchiveTransferState.NONE) {
Log.i(TAG, "[$attachmentId] Not marked as pending copy. Enqueueing an upload job instead.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Not marked as pending copy. Enqueueing an upload job instead.")
AppDependencies.jobManager.add(UploadAttachmentToArchiveJob(attachmentId))
return Result.success()
}
if (isCanceled) {
Log.w(TAG, "[$attachmentId] Canceled. Refusing to proceed.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Canceled. Refusing to proceed.")
return Result.failure()
}
val result = when (val archiveResult = BackupRepository.copyAttachmentToArchive(attachment)) {
is NetworkResult.Success -> {
Log.i(TAG, "[$attachmentId] Successfully copied the archive tier.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Successfully copied the archive tier.")
Result.success()
}
is NetworkResult.NetworkError -> {
Log.w(TAG, "[$attachmentId] Encountered a retryable network error.", archiveResult.exception)
Log.w(TAG, "[$attachmentId]$mediaIdLog Encountered a retryable network error.", archiveResult.exception)
Result.retry(defaultBackoff())
}
is NetworkResult.StatusCodeError -> {
when (archiveResult.code) {
400 -> {
Log.w(TAG, "[$attachmentId] Something is invalid about our request. Possibly the length. Scheduling a re-upload. Body: ${archiveResult.exception.stringBody}")
Log.w(TAG, "[$attachmentId]$mediaIdLog Something is invalid about our request. Possibly the length. Scheduling a re-upload. Body: ${archiveResult.exception.stringBody}")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
AppDependencies.jobManager.add(UploadAttachmentToArchiveJob(attachmentId, canReuseUpload = false))
Result.success()
}
403 -> {
Log.w(TAG, "[$attachmentId] Insufficient permissions to upload. Handled in parent handler.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Insufficient permissions to upload. Handled in parent handler.")
Result.success()
}
410 -> {
Log.w(TAG, "[$attachmentId] The attachment no longer exists on the transit tier. Scheduling a re-upload.")
Log.w(TAG, "[$attachmentId]$mediaIdLog The attachment no longer exists on the transit tier. Scheduling a re-upload.")
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
AppDependencies.jobManager.add(UploadAttachmentToArchiveJob(attachmentId, canReuseUpload = false))
Result.success()
}
413 -> {
Log.w(TAG, "[$attachmentId] Insufficient storage space! Can't upload!")
Log.w(TAG, "[$attachmentId]$mediaIdLog Insufficient storage space! Can't upload!")
val remoteStorageQuota = getServerQuota() ?: return Result.retry(defaultBackoff()).logW(TAG, "[$attachmentId] Failed to fetch server quota! Retrying.")
if (SignalDatabase.attachments.getPaidEstimatedArchiveMediaSize() > remoteStorageQuota.inWholeBytes) {
@@ -186,14 +196,14 @@ class CopyAttachmentToArchiveJob private constructor(private val attachmentId: A
return Result.failure()
}
Log.i(TAG, "[$attachmentId] Remote storage is full, but our local state indicates that once we reconcile our storage, we should have enough. Enqueuing the reconciliation job and retrying.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Remote storage is full, but our local state indicates that once we reconcile our storage, we should have enough. Enqueuing the reconciliation job and retrying.")
SignalStore.backup.remoteStorageGarbageCollectionPending = true
ArchiveAttachmentReconciliationJob.enqueueIfRetryAllowed(forced = true)
Result.retry(defaultBackoff())
}
else -> {
Log.w(TAG, "[$attachmentId] Got back a non-2xx status code: ${archiveResult.code}. Retrying.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Got back a non-2xx status code: ${archiveResult.code}. Retrying.")
Result.retry(defaultBackoff())
}
}
@@ -201,17 +211,17 @@ class CopyAttachmentToArchiveJob private constructor(private val attachmentId: A
is NetworkResult.ApplicationError -> {
if (archiveResult.throwable is VerificationFailedException) {
Log.w(TAG, "[$attachmentId] Encountered a verification failure when trying to upload! Retrying.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Encountered a verification failure when trying to upload! Retrying.")
Result.retry(defaultBackoff())
} else {
Log.w(TAG, "[$attachmentId] Encountered a fatal error when trying to upload!")
Log.w(TAG, "[$attachmentId]$mediaIdLog Encountered a fatal error when trying to upload!")
Result.fatalFailure(RuntimeException(archiveResult.throwable))
}
}
}
if (result.isSuccess) {
Log.d(TAG, "[$attachmentId] Updating archive transfer state to ${AttachmentTable.ArchiveTransferState.FINISHED}")
Log.d(TAG, "[$attachmentId]$mediaIdLog Updating archive transfer state to ${AttachmentTable.ArchiveTransferState.FINISHED}")
ArchiveDatabaseExecutor.runBlocking {
SignalDatabase.attachments.setArchiveTransferState(attachmentId, attachment.remoteKey!!, attachment.dataHash!!, AttachmentTable.ArchiveTransferState.FINISHED, notify = false)
ArchiveDatabaseExecutor.throttledNotifyAttachmentObservers()
@@ -221,10 +231,10 @@ class CopyAttachmentToArchiveJob private constructor(private val attachmentId: A
if (!attachment.quote) {
ArchiveThumbnailUploadJob.enqueueIfNecessary(attachmentId)
} else {
Log.d(TAG, "[$attachmentId] Refusing to enqueue thumb for quote attachment.")
Log.d(TAG, "[$attachmentId]$mediaIdLog Refusing to enqueue thumb for quote attachment.")
}
} else {
Log.d(TAG, "[$attachmentId] Refusing to enqueue thumb for canceled upload.")
Log.d(TAG, "[$attachmentId]$mediaIdLog Refusing to enqueue thumb for canceled upload.")
}
ArchiveUploadProgress.onAttachmentFinished(attachmentId)

58
app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt
View File

@@ -5,7 +5,9 @@
package org.thoughtcrime.securesms.jobs
import org.signal.core.models.backup.MediaName
import org.signal.core.util.Base64
import org.signal.core.util.Base64.decodeBase64
import org.signal.core.util.inRoundedDays
import org.signal.core.util.isNotNullOrBlank
import org.signal.core.util.logging.Log
@@ -28,6 +30,7 @@ import org.thoughtcrime.securesms.keyvalue.SignalStore
import org.thoughtcrime.securesms.net.SignalNetwork
import org.thoughtcrime.securesms.service.AttachmentProgressService
import org.thoughtcrime.securesms.util.MediaUtil
import org.thoughtcrime.securesms.util.RemoteConfig
import org.thoughtcrime.securesms.util.Util
import org.whispersystems.signalservice.api.NetworkResult
import org.whispersystems.signalservice.api.archive.ArchiveMediaUploadFormStatusCodes
@@ -133,29 +136,36 @@ class UploadAttachmentToArchiveJob private constructor(
return Result.failure()
}
val mediaIdLog: String = if (RemoteConfig.internalUser && attachment.remoteKey != null && attachment.dataHash != null) {
val mediaId = MediaName.fromPlaintextHashAndRemoteKey(attachment.dataHash.decodeBase64()!!, attachment.remoteKey.decodeBase64()!!).toMediaId(SignalStore.backup.mediaRootBackupKey)
"[$mediaId]"
} else {
""
}
if (attachment.uri == null) {
Log.w(TAG, "[$attachmentId] Attachment has no uri! Cannot upload.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Attachment has no uri! Cannot upload.")
return Result.failure()
}
if (attachment.archiveTransferState == AttachmentTable.ArchiveTransferState.FINISHED) {
Log.i(TAG, "[$attachmentId] Already finished. Skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Already finished. Skipping.")
return Result.success()
}
if (attachment.archiveTransferState == AttachmentTable.ArchiveTransferState.PERMANENT_FAILURE) {
Log.i(TAG, "[$attachmentId] Already marked as a permanent failure. Skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Already marked as a permanent failure. Skipping.")
return Result.failure()
}
if (attachment.archiveTransferState == AttachmentTable.ArchiveTransferState.COPY_PENDING) {
Log.i(TAG, "[$attachmentId] Already marked as pending transfer. Enqueueing a copy job just in case.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Already marked as pending transfer. Enqueueing a copy job just in case.")
AppDependencies.jobManager.add(CopyAttachmentToArchiveJob(attachment.attachmentId))
return Result.success()
}
if (SignalDatabase.messages.isStory(attachment.mmsId)) {
Log.i(TAG, "[$attachmentId] Attachment is a story. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment is a story. Resetting transfer state to none and skipping.")
ArchiveDatabaseExecutor.runBlocking {
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
}
@@ -163,7 +173,7 @@ class UploadAttachmentToArchiveJob private constructor(
}
if (SignalDatabase.messages.isViewOnce(attachment.mmsId)) {
Log.i(TAG, "[$attachmentId] Attachment is a view-once. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment is a view-once. Resetting transfer state to none and skipping.")
ArchiveDatabaseExecutor.runBlocking {
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
}
@@ -171,7 +181,7 @@ class UploadAttachmentToArchiveJob private constructor(
}
if (SignalDatabase.messages.willMessageExpireBeforeCutoff(attachment.mmsId)) {
Log.i(TAG, "[$attachmentId] Message will expire within 24 hours. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Message will expire within 24 hours. Resetting transfer state to none and skipping.")
ArchiveDatabaseExecutor.runBlocking {
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
}
@@ -179,7 +189,7 @@ class UploadAttachmentToArchiveJob private constructor(
}
if (attachment.contentType == MediaUtil.LONG_TEXT) {
Log.i(TAG, "[$attachmentId] Attachment is long text. Resetting transfer state to none and skipping.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Attachment is long text. Resetting transfer state to none and skipping.")
ArchiveDatabaseExecutor.runBlocking {
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.NONE)
}
@@ -187,7 +197,7 @@ class UploadAttachmentToArchiveJob private constructor(
}
if (attachment.remoteKey == null || attachment.remoteKey.isBlank()) {
Log.w(TAG, "[$attachmentId] Attachment is missing remote key! Cannot upload.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Attachment is missing remote key! Cannot upload.")
return Result.failure()
}
@@ -199,12 +209,12 @@ class UploadAttachmentToArchiveJob private constructor(
}
if (uploadSpec != null && System.currentTimeMillis() > uploadSpec!!.timeout) {
Log.w(TAG, "[$attachmentId] Upload spec expired! Clearing.")
Log.w(TAG, "[$attachmentId]$mediaIdLog Upload spec expired! Clearing.")
uploadSpec = null
}
if (uploadSpec == null) {
Log.d(TAG, "[$attachmentId] Need an upload spec. Fetching...")
Log.d(TAG, "[$attachmentId]$mediaIdLog Need an upload spec. Fetching...")
val (spec, result) = fetchResumableUploadSpec(key = Base64.decode(attachment.remoteKey), iv = Util.getSecretBytes(16))
if (result != null) {
@@ -213,7 +223,7 @@ class UploadAttachmentToArchiveJob private constructor(
uploadSpec = spec
} else {
Log.d(TAG, "[$attachmentId] Already have an upload spec. Continuing...")
Log.d(TAG, "[$attachmentId]$mediaIdLog Already have an upload spec. Continuing...")
}
val progressServiceController = if (attachment.size >= AttachmentUploadUtil.FOREGROUND_LIMIT_BYTES) {
@@ -240,37 +250,37 @@ class UploadAttachmentToArchiveJob private constructor(
}
)
} catch (e: FileNotFoundException) {
Log.w(TAG, "[$attachmentId] No file exists for this attachment! Marking as a permanent failure.", e)
Log.w(TAG, "[$attachmentId]$mediaIdLog No file exists for this attachment! Marking as a permanent failure.", e)
ArchiveDatabaseExecutor.runBlocking {
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.PERMANENT_FAILURE)
}
return Result.failure()
} catch (e: IOException) {
Log.w(TAG, "[$attachmentId] Failed while reading the stream.", e)
Log.w(TAG, "[$attachmentId]$mediaIdLog Failed while reading the stream.", e)
return Result.retry(defaultBackoff())
}
Log.d(TAG, "[$attachmentId] Beginning upload...")
Log.d(TAG, "[$attachmentId]$mediaIdLog Beginning upload...")
progressServiceController.use {
val uploadResult: AttachmentUploadResult = attachmentStream.use { managedAttachmentStream ->
when (val result = SignalNetwork.attachments.uploadAttachmentV4(managedAttachmentStream)) {
is NetworkResult.Success -> result.result
is NetworkResult.ApplicationError -> throw result.throwable
is NetworkResult.NetworkError -> {
Log.w(TAG, "[$attachmentId] Failed to upload due to network error.", result.exception)
Log.w(TAG, "[$attachmentId]$mediaIdLog Failed to upload due to network error.", result.exception)
if (result.exception.cause is ProtocolException) {
Log.w(TAG, "[$attachmentId] Length may be incorrect. Recalculating.", result.exception)
Log.w(TAG, "[$attachmentId]$mediaIdLog Length may be incorrect. Recalculating.", result.exception)
val actualLength = SignalDatabase.attachments.getAttachmentStream(attachmentId, 0)
.use { it.readLength() }
if (actualLength != attachment.size) {
Log.w(TAG, "[$attachmentId] Length was incorrect! Will update. Previous: ${attachment.size}, Newly-Calculated: $actualLength", result.exception)
Log.w(TAG, "[$attachmentId]$mediaIdLog Length was incorrect! Will update. Previous: ${attachment.size}, Newly-Calculated: $actualLength", result.exception)
ArchiveDatabaseExecutor.runBlocking {
SignalDatabase.attachments.updateAttachmentLength(attachmentId, actualLength)
}
} else {
Log.i(TAG, "[$attachmentId] Length was correct. No action needed. Will retry.")
Log.i(TAG, "[$attachmentId]$mediaIdLog Length was correct. No action needed. Will retry.")
}
}
@@ -278,14 +288,14 @@ class UploadAttachmentToArchiveJob private constructor(
}
is NetworkResult.StatusCodeError -> {
Log.w(TAG, "[$attachmentId] Failed to upload due to status code error. Code: ${result.code}", result.exception)
Log.w(TAG, "[$attachmentId]$mediaIdLog Failed to upload due to status code error. Code: ${result.code}", result.exception)
when (result.code) {
400 -> {
Log.w(TAG, "[$attachmentId] 400 likely means bad resumable state. Clearing upload spec before retrying.")
Log.w(TAG, "[$attachmentId]$mediaIdLog 400 likely means bad resumable state. Clearing upload spec before retrying.")
uploadSpec = null
}
413 -> {
Log.w(TAG, "[$attachmentId] 413 means the attachment was too large. We've seen this happen with frankenstein imports using third party tools. This can never succeed.")
Log.w(TAG, "[$attachmentId]$mediaIdLog 413 means the attachment was too large. We've seen this happen with frankenstein imports using third party tools. This can never succeed.")
ArchiveDatabaseExecutor.runBlocking {
setArchiveTransferStateWithDelayedNotification(attachmentId, AttachmentTable.ArchiveTransferState.PERMANENT_FAILURE)
}
@@ -298,7 +308,7 @@ class UploadAttachmentToArchiveJob private constructor(
}
}
Log.d(TAG, "[$attachmentId] Upload complete!")
Log.d(TAG, "[$attachmentId]$mediaIdLog Upload complete!")
ArchiveDatabaseExecutor.runBlocking {
SignalDatabase.attachments.finalizeAttachmentAfterUpload(attachment.attachmentId, uploadResult)
}
@@ -307,7 +317,7 @@ class UploadAttachmentToArchiveJob private constructor(
if (!isCanceled) {
AppDependencies.jobManager.add(CopyAttachmentToArchiveJob(attachment.attachmentId))
} else {
Log.d(TAG, "[$attachmentId] Job was canceled. Skipping copy job.")
Log.d(TAG, "[$attachmentId]$mediaIdLog Job was canceled. Skipping copy job.")
}
return Result.success()

14
app/src/main/java/org/thoughtcrime/securesms/wallpaper/WallpaperStorage.java
View File

@@ -57,17 +57,23 @@ public final class WallpaperStorage {
*/
@WorkerThread
public static void onWallpaperDeselected(@NonNull Uri uri) {
if (!isWallpaperUriUsed(uri)) {
AttachmentId attachmentId = new PartUriParser(uri).getPartId();
SignalDatabase.attachments().deleteAttachment(attachmentId);
}
}
public static boolean isWallpaperUriUsed(@NonNull Uri uri) {
Uri globalUri = SignalStore.wallpaper().getWallpaperUri();
if (Objects.equals(uri, globalUri)) {
return;
return true;
}
int recipientCount = SignalDatabase.recipients().getWallpaperUriUsageCount(uri);
if (recipientCount > 0) {
return;
return true;
}
AttachmentId attachmentId = new PartUriParser(uri).getPartId();
SignalDatabase.attachments().deleteAttachment(attachmentId);
return false;
}
}

5
core/models/src/main/java/org/signal/core/models/backup/MediaId.kt
View File

@@ -6,6 +6,7 @@
package org.signal.core.models.backup
import org.signal.core.util.Base64
import org.signal.core.util.Hex
/**
* Safe typing around a mediaId, which is a 15-byte array.
@@ -23,4 +24,8 @@ value class MediaId(val value: ByteArray) {
fun encode(): String {
return Base64.encodeUrlSafeWithPadding(value)
}
override fun toString(): String {
return "MediaId::${Hex.toStringCondensed(value)}"
}
}

14
core/util-jvm/src/main/java/org/signal/core/util/logging/Scrubber.kt
View File

@@ -10,6 +10,7 @@ import org.signal.core.util.Hex
import org.signal.core.util.isNotNullOrBlank
import java.util.regex.Matcher
import java.util.regex.Pattern
import kotlin.io.path.Path
/** Given a [Matcher], update the [StringBuilder] with the scrubbed output you want for a given match. */
private typealias MatchProcessor = (Matcher, StringBuilder) -> Unit
@@ -30,6 +31,8 @@ object Scrubber {
private val CRUDE_EMAIL_PATTERN = Pattern.compile("\\b([^\\s/,()])([^\\s/,()]*@[^\\s]+\\.[^\\s]+)")
private const val EMAIL_CENSOR = "...@..."
private val MEDIA_ID_PATTERN = Pattern.compile("MediaId::([a-f0-9]{30})")
/** The middle group will be censored. */
private val GROUP_ID_V1_PATTERN = Pattern.compile("(__textsecure_group__!)([^\\s]+)([^\\s]{3})")
@@ -101,6 +104,7 @@ object Scrubber {
.scrubIpv6()
.scrubCallLinkKeys()
.scrubCallLinkRoomIds()
.scrubMediaIds()
}
private fun CharSequence.scrubE164(): CharSequence {
@@ -230,6 +234,14 @@ object Scrubber {
}
}
private fun CharSequence.scrubMediaIds(): CharSequence {
return scrub(this, MEDIA_ID_PATTERN) { matcher, output ->
output
.append("MediaId::")
.append(hash(matcher.group(1)))
}
}
private fun String.censorMiddle(leading: Int, trailing: Int): String {
val totalKept = leading + trailing
if (this.length < totalKept) {
@@ -266,6 +278,6 @@ object Scrubber {
val key: ByteArray = identifierHmacKey ?: return "<redacted>"
val hash = CryptoUtil.hmacSha256(key, value.toByteArray())
return "<${Hex.toStringCondensed(hash).take(5)}>"
return "<${Hex.toStringCondensed(hash).take(8)}>"
}
}

52
core/util-jvm/src/test/java/org/signal/core/util/logging/ScrubberTest.kt
View File

@@ -32,19 +32,19 @@ class ScrubberTest(private val input: String, private val expected: String) {
return listOf(
arrayOf(
"An E164 number +15551234567",
"An E164 number E164:<9f683>"
"An E164 number E164:<9f6833c8>"
),
arrayOf(
"A UK number +447700900000",
"A UK number E164:<cad1f>"
"A UK number E164:<cad1f43d>"
),
arrayOf(
"A Japanese number 08011112222",
"A Japanese number E164:<d3f26>"
"A Japanese number E164:<d3f264bd>"
),
arrayOf(
"A Japanese number (08011112222)",
"A Japanese number (E164:<d3f26>)"
"A Japanese number (E164:<d3f264bd>)"
),
arrayOf(
"Not a Japanese number 08011112222333344445555",
@@ -56,11 +56,11 @@ class ScrubberTest(private val input: String, private val expected: String) {
),
arrayOf(
"An avatar filename: file:///data/user/0/org.thoughtcrime.securesms/files/avatars/%2B447700900099",
"An avatar filename: file:///data/user/0/org.thoughtcrime.securesms/files/avatars/E164:<3106a>"
"An avatar filename: file:///data/user/0/org.thoughtcrime.securesms/files/avatars/E164:<3106a51b>"
),
arrayOf(
"Multiple numbers +447700900001 +447700900002",
"Multiple numbers E164:<87035> E164:<1e488>"
"Multiple numbers E164:<87035e22> E164:<1e488ca0>"
),
arrayOf(
"One less than shortest number +155556",
@@ -68,11 +68,11 @@ class ScrubberTest(private val input: String, private val expected: String) {
),
arrayOf(
"Shortest number +1555567",
"Shortest number E164:<8edd2>"
"Shortest number E164:<8edd240f>"
),
arrayOf(
"Longest number +155556789012345",
"Longest number E164:<90596>"
"Longest number E164:<90596670>"
),
arrayOf(
"An E164 number KEEP_E164::+15551234567",
@@ -92,7 +92,7 @@ class ScrubberTest(private val input: String, private val expected: String) {
),
arrayOf(
"One more than longest number +1234567890123456",
"One more than longest number E164:<78d5b>6"
"One more than longest number E164:<78d5bea7>6"
),
arrayOf(
"abc@def.com",
@@ -120,7 +120,7 @@ class ScrubberTest(private val input: String, private val expected: String) {
),
arrayOf(
"An email and a number abc@def.com +155556789012345",
"An email and a number a...@... E164:<90596>"
"An email and a number a...@... E164:<90596670>"
),
arrayOf(
"__textsecure_group__!000102030405060708090a0b0c0d0e0f",
@@ -152,7 +152,7 @@ class ScrubberTest(private val input: String, private val expected: String) {
),
arrayOf(
"A PNI:a37cb654-c9e0-4c1e-93df-3d11ca3c97f4 surrounded with text",
"A PNI:<bdf84> surrounded with text"
"A PNI:<bdf84cf4> surrounded with text"
),
arrayOf(
"JOB::a37cb654-c9e0-4c1e-93df-3d11ca3c97f4",
@@ -160,7 +160,7 @@ class ScrubberTest(private val input: String, private val expected: String) {
),
arrayOf(
"All patterns in a row __textsecure_group__!abcdefg1234567890 +123456789012345 abc@def.com a37cb654-c9e0-4c1e-93df-3d11ca3c97f4 nl.motorsport.com 192.168.1.1 with text after",
"All patterns in a row GV1::***890 E164:<78d5b> a...@... ********-****-****-****-*********7f4 ***.com ...ipv4... with text after"
"All patterns in a row GV1::***890 E164:<78d5bea7> a...@... ********-****-****-****-*********7f4 ***.com ...ipv4... with text after"
),
arrayOf(
"java.net.UnknownServiceException: CLEARTEXT communication to nl.motorsport.com not permitted by network security policy",
@@ -265,6 +265,34 @@ class ScrubberTest(private val input: String, private val expected: String) {
arrayOf(
"https://debuglogs.org/android/7.47.2/2b5ccf4e3e58e44f12b3c92cfd5b526a2432f1dd0f81c8f89dededb176f1122d",
"https://debuglogs.org/android/7.47.2/2b5ccf4e3e58e44f12b3c92cfd5b526a2432f1dd0f81c8f89dededb176f1122d"
),
arrayOf(
"A media ID MediaId::0123456789abcdef0123456789abcd",
"A media ID MediaId::<cad309e5>"
),
arrayOf(
"MediaId::abcdefabcdefabcdefabcdefabcdef surrounded with text",
"MediaId::<1a076ecf> surrounded with text"
),
arrayOf(
"Multiple media IDs MediaId::000000000000000000000000000001 and MediaId::000000000000000000000000000002",
"Multiple media IDs MediaId::<9f0d2177> and MediaId::<7f96bb4c>"
),
arrayOf(
"Not a media ID (too short) MediaId::0123456789abcdef012345678",
"Not a media ID (too short) MediaId::0123456789abcdef012345678"
),
arrayOf(
"One more than media ID length MediaId::0123456789abcdef0123456789abcdef",
"One more than media ID length MediaId::<cad309e5>ef"
),
arrayOf(
"Not a media ID (uppercase) MediaId::0123456789ABCDEF0123456789ABCD",
"Not a media ID (uppercase) MediaId::0123456789ABCDEF0123456789ABCD"
),
arrayOf(
"Not a media ID (invalid chars) MediaId::0123456789ghijkl0123456789abcd",
"Not a media ID (invalid chars) MediaId::0123456789ghijkl0123456789abcd"
)
)
}