Uploaded image for project: 'Artifactory Binary Repository'
  1. Artifactory Binary Repository
  2. RTFACT-25120

JFRT NodeEventSweeper logs NullPointerExcetions and ents-event-sweeper 'Unable to execute event on path' on maven snapshots repository

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Resolution: Unresolved
    • Affects Version/s: 7.12.3
    • Fix Version/s: None
    • Component/s: Artifactory
    • Labels:

      Description

      Artifactory Pro logs at lot of lines from ents-event-sweeper failures:
       

      2021-03-05T08:16:41.457Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:106  ] [ents-event-sweeper-0] - Unable to execute event on path oskari.org-snapshots-cache/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-
      20210303.221510-105.pom                                                                                                                                                                                                                                
      2021-03-05T08:16:41.458Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:107  ] [ents-event-sweeper-0] -                                                                                                                                  
      2021-03-05T08:16:41.458Z [jfrt ] [WARN ] [bac96efb62baa569] [o.j.c.ExecutionUtils:142      ] [ents-event-sweeper-0] - Retry 1 Elapsed 2 millis failed: Unable to execute event: PrioritizedNodeEvent(priorityId=1887160, path=oskari.org-snapshots-cach
      e/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-20210303.221510-105.pom, type=props, operatorId=metadata-operator-events, priority=1, timestamp=1614845336319, retryCount=1, status=PENDING) in event category: metadata-operat
      or-events. Trying again                                                                                                                                                                                                                                
      2021-03-05T08:16:42.959Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:106  ] [ents-event-sweeper-0] - Unable to execute event on path oskari.org-snapshots-cache/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-
      20210303.221510-105.pom                                                                                                                                                                                                                                
      2021-03-05T08:16:42.961Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:107  ] [ents-event-sweeper-0] -                                                                                                                                  
      2021-03-05T08:16:42.963Z [jfrt ] [WARN ] [bac96efb62baa569] [o.j.c.ExecutionUtils:142      ] [ents-event-sweeper-0] - Retry 2 Elapsed 1.51 secs failed: Unable to execute event: PrioritizedNodeEvent(priorityId=1887160, path=oskari.org-snapshots-cac
      he/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-20210303.221510-105.pom, type=props, operatorId=metadata-operator-events, priority=1, timestamp=1614845336319, retryCount=2, status=PENDING) in event category: metadata-opera
      tor-events. Trying again                                                                                                                                                                                                                               
      2021-03-05T08:16:47.464Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:106  ] [ents-event-sweeper-0] - Unable to execute event on path oskari.org-snapshots-cache/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-
      20210303.221510-105.pom                                                                                                                                                                                                                                
      2021-03-05T08:16:47.466Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:107  ] [ents-event-sweeper-0] -                                                                                                                                  
      2021-03-05T08:16:47.468Z [jfrt ] [WARN ] [bac96efb62baa569] [o.j.c.ExecutionUtils:142      ] [ents-event-sweeper-0] - Retry 3 Elapsed 6.01 secs failed: Unable to execute event: PrioritizedNodeEvent(priorityId=1887160, path=oskari.org-snapshots-cac
      he/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-20210303.221510-105.pom, type=props, operatorId=metadata-operator-events, priority=1, timestamp=1614845336319, retryCount=3, status=PENDING) in event category: metadata-opera
      tor-events. Trying again                                                                                                                                                                                                                               
      2021-03-05T08:16:53.470Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:106  ] [ents-event-sweeper-0] - Unable to execute event on path oskari.org-snapshots-cache/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-
      20210303.221510-105.pom                                                                                                                                                                                                                                
      2021-03-05T08:16:53.472Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:107  ] [ents-event-sweeper-0] -                                                                                                                                  
      2021-03-05T08:16:53.474Z [jfrt ] [WARN ] [bac96efb62baa569] [o.j.c.ExecutionUtils:142      ] [ents-event-sweeper-0] - Retry 4 Elapsed 12.02 secs failed: Unable to execute event: PrioritizedNodeEvent(priorityId=1887160, path=oskari.org-snapshots-ca
      che/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-20210303.221510-105.pom, type=props, operatorId=metadata-operator-events, priority=1, timestamp=1614845336319, retryCount=4, status=PENDING) in event category: metadata-oper
      ator-events. Trying again                                                                                                                                                                                                                              
      2021-03-05T08:16:59.475Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:106  ] [ents-event-sweeper-0] - Unable to execute event on path oskari.org-snapshots-cache/org/oskari/control-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-
      20210303.221510-105.pom                                                                                                                                                                                                                                
      2021-03-05T08:16:59.476Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:107  ] [ents-event-sweeper-0] -                                                                                                                                  
      2021-03-05T08:16:59.479Z [jfrt ] [WARN ] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:123  ] [ents-event-sweeper-0] - Short-term retry attempts exhausted at '5' retries for 'oskari.org-snapshots-cache/org/oskari/control-statistics/2.2.0-SNAPSHOT/c
      ontrol-statistics-2.2.0-20210303.221510-105.pom'                                                                                                                                                                                                       
      2021-03-05T08:16:59.482Z [jfrt ] [ERROR] [bac96efb62baa569] [o.j.c.ExecutionUtils:155      ] [ents-event-sweeper-0] - Last retry failed: Unable to execute event: PrioritizedNodeEvent(priorityId=1887160, path=oskari.org-snapshots-cache/org/oskari/c
      ontrol-statistics/2.2.0-SNAPSHOT/control-statistics-2.2.0-20210303.221510-105.pom, type=props, operatorId=metadata-operator-events, priority=1, timestamp=1614845336319, retryCount=5, status=PROCESSED) in event category: metadata-operator-events. N
      ot trying again (exceeded number of attempts (5))                                                                                                                                                                                                      
      

      Similar errors are spawned from other maven-2-default local and remote repositories.

      Time to time there are also quite a few NullPointerExceptions:

      2021-03-05T08:17:35.588Z [jfrt ] [ERROR] [bac96efb62baa569] [o.a.e.w.NodeEventSweeper:107  ] [ents-event-sweeper-3] - 
      java.lang.NullPointerException: null
      	at org.artifactory.addon.xray.XrayServiceImpl.getXrayVersion(XrayServiceImpl.java:365)
      	at jdk.internal.reflect.GeneratedMethodAccessor554.invoke(Unknown Source)
      	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:205)
      	at com.sun.proxy.$Proxy367.getXrayVersion(Unknown Source)
      	at org.artifactory.addon.xray.XrayAddonImpl.getXrayVersion(XrayAddonImpl.java:618)
      	at org.artifactory.addon.xray.XrayAddonImpl.isXrayOfMinimalRequiredVersion(XrayAddonImpl.java:123)
      	at jdk.internal.reflect.GeneratedMethodAccessor553.invoke(Unknown Source)
      	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:205)
      	at com.sun.proxy.$Proxy369.isXrayOfMinimalRequiredVersion(Unknown Source)
      	at org.artifactory.metadata.service.provider.MavenMetadataProvider$MavenTypeSpecificMetadataTemplate.isUniqueSnapshotHandlingSupported(MavenMetadataProvider.java:109)
      	at org.artifactory.metadata.service.provider.MavenMetadataProvider$MavenTypeSpecificMetadataTemplate.lambda$getVersion$0(MavenMetadataProvider.java:89)
      	at java.base/java.util.Optional.map(Optional.java:265)
      	at org.artifactory.metadata.service.provider.MavenMetadataProvider$MavenTypeSpecificMetadataTemplate.getVersion(MavenMetadataProvider.java:81)
      	at org.artifactory.metadata.service.provider.AbstractMetadataProvider.lambda$versionResolver$14(AbstractMetadataProvider.java:208)
      	at org.artifactory.metadata.service.provider.AbstractMetadataProvider.lambda$supplement$0(AbstractMetadataProvider.java:70)
      	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
      	at org.artifactory.metadata.service.provider.AbstractMetadataProvider.supplement(AbstractMetadataProvider.java:70)
      	at org.artifactory.metadata.service.MetadataEntityFacade.createMutableMetadataEntityBOM(MetadataEntityFacade.java:194)
      	at org.artifactory.metadata.service.MetadataEntityFacade.createMdsPackage(MetadataEntityFacade.java:176)
      	at java.base/java.util.Optional.map(Optional.java:265)
      	at org.artifactory.metadata.service.MetadataEntityFacade.createMetadataEntity(MetadataEntityFacade.java:87)
      	at org.artifactory.metadata.service.MetadataEventServiceImpl.prioritizedEventToMetadataEvent(MetadataEventServiceImpl.java:540)
      	at org.artifactory.metadata.service.MetadataEventServiceImpl.operateOnEvent(MetadataEventServiceImpl.java:247)
      	at org.artifactory.event.work.NodeEventSweeper.doProcessEvent(NodeEventSweeper.java:96)
      	at org.artifactory.event.work.NodeEventSweeper.lambda$tryToProcessEvent$0(NodeEventSweeper.java:79)
      	at org.artifactory.event.work.NodeEventSweeper.lambda$executeWithRetry$2(NodeEventSweeper.java:103)
      	at org.jfrog.common.ExecutionUtils.handleFunctionExecution(ExecutionUtils.java:100)
      	at org.jfrog.common.ExecutionUtils.lambda$generateExecutionRunnable$0(ExecutionUtils.java:67)
      	at org.jfrog.common.ExecutionUtils$MDCRunnableDecorator.run(ExecutionUtils.java:172)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
      	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
      	at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:322)
      	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:36)
      	at org.jfrog.common.ExecutionUtils.handleRetry(ExecutionUtils.java:129)
      	at org.jfrog.common.ExecutionUtils.handleFunctionExecution(ExecutionUtils.java:106)
      	at org.jfrog.common.ExecutionUtils.lambda$generateExecutionRunnable$0(ExecutionUtils.java:67)
      	at org.jfrog.common.ExecutionUtils$MDCRunnableDecorator.run(ExecutionUtils.java:172)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
      	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
      	at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:322)
      	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:36)
      	at org.jfrog.common.ExecutionUtils.handleRetry(ExecutionUtils.java:129)
      	at org.jfrog.common.ExecutionUtils.handleFunctionExecution(ExecutionUtils.java:106)
      	at org.jfrog.common.ExecutionUtils.lambda$generateExecutionRunnable$0(ExecutionUtils.java:67)
      	at org.jfrog.common.ExecutionUtils$MDCRunnableDecorator.run(ExecutionUtils.java:172)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
      	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
      	at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:322)
      	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:36)
      	at org.jfrog.common.ExecutionUtils.handleRetry(ExecutionUtils.java:129)
      	at org.jfrog.common.ExecutionUtils.handleFunctionExecution(ExecutionUtils.java:106)
      	at org.jfrog.common.ExecutionUtils.lambda$generateExecutionRunnable$0(ExecutionUtils.java:67)
      	at org.jfrog.common.ExecutionUtils$MDCRunnableDecorator.run(ExecutionUtils.java:172)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
      	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
      	at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:322)
      	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:36)
      	at org.jfrog.common.ExecutionUtils.handleRetry(ExecutionUtils.java:129)
      	at org.jfrog.common.ExecutionUtils.handleFunctionExecution(ExecutionUtils.java:106)
      	at org.jfrog.common.ExecutionUtils.lambda$generateExecutionRunnable$0(ExecutionUtils.java:67)
      	at org.jfrog.common.ExecutionUtils$MDCRunnableDecorator.run(ExecutionUtils.java:172)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
      	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
      	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
      	at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:322)
      	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:56)
      	at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:36)
      	at org.jfrog.common.ExecutionUtils.retry(ExecutionUtils.java:59)
      	at org.artifactory.event.work.NodeEventSweeper.executeWithRetry(NodeEventSweeper.java:101)
      	at org.artifactory.event.work.NodeEventSweeper.lambda$tryToProcessEvent$1(NodeEventSweeper.java:79)
      	at org.jfrog.common.concurrency.LockingUtilImpl.clusterExclusive(LockingUtilImpl.java:24)
      	at org.artifactory.event.work.EventOperatorDispatcher.runExclusive(EventOperatorDispatcher.java:270)
      	at org.artifactory.event.work.NodeEventSweeper.tryToProcessEvent(NodeEventSweeper.java:77)
      	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
      	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177)
      	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655)
      	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
      	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
      	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
      	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
      	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
      	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
      	at org.artifactory.event.work.NodeEventSweeper.run(NodeEventSweeper.java:67)
      	at org.artifactory.opentracing.TraceableRunnableDecorator.run(TraceableRunnableDecorator.java:26)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
      	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      	at java.base/java.lang.Thread.run(Thread.java:834)
      

      We used to have JFrog Xray, but dropped it from the renewed license, which might be related to the constant errors in log. The Xray's removal does not look like to be properly handled by Artifactory:

      JFrog Xray Integration
      Xray is currently disabled. No events are sent and new alerts are not being assigned to artifacts.

        Attachments

          Activity

              People

              Assignee:
              Unassigned
              Reporter:
              Kauhava Mikael Kauhava (Inactive)
              Votes:
              1 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated: