Details
-
Type:
Bug
-
Status: Closed
-
Priority:
Major
-
Resolution: Done
-
Affects Version/s: 3.18.1
-
Fix Version/s: 3.21.0
-
Component/s: Blobstore, Scheduled Tasks
-
Notability:3
Description
It has been noticed that the Admin - Remove a member from a blob store group task may process source blobstore files that it, itself already processed during the same run ( and logged as deleted from the source blobstore ). When it tries to process a blob that is already deleted, it fails the entire task, preventing any further blobs from being moved.
Notice in the following log ourput the 7fa54570-4272-4bdf-8927-f4605cb9d020 blob was processed twice. The first time it twas successfully moved to the target blobstore, the second time it caused the task to fail.
2019-09-20 16:16:58,027+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.file.FileBlobStore - Accessing blob 7fa54570-4272-4bdf-8927-f4605cb9d020 2019-09-20 16:16:58,041+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.s3.internal.S3BlobStore - Writing blob 7fa54570-4272-4bdf-8927-f4605cb9d020 to maven/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes 2019-09-20 16:16:58,047+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.s3.internal.MultipartUploader - Starting upload to key maven/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes in bucket pgac-nexus-blobstores of 40 bytes 2019-09-20 16:16:58,069+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.s3.internal.S3PropertiesFile - Storing: pgac-nexus-blobstores/maven/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.properties 2019-09-20 16:16:58,134+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.s3.internal.S3PropertiesFile - Loading: pgac-nexus-blobstores/maven/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.properties 2019-09-20 16:16:58,152+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.s3.internal.S3PropertiesFile - Storing: pgac-nexus-blobstores/maven/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.properties 2019-09-20 16:16:58,221+0000 INFO [ForkJoinPool-1221-worker-1] *SYSTEM com.sonatype.nexus.blobstore.group.internal.tasks.BlobStoreGroupMemberRemovalTask - Created blobId 7fa54570-4272-4bdf-8927-f4605cb9d020 in blob store 'default' 2019-09-20 16:16:58,221+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.file.FileBlobStore - Hard deleting blob 7fa54570-4272-4bdf-8927-f4605cb9d020 2019-09-20 16:16:58,236+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.file.FileBlobStore - Deleted /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes 2019-09-20 16:16:58,243+0000 DEBUG [ForkJoinPool-1221-worker-1] *SYSTEM org.sonatype.nexus.blobstore.file.FileBlobStore - Deleted /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.properties 2019-09-20 16:16:58,243+0000 INFO [ForkJoinPool-1221-worker-1] *SYSTEM com.sonatype.nexus.blobstore.group.internal.tasks.BlobStoreGroupMemberRemovalTask - Removed blobId 7fa54570-4272-4bdf-8927-f4605cb9d020 from blob store 'default-promoted' java.util.concurrent.ExecutionException: java.io.UncheckedIOException: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes Caused by: java.io.UncheckedIOException: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes Caused by: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes java.util.concurrent.ExecutionException: java.io.UncheckedIOException: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes Caused by: java.io.UncheckedIOException: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes Caused by: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes java.util.concurrent.ExecutionException: java.io.UncheckedIOException: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes Caused by: java.io.UncheckedIOException: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes Caused by: java.nio.file.NoSuchFileException: /nexus-data/blobs/default/content/vol-03/chap-21/7fa54570-4272-4bdf-8927-f4605cb9d020.bytes
Diagnosis
We have only one report of this problem so far. However the code doing the move uses parallel streams of blobs in the source blobstore, so this may lead to the rareness of this issue being reported as it could be a race condition or concurrency issue.
Workaround
One customer scheduled the task to execute every 5 minutes, until the task finally moved all blobs in the source blobstore. This is an extreme action.
Sonatype recommends to first contact Sonatype support ( support@sonatype.com ) should you need to attempt this workaround. We wish to gather evidence and info about environments that may contribute to this issue.
Expected
Do not process already deleted blobs. Make sure any concurrency used in code to process blobs is thread safe.
Continue to stop the task if a deleted /missing blob is encountered - the intent is that if such a failure happens, we need to figure out why.
Attachments
Issue Links
- is related to
-
-
- Closed
-
- relates
-
-
- New
-
-
-
- Closed
-
