Thread cooperation does not work when recovering from missing blobs in proxy repositories

If the component database contains a reference to blobs which do not exist in blob storage, and the repository is a proxy repository Nexus Repo will attempt to automatically recover by downloading the missing file from the remote and replacing the invalid reference.

This was implemented in: NEXUS-12388

We have observed that if multiple requests come in for an npm metadata file, and the blob is missing, they are all processed simultaneously. If s3 blob storage is used, this can cause the outbound request pool to become completely full.

2021-01-21 00:03:16,102-0500 WARN [qtp225668103-7385] node-3 anonymous org.sonatype.nexus.repository.docker.internal.V2Handlers - Error: GET /v2/core-agents/eqrs-inspec-agent/manifests/latest
com.amazonaws.SdkClientException: Unable to execute HTTP request: Timeout waiting for connection from pool
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.handleRetryableException(AmazonHttpClient.java:1207)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1153)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:802)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:770)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:744)
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:704)
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:686)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:550)
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:530)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:5062)
at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:5008)
at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:1338)
at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:1312)
at com.amazonaws.services.s3.AmazonS3Client.doesObjectExist(AmazonS3Client.java:1393)
at org.sonatype.nexus.blobstore.s3.internal.S3PropertiesFile.exists(S3PropertiesFile.java:76)
at org.sonatype.nexus.blobstore.s3.internal.S3BlobAttributes.load(S3BlobAttributes.java:44)
at org.sonatype.nexus.blobstore.s3.internal.S3BlobStore.refreshBlob(S3BlobStore.java:392)
at org.sonatype.nexus.blobstore.s3.internal.S3BlobStore.get(S3BlobStore.java:379)
at com.palominolabs.metrics.guice.TimedInterceptor.invoke(TimedInterceptor.java:26)
at org.sonatype.nexus.blobstore.s3.internal.S3BlobStore.get(S3BlobStore.java:365)
at org.sonatype.nexus.common.stateguard.MethodInvocationAction.run(MethodInvocationAction.java:39)
at org.sonatype.nexus.common.stateguard.StateGuard$GuardImpl.run(StateGuard.java:272)
at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:54)
at org.sonatype.nexus.repository.storage.BlobTx.get(BlobTx.java:166)
at org.sonatype.nexus.repository.storage.StorageTxImpl.getBlob(StorageTxImpl.java:994)
at org.sonatype.nexus.repository.storage.StorageTxImpl.requireBlob(StorageTxImpl.java:1005)
at sun.reflect.GeneratedMethodAccessor210.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)

Preceding this, you will see messages indicating the blob is missing, followed by messages showing update conflicts as the various executing threads complete and try to simultaneously update the same record.

021-01-21 12:34:58,379-0500 WARN [qtp223528361-225] node-3 *UNKNOWN org.sonatype.nexus.repository.npm.internal.orient.NpmStreamPayload - Missing blob for asset Asset{metadata=AttachedEntityMetadata

Unknown macro: {schema=asset, document=asset#38}

v5543}, name=tslib} and no handler set to recover, for package 'tslib' and rev 'tslib'
2021-01-21 12:34:58,381-0500 WARN [qtp223528361-48] node-3 *UNKNOWN org.sonatype.nexus.repository.npm.internal.orient.NpmStreamPayload - Missing blob for asset Asset{metadata=AttachedEntityMetadata

Unknown macro: {schema=asset, document=asset#38}

v5543}, name=tslib} and no handler set to recover, for package 'tslib' and rev 'tslib'
2021-01-21 12:34:58,404-0500 WARN [qtp223528361-209] node-3 *UNKNOWN org.sonatype.nexus.repository.npm.internal.orient.NpmStreamPayload - Missing blob for asset Asset{metadata=AttachedEntityMetadata

Unknown macro: {schema=asset, document=asset#38}

v5543}, name=tslib} and no handler set to recover, for package 'tslib' and rev 'tslib'
2021-01-21 12:34:58,411-0500 WARN [qtp223528361-238] node-3 *UNKNOWN org.sonatype.nexus.repository.npm.internal.orient.NpmStreamPayload - Missing blob for asset Asset{metadata=AttachedEntityMetadata

Unknown macro: {schema=asset, document=asset#38}

v5543}, name=tslib} and no handler set to recover, for package 'tslib' and rev 'tslib'
2021-01-21 12:34:58,548-0500 WARN [qtp223528361-226] node-3 *UNKNOWN org.sonatype.nexus.blobstore.s3.internal.S3BlobStore - Attempt to mark-for-delete non-existent blob 6d8a76bf-890c-4b95-945e-fe024571bb5f
2021-01-21 12:34:58,897-0500 WARN [qtp223528361-209] node-3 *UNKNOWN org.sonatype.nexus.repository.httpbridge.internal.ViewServlet - Failure servicing: GET /repository/eqrs-npm/tslib
com.orientechnologies.orient.core.exception.OConcurrentModificationException: Cannot UPDATE the record #38:2077 because the version is not the latest. Probably you are updating an old record or it has been modified by another user (db=v5544 your=v5543)
DB name="component"
at org.sonatype.nexus.orient.entity.ConflictHook.onUpdate(ConflictHook.java:154)
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.checkAndIncrementVersion(OAbstractPaginatedStorage.java:4545)
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.doUpdateRecord(OAbstractPaginatedStorage.java:4022)
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.commitEntry(OAbstractPaginatedStorage.java:4607)
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.commit(OAbstractPaginatedStorage.java:1857)
at com.orientechnologies.orient.core.tx.OTransactionOptimistic.doCommit(OTransactionOptimistic.java:541)
at com.orientechnologies.orient.core.tx.OTransactionOptimistic.commit(OTransactionOptimistic.java:99)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2908)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2870)
at org.sonatype.nexus.repository.storage.StorageTxImpl.commit(StorageTxImpl.java:195)
at sun.reflect.GeneratedMethodAccessor163.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.sonatype.nexus.common.stateguard.SimpleMethodInvocation.proceed(SimpleMethodInvocation.java:53)
at org.sonatype.nexus.common.stateguard.MethodInvocationAction.run(MethodInvocationAction.java:39)
at org.sonatype.nexus.common.stateguard.StateGuard$TransitionImpl.run(StateGuard.java:193)
at org.sonatype.nexus.common.stateguard.TransitionsInterceptor.invoke(TransitionsInterceptor.java:57)
at org.sonatype.nexus.common.stateguard.StateGuardAspect$1.invoke(StateGuardAspect.java:66)
at com.sun.proxy.$Proxy243.commit(Unknown Source)
at org.sonatype.nexus.transaction.TransactionalWrapper.proceedWithTransaction(TransactionalWrapper.java:68)
at org.sonatype.nexus.transaction.Operations.proceedWithTransaction(Operations.java:232)
at org.sonatype.nexus.transaction.Operations.transactional(Operations.java:223)
at org.sonatype.nexus.transaction.Operations.call(Operations.java:166)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)

 Expected: When multiple nearly simultaneous requests for the same file come into a proxy repository, only one of them should trigger an outbound request. The rest should queue waiting for the first one to complete, and the use its results.