Over the past few days we have been struggling with an issue where we are unable to read or push anything towards our Nexus instance and the only way to recover is to restore it from a backup.
At the time tons of the below message appear (like 2-3 every milli second).
2022-06-23 07:49:30,635+0000 WARN [qtp1258398841-613] ci.user com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster - $ANSI{green {db=component}} Page in file asset_14.pcl with index 154 was placed in wrong free list, this error will be fixed automatically.
The issue re-appears randomly after a restore on the same asset file and the same indexes are reported.
Around a month ago we have upgraded our instance to 3.37.3, where the issue initially occurred. Yesterday we have upgraded to 3.39.0, hoping that it would sort this out.
Looking at OrientDB’s github repository, there was a similar issue reported and there seems to be a solution in version 3, however Nexus is still using v2 of the database.
So far we have checked the filesystem for consistency checks, ran checks on the orientdb, rebuilt the indexes. All seems to be in order, no issues were noted.
Do you have idea what could be going wrong here? Any feedback would be appreciated.
[INFO] --- maven-deploy-plugin:2.8.2:deploy (default-cli) @ MyMavenModule ---
[INFO] Downloading from nxrm: https://internal.corp/repository/maven-snapshots/com/corp/artifact-name/1.0-SNAPSHOT/maven-metadata.xml
[INFO] Downloaded from nxrm: https://internal.corp/repository/maven-snapshots/com/corp/artifact-name/1.0-SNAPSHOT/maven-metadata.xml (853 B at 36 kB/s)
[INFO] Uploading to nxrm: https://internal.corp/repository/maven-snapshots/com/corp/artifact-name/1.0-SNAPSHOT/MyMavenModule-1.0-20230112.192706-2.sbar
[INFO] Uploaded to nxrm: https://internal.corp/repository/maven-snapshots/com/corp/artifact-name/1.0-SNAPSHOT/MyMavenModule-1.0-20230112.192706-2.sbar (24 kB at 623 kB/s)
[INFO] Uploading to nxrm: https://internal.corp/repository/maven-snapshots/com/corp/artifact-name/1.0-SNAPSHOT/MyMavenModule-1.0-20230112.192706-2.pom
[WARNING] Failed to upload checksum to com/corp/artifact-name/1.0-SNAPSHOT/MyMavenModule-1.0-20230112.192706-2.pom.md5
org.apache.maven.wagon.TransferFailedException: transfer failed for https://internal.corp/repository/maven-snapshots/com/corp/artifact-name/1.0-SNAPSHOT/MyMavenModule-1.0-20230112.192706-2.pom.md5, status: 502 Proxy Error
Nexus didn’t show any error or warning relating to the problem. It just started spamming
WARN [qtp1199388610-444] nxrm_uploader com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedCluster - $ANSI{green {db=component}} Page in file asset.pcl with index 9712 was placed in wrong free list, this error will be fixed automatically
at an incredible speed (about 1GB per 10min), with the “index #” being different every time.
This has rendered our Nexus Pro (which 100+ devs depend on) useless.
When trying to shutdown the Nexus service (systemctl stop nexus.service) the shutdown task would timeout and the Nexus JVM would jump to 100% CPU and stay there for an hour. I finally had to kill -9 the whole thing.
Tried:
orientdb {db=component}> REBUILD INDEX *
rm -rf ./sonatype-work/nexus3/cache
Didn’t seem to work. Nexus will startup just fine after killing it. Everything looks okay and artifacts can be downloaded normally. But as soon as I upload a Maven artifact, the whole thing explodes again and it starts spamming the Page in file asset.pcl with index #### was placed in wrong free list error again.
Running on Nexus Repository 3.45.0 with OrientDB Server v2.2.37
Update: seems I’ve managed to fix it by basically emptying most of the repository. So:
Set a clean-up policy on the repository that deletes everything older than 1 day (wanted to set it to 1 hour, but that’s not possible unfortunately).
Run the clean-up task.
Manually delete the parent folder of the artifact that originally introduced the error, using the web-interface. Very lucky I was able to determine the exact artifact (or close enough) in the build-logs to be able to pinpoint it. I just deleted the entire parent group-id dir folder.
Run “compact blob store” on the affected blob store.
Restart Nexus service.
Try another build (fingers crossed).
Bullet dodged it seems. Feeling lucky that it appears to only have affected our “snapshots” repo. If this were a “releases” repo, the severity of the situation would be entirely different.
Not feeling very confident in Nexus at the moment…
we had the same issue .
it seems that is happened after a full of space on the disk but not sure of that .
tried to delete the cache and rebuild the index but does not fix the issue
the only thing that fixed our issue is deleting all data in mavens repos manually (right click on each folder from the UI)
Interestingly: when in corrupted state, I get the following NullPointerException errors when selecting any component in the Nexus “Browse” view, when the component is in a Maven repository (and shares the blob store):
2023-02-22 00:33:03,392+0100 ERROR [qtp1302364433-451] NexusAdminAccount org.sonatype.nexus.extdirect.internal.ExtDirectExceptionHandler - Failed to invoke action method: healthcheck_AssetDetail.identify, java-method: com.sonatype.nexus.plugins.healthcheck.pro.internal.ui.HealthCheckAssetDetailComponent.identify
java.lang.NullPointerException: null
at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:880)
at org.sonatype.nexus.repository.storage.StorageTxImpl.findComponent(StorageTxImpl.java:498)
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)
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$GuardImpl.run(StateGuard.java:272)
at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:54)
at org.sonatype.nexus.common.stateguard.StateGuardAspect$1.invoke(StateGuardAspect.java:63)
at com.sun.proxy.$Proxy250.findComponent(Unknown Source)
at com.sonatype.nexus.plugins.healthcheck.pro.internal.ui.orient.OrientAssetIdentificationService.lambda$8(OrientAssetIdentificationService.java:120)
at org.sonatype.nexus.transaction.OperationPoint.proceed(OperationPoint.java:64)
at org.sonatype.nexus.transaction.TransactionalWrapper.proceedWithTransaction(TransactionalWrapper.java:58)
at org.sonatype.nexus.transaction.Operations.proceedWithTransaction(Operations.java:237)
at org.sonatype.nexus.transaction.Operations.transactional(Operations.java:228)
at org.sonatype.nexus.transaction.Operations.call(Operations.java:171)
at com.sonatype.nexus.plugins.healthcheck.pro.internal.ui.orient.OrientAssetIdentificationService.identify(OrientAssetIdentificationService.java:118)
at com.sonatype.nexus.plugins.healthcheck.pro.internal.ui.AssetIdentificationService$identify.call(Unknown Source)
at com.sonatype.nexus.plugins.healthcheck.pro.internal.ui.HealthCheckAssetDetailComponent.identify(HealthCheckAssetDetailComponent.groovy:47)
at com.palominolabs.metrics.guice.ExceptionMeteredInterceptor.invoke(ExceptionMeteredInterceptor.java:23)
at com.palominolabs.metrics.guice.TimedInterceptor.invoke(TimedInterceptor.java:26)
at org.sonatype.nexus.validation.internal.ValidationInterceptor.invoke(ValidationInterceptor.java:53)
at org.apache.shiro.guice.aop.AopAllianceMethodInvocationAdapter.proceed(AopAllianceMethodInvocationAdapter.java:49)
at org.apache.shiro.authz.aop.AuthorizingAnnotationMethodInterceptor.invoke(AuthorizingAnnotationMethodInterceptor.java:68)
at org.apache.shiro.guice.aop.AopAllianceMethodInterceptorAdapter.invoke(AopAllianceMethodInterceptorAdapter.java:36)
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)
at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeJavaMethod(DispatcherBase.java:142)
at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeMethod(DispatcherBase.java:133)
at org.sonatype.nexus.extdirect.internal.ExtDirectDispatcher.invokeMethod(ExtDirectDispatcher.java:82)
at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.dispatch(DispatcherBase.java:63)
at com.softwarementors.extjs.djn.router.processor.standard.StandardRequestProcessorBase.dispatchStandardMethod(StandardRequestProcessorBase.java:73)
at com.softwarementors.extjs.djn.router.processor.standard.json.JsonRequestProcessor.processIndividualRequest(JsonRequestProcessor.java:502)
at com.softwarementors.extjs.djn.router.processor.standard.json.JsonRequestProcessor.processIndividualRequestsInThisThread(JsonRequestProcessor.java:150)
at com.softwarementors.extjs.djn.router.processor.standard.json.JsonRequestProcessor.process(JsonRequestProcessor.java:133)
at com.softwarementors.extjs.djn.router.RequestRouter.processJsonRequest(RequestRouter.java:83)
at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.processRequest(DirectJNgineServlet.java:632)
at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.doPost(DirectJNgineServlet.java:595)
at org.sonatype.nexus.extdirect.internal.ExtDirectServlet.doPost(ExtDirectServlet.java:137)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:290)
at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:280)
at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:184)
at com.google.inject.servlet.DynamicServletPipeline.service(DynamicServletPipeline.java:71)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
at org.sonatype.nexus.security.SecurityFilter.executeChain(SecurityFilter.java:96)
at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
at org.sonatype.nexus.security.SecurityFilter.doFilterInternal(SecurityFilter.java:112)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:112)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:458)
at org.sonatype.nexus.security.SecurityFilter.executeChain(SecurityFilter.java:96)
at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:373)
at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:387)
at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:370)
at org.sonatype.nexus.security.SecurityFilter.doFilterInternal(SecurityFilter.java:112)
at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:154)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at com.sonatype.nexus.licensing.internal.LicensingRedirectFilter.doFilter(LicensingRedirectFilter.java:116)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:112)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at org.sonatype.nexus.internal.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:79)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at org.sonatype.nexus.internal.web.EnvironmentFilter.doFilter(EnvironmentFilter.java:101)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at org.sonatype.nexus.internal.web.HeaderPatternFilter.doFilter(HeaderPatternFilter.java:98)
at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at com.google.inject.servlet.DynamicFilterPipeline.dispatch(DynamicFilterPipeline.java:104)
at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
at org.sonatype.nexus.bootstrap.osgi.DelegatingFilter.doFilter(DelegatingFilter.java:73)
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:201)
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:239)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:516)
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
at java.lang.Thread.run(Thread.java:750)
Update: okay so I think I’ve got the remediation steps sorted.
If Nexus is still running and spamming Page in file asset.pcl with index #### was placed in wrong free list, shut it down immediately. If it won’t shut down properly, kill -9 it.
Search your logs for the exact artifact that introduced the error. This could be in the access logs, but for me it was in the Jenkins build logs: [WARNING] Failed to upload checksum to com/corp/artifact-name/1.0-SNAPSHOT/my-app-1.0-20230221.153925-1-.war.sha1
Start Nexus. It shouldn’t start spamming immediately. Only trying to upload a new artifact will trigger the flood. So make sure no artifacts are being uploaded.
In the Nexus UI (Browse mode), find the artifact which caused the error.
Delete the entire artifact folder (the folder containing the maven-metadata.xml). This should be enough, but if the problem persists, you might need to remove more and more parent folders.
Run “Admin - Cleanup repositories using their associated policies”
Run “Admin - Compact blob store” for the relevant Maven blob stores.
Restart Nexus.
Upload artifacts as normal.
I hope Sonatype can provide some insights into this problem.
In my case, both times the issue was triggered during [WARNING] Failed to upload checksum, once for an .md5 and once for an .sha1
In the end, we couldn’t fix this and it happened more and more frequently.
So we decided to migrate from OrientDB to PostgreSQL with haste using Migrating to a New Database
This has resolved the issue for us, but this path might not be available to everyone. We’re looking into doing a postmortem on the original OrientDB to see if we can find the cause (or at least a workable solution).
