From 43607edc1c85da1c7d2e147a5aa1611f67dc8157 Mon Sep 17 00:00:00 2001 From: Greyson Parrelli Date: Wed, 14 Jan 2026 13:53:57 -0500 Subject: [PATCH] Improve reconciliation logging and handling. --- .../securesms/database/AttachmentTable.kt | 12 ++-- .../ArchiveAttachmentReconciliationJob.kt | 66 ++++++++++++++----- .../jobs/ArchiveCommitAttachmentDeletesJob.kt | 8 +++ .../jobs/CopyAttachmentToArchiveJob.kt | 56 +++++++++------- .../jobs/UploadAttachmentToArchiveJob.kt | 58 +++++++++------- .../securesms/wallpaper/WallpaperStorage.java | 14 ++-- .../org/signal/core/models/backup/MediaId.kt | 5 ++ .../org/signal/core/util/logging/Scrubber.kt | 14 +++- .../signal/core/util/logging/ScrubberTest.kt | 52 +++++++++++---- 9 files changed, 199 insertions(+), 86 deletions(-) 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 35ab2232b9..4e0a33fb1d 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/database/AttachmentTable.kt @@ -3426,7 +3426,7 @@ class AttachmentTable( } } - fun debugGetAttachmentDataForMediaIds(mediaIds: Collection): List { + fun getAttachmentDataForMediaIds(mediaIds: Collection): List { 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): Set { 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}" } } } diff --git a/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentReconciliationJob.kt b/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentReconciliationJob.kt index 67f24fc44b..1790fc43c1 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentReconciliationJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveAttachmentReconciliationJob.kt @@ -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): 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 = 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") - } + stopwatch.split("fix-state") } if (validatedDeletes.isEmpty()) { diff --git a/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveCommitAttachmentDeletesJob.kt b/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveCommitAttachmentDeletesJob.kt index 83443f8104..3212da7692 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveCommitAttachmentDeletesJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/ArchiveCommitAttachmentDeletesJob.kt @@ -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, 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) diff --git a/app/src/main/java/org/thoughtcrime/securesms/jobs/CopyAttachmentToArchiveJob.kt b/app/src/main/java/org/thoughtcrime/securesms/jobs/CopyAttachmentToArchiveJob.kt index 8c51e3eee7..181acf2864 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/CopyAttachmentToArchiveJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/CopyAttachmentToArchiveJob.kt @@ -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) 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 dfbdb1a977..484e7e89a0 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt +++ b/app/src/main/java/org/thoughtcrime/securesms/jobs/UploadAttachmentToArchiveJob.kt @@ -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() diff --git a/app/src/main/java/org/thoughtcrime/securesms/wallpaper/WallpaperStorage.java b/app/src/main/java/org/thoughtcrime/securesms/wallpaper/WallpaperStorage.java index 8b3b1da7eb..fcba73401b 100644 --- a/app/src/main/java/org/thoughtcrime/securesms/wallpaper/WallpaperStorage.java +++ b/app/src/main/java/org/thoughtcrime/securesms/wallpaper/WallpaperStorage.java @@ -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; } } diff --git a/core/models/src/main/java/org/signal/core/models/backup/MediaId.kt b/core/models/src/main/java/org/signal/core/models/backup/MediaId.kt index 4c92f4abd0..17b94e7ceb 100644 --- a/core/models/src/main/java/org/signal/core/models/backup/MediaId.kt +++ b/core/models/src/main/java/org/signal/core/models/backup/MediaId.kt @@ -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)}" + } } diff --git a/core/util-jvm/src/main/java/org/signal/core/util/logging/Scrubber.kt b/core/util-jvm/src/main/java/org/signal/core/util/logging/Scrubber.kt index 294e325781..552bbad791 100644 --- a/core/util-jvm/src/main/java/org/signal/core/util/logging/Scrubber.kt +++ b/core/util-jvm/src/main/java/org/signal/core/util/logging/Scrubber.kt @@ -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 "" val hash = CryptoUtil.hmacSha256(key, value.toByteArray()) - return "<${Hex.toStringCondensed(hash).take(5)}>" + return "<${Hex.toStringCondensed(hash).take(8)}>" } } diff --git a/core/util-jvm/src/test/java/org/signal/core/util/logging/ScrubberTest.kt b/core/util-jvm/src/test/java/org/signal/core/util/logging/ScrubberTest.kt index 50c94bdc03..bf9d8501cb 100644 --- a/core/util-jvm/src/test/java/org/signal/core/util/logging/ScrubberTest.kt +++ b/core/util-jvm/src/test/java/org/signal/core/util/logging/ScrubberTest.kt @@ -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:" + "A UK number E164:" ), arrayOf( "A Japanese number 08011112222", - "A Japanese number E164:" + "A Japanese number E164:" ), arrayOf( "A Japanese number (08011112222)", - "A Japanese number (E164:)" + "A Japanese number (E164:)" ), 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: surrounded with text" + "A PNI: 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::" + ), + 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::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" ) ) }