Details
-
Type:
Bug
-
Status: New
-
Priority:
Major
-
Resolution: Unresolved
-
Affects Version/s: 3.19.0, 3.20.1
-
Fix Version/s: None
-
Component/s: PyPI, Scheduled Tasks
-
Labels:
-
Notability:3
Description
The "Repair - Reconcile component database from blobstore" task was run against a blobstore with PyPI assets using version 3.19.0 ( in an HA-C cluster ).
Many messages were logged for assets being restored - here is one set of 3 log messages that indicate:
1) There was an ERROR ClassCastException restoring an asset
2) The was an INFO message indicating the asset was restored
3) There was a WARN NullPointerException indicating Browse nodes could not be restored.
2019-11-14 06:37:13,646-0500 ERROR [quartz-5-thread-18] pypi-uat2-03 *SYSTEM com.google.common.eventbus.EventBus.nexus - Could not dispatch event AssetCreatedEvent{metadata=AttachedEntityMetadata{schema=asset, document=asset#33:2680{bucket:#26:4,format:pypi,last_updated:Thu Nov 14 06:37:13 EST 2019,attributes:[3],component:#32:196,name:packages/78/7b/2e3657ede5369f0e88a1833c209cec095e3a8ba2665676a35d78aaee5ba2/pandas-0.25.1-cp35-cp35m-win_amd64.whl,size:8786520,content_type:application/zip,created_by:anonymous,created_by_ip:127.0.0.1,blob_ref:OBSv2 Blob Store@2BAF309D-7270A5D1-D4ECF511-A780BF17-4820F84E:ce6c4b34-5041-471b-b39c-ce20aa001e08,last_downloaded:null,blob_created:Wed Oct 16 12:41:04 EDT 2019,blob_updated:Wed Oct 16 12:41:04 EDT 2019} v1}, remoteNodeId=null} to subscriber org.sonatype.nexus.repository.pypi.internal.PyPiGroupFacet$$EnhancerByGuice$$de319030@348eb2e6 method [public void org.sonatype.nexus.repository.pypi.internal.PyPiGroupFacet.on(org.sonatype.nexus.repository.storage.AssetCreatedEvent)]
java.lang.ClassCastException: Cannot cast org.sonatype.nexus.repository.pypi.internal.AssetKind to java.lang.String
at java.lang.Class.cast(Class.java:3369)
at org.sonatype.nexus.common.collect.AttributesMap.coerce(AttributesMap.java:75)
at org.sonatype.nexus.common.collect.AttributesMap.get(AttributesMap.java:153)
at org.sonatype.nexus.common.collect.AttributesMap.get(AttributesMap.java:162)
at org.sonatype.nexus.repository.pypi.internal.PyPiGroupFacet.maybeDeleteFromCache(PyPiGroupFacet.java:103)
at org.sonatype.nexus.repository.pypi.internal.PyPiGroupFacet.on(PyPiGroupFacet.java:90)
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:53)
at sun.reflect.GeneratedMethodAccessor649.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.google.common.eventbus.Subscriber.invokeSubscriberMethod(Subscriber.java:87)
at com.google.common.eventbus.Subscriber$1.run(Subscriber.java:72)
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:398)
at com.google.common.eventbus.Subscriber.dispatchEvent(Subscriber.java:67)
at com.google.common.eventbus.Dispatcher$ImmediateDispatcher.dispatch(Dispatcher.java:186)
at com.google.common.eventbus.EventBus.post(EventBus.java:212)
at org.sonatype.nexus.internal.event.EventManagerImpl.post(EventManagerImpl.java:127)
at org.sonatype.nexus.orient.entity.EntityHook.postEvents(EntityHook.java:316)
at org.sonatype.nexus.orient.entity.EntityHook.flushEvents(EntityHook.java:289)
at org.sonatype.nexus.orient.entity.EntityHook.onAfterTxCommit(EntityHook.java:174)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2949)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2870)
at org.sonatype.nexus.repository.storage.StorageTxImpl.commit(StorageTxImpl.java:176)
at sun.reflect.GeneratedMethodAccessor144.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:56)
at org.sonatype.nexus.common.stateguard.StateGuardAspect$1.invoke(StateGuardAspect.java:66)
at com.sun.proxy.$Proxy215.commit(Unknown Source)
at org.sonatype.nexus.transaction.TransactionalWrapper.proceedWithTransaction(TransactionalWrapper.java:67)
at org.sonatype.nexus.transaction.TransactionInterceptor.proceedWithTransaction(TransactionInterceptor.java:63)
at org.sonatype.nexus.transaction.TransactionInterceptor.invoke(TransactionInterceptor.java:52)
at org.sonatype.nexus.blobstore.restore.BaseRestoreBlobStrategy.doRestore(BaseRestoreBlobStrategy.java:129)
at org.sonatype.nexus.blobstore.restore.BaseRestoreBlobStrategy.restore(BaseRestoreBlobStrategy.java:93)
at org.sonatype.nexus.blobstore.restore.RestoreMetadataTask.restore(RestoreMetadataTask.java:134)
at org.sonatype.nexus.blobstore.restore.RestoreMetadataTask.execute(RestoreMetadataTask.java:102)
at org.sonatype.nexus.blobstore.restore.RestoreMetadataTask.execute(RestoreMetadataTask.java:1)
at org.sonatype.nexus.scheduling.TaskSupport.call(TaskSupport.java:100)
at org.sonatype.nexus.quartz.internal.task.QuartzTaskJob.doExecute(QuartzTaskJob.java:143)
at org.sonatype.nexus.quartz.internal.task.QuartzTaskJob.execute(QuartzTaskJob.java:106)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at org.sonatype.nexus.quartz.internal.QuartzThreadPool.lambda$0(QuartzThreadPool.java:143)
at org.sonatype.nexus.thread.internal.MDCAwareRunnable.run(MDCAwareRunnable.java:40)
at org.apache.shiro.subject.support.SubjectRunnable.doRun(SubjectRunnable.java:120)
at org.apache.shiro.subject.support.SubjectRunnable.run(SubjectRunnable.java:108)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-11-14 06:37:13,647-0500 INFO [quartz-5-thread-18] pypi-uat2-03 *SYSTEM org.sonatype.nexus.blobstore.restore.pypi.internal.PyPiRestoreBlobStrategy - Restored asset, blob store: OBSv2 Blob Store, repository: pypi-proxy, path: packages/78/7b/2e3657ede5369f0e88a1833c209cec095e3a8ba2665676a35d78aaee5ba2/pandas-0.25.1-cp35-cp35m-win_amd64.whl, blob name: packages/78/7b/2e3657ede5369f0e88a1833c209cec095e3a8ba2665676a35d78aaee5ba2/pandas-0.25.1-cp35-cp35m-win_amd64.whl, blob id: ce6c4b34-5041-471b-b39c-ce20aa001e08
2019-11-14 06:37:15,485-0500 WARN [event-8-thread-2314] pypi-uat2-03 *SYSTEM org.sonatype.nexus.repository.browse.internal.BrowseNodeManager - Problem generating browse nodes for Asset{metadata=AttachedEntityMetadata{schema=asset, document=#33:2680{bucket:#26:4,format:pypi,last_updated:Thu Nov 14 06:37:13 EST 2019,attributes:[3],component:#32:196,name:packages/78/7b/2e3657ede5369f0e88a1833c209cec095e3a8ba2665676a35d78aaee5ba2/pandas-0.25.1-cp35-cp35m-win_amd64.whl,size:8786520,content_type:application/zip,created_by:anonymous,created_by_ip:127.0.0.1,blob_ref:OBSv2 Blob Store@2BAF309D-7270A5D1-D4ECF511-A780BF17-4820F84E:ce6c4b34-5041-471b-b39c-ce20aa001e08,last_downloaded:null,blob_created:Wed Oct 16 12:41:04 EDT 2019,blob_updated:Wed Oct 16 12:41:04 EDT 2019} v1}, name=packages/78/7b/2e3657ede5369f0e88a1833c209cec095e3a8ba2665676a35d78aaee5ba2/pandas-0.25.1-cp35-cp35m-win_amd64.whl}
java.lang.NullPointerException: null
at org.sonatype.nexus.repository.storage.BrowseNodeEntityAdapter.maybeCreateParentNodes(BrowseNodeEntityAdapter.java:297)
at org.sonatype.nexus.repository.storage.BrowseNodeEntityAdapter.createAssetNode(BrowseNodeEntityAdapter.java:245)
at org.sonatype.nexus.repository.storage.BrowseNodeStoreImpl.lambda$1(BrowseNodeStoreImpl.java:142)
at org.sonatype.nexus.orient.transaction.OrientOperations.lambda$2(OrientOperations.java:62)
at org.sonatype.nexus.transaction.OperationPoint.lambda$0(OperationPoint.java:53)
at org.sonatype.nexus.transaction.OperationPoint.proceed(OperationPoint.java:64)
at org.sonatype.nexus.transaction.TransactionalWrapper.proceedWithTransaction(TransactionalWrapper.java:56)
at org.sonatype.nexus.transaction.Operations.proceedWithTransaction(Operations.java:220)
at org.sonatype.nexus.transaction.Operations.transactional(Operations.java:211)
at org.sonatype.nexus.transaction.Operations.run(Operations.java:166)
at org.sonatype.nexus.orient.transaction.OrientOperations.run(OrientOperations.java:62)
at org.sonatype.nexus.repository.storage.BrowseNodeStoreImpl.createAssetNode(BrowseNodeStoreImpl.java:142)
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:53)
at org.sonatype.nexus.repository.browse.internal.BrowseNodeManager.createBrowseNodes(BrowseNodeManager.java:111)
at org.sonatype.nexus.repository.browse.internal.BrowseNodeManager.createFromAsset(BrowseNodeManager.java:78)
at org.sonatype.nexus.repository.browse.internal.BrowseNodeEventHandler.lambda$0(BrowseNodeEventHandler.java:55)
at org.sonatype.nexus.repository.browse.internal.BrowseNodeEventHandler.handle(BrowseNodeEventHandler.java:79)
at org.sonatype.nexus.repository.browse.internal.BrowseNodeEventHandler.on(BrowseNodeEventHandler.java:55)
at sun.reflect.GeneratedMethodAccessor650.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.google.common.eventbus.Subscriber.invokeSubscriberMethod(Subscriber.java:87)
at com.google.common.eventbus.Subscriber$1.run(Subscriber.java:72)
at org.sonatype.nexus.internal.event.AffinityBarrier.lambda$1(AffinityBarrier.java:91)
at org.sonatype.nexus.thread.internal.MDCAwareRunnable.run(MDCAwareRunnable.java:40)
at org.apache.shiro.subject.support.SubjectRunnable.doRun(SubjectRunnable.java:120)
at org.apache.shiro.subject.support.SubjectRunnable.run(SubjectRunnable.java:108)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Diagnosis
There appears to be a code problem writing PyPi blob properties files to the blobstore.
Some code has pushed an actual AssetKind instance into the attributes rather than the expected string - and this has broken the PyPi filtering which expects a string, not the full class.
The result appears to be the asset should be downloadable and "restored", but will not appear in the Browse node, or may not function with any code which tries to read NestedAttributesMap for this asset.
Expected
Prevent the ERROR and the WARN from happening. Fix any underlying code problems that lead to these issues. Include an upgrade step or task which can repair these broken assets in existing instances being upgraded, or a groovy script that can be run to fix this in older versions. Make the reconcile task fully restore pypi assets.