Uploaded image for project: 'Dev - Nexus Repo'
  1. Dev - Nexus Repo
  2. NEXUS-21315

Extremely slow processing in "Docker - Delete unused manifests and images" task

    XMLWordPrintable

    Details

    • Notability:
      2

      Description

      There is a major bottleneck in event processing in the "docker - delete unused manifests and images" task.  See the attached thread dumps.

       

      For example in the thread1.txt file the task thread is blocked by this event thread, which is running "BrowseNodeEntityAdapter.maybeDeleteParents"

      "quartz-3-thread-1" id=387 state=BLOCKED
      
          - waiting to lock <0x5c104d14> (a com.google.common.eventbus.Subscriber$SynchronizedSubscriber)
      
          owned by event-6-thread-7994 <command>sql.select count(*) from browse_node where (repository_name=:repository_name and parent_path=:base_path)</command> id=10713
      
          at com.google.common.eventbus.Subscriber$SynchronizedSubscriber.invokeSubscriberMethod(Subscriber.java:143)
      
          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.internal.event.AffinityBarrier$$Lambda$418/952964078.run(Unknown Source)
      
          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 org.sonatype.nexus.internal.event.EventExecutor.lambda$0(EventExecutor.java:72)
      
          at org.sonatype.nexus.internal.event.EventExecutor$$Lambda$30/1871696384.rejectedExecution(Unknown Source)
      
          at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
      
          at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
      
          at org.apache.shiro.concurrent.SubjectAwareExecutor.execute(SubjectAwareExecutor.java:129)
      
          at org.sonatype.nexus.internal.event.AffinityBarrier.execute(AffinityBarrier.java:89)
      
          at org.sonatype.nexus.internal.event.EventExecutor.execute(EventExecutor.java:215)
      
          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.lambda$0(EventManagerImpl.java:132)
      
          at org.sonatype.nexus.internal.event.EventManagerImpl$$Lambda$248/1238197687.run(Unknown Source)
      
          at org.sonatype.nexus.internal.event.AffinityBarrier.lambda$0(AffinityBarrier.java:75)
      
          at org.sonatype.nexus.internal.event.AffinityBarrier$$Lambda$249/34327242.run(Unknown Source)
      
          at com.google.common.util.concurrent.SequentialExecutor$1.run(SequentialExecutor.java:120)
      
          at com.google.common.util.concurrent.SequentialExecutor$QueueWorker.workOnQueue(SequentialExecutor.java:227)
      
          at com.google.common.util.concurrent.SequentialExecutor$QueueWorker.run(SequentialExecutor.java:171)
      
          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 org.sonatype.nexus.internal.event.EventExecutor.lambda$0(EventExecutor.java:72)
      
          at org.sonatype.nexus.internal.event.EventExecutor$$Lambda$30/1871696384.rejectedExecution(Unknown Source)
      
          at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
      
          at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
      
          at org.apache.shiro.concurrent.SubjectAwareExecutor.execute(SubjectAwareExecutor.java:129)
      
          at com.google.common.util.concurrent.SequentialExecutor.execute(SequentialExecutor.java:128)
      
          at org.sonatype.nexus.internal.event.AffinityBarrier.coordinate(AffinityBarrier.java:71)
      
          at org.sonatype.nexus.internal.event.EventExecutor.executeWithAffinity(EventExecutor.java:199)
      
          at org.sonatype.nexus.internal.event.EventManagerImpl.post(EventManagerImpl.java:132)
      
          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.GeneratedMethodAccessor139.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.$Proxy237.commit(Unknown Source)
      
          at org.sonatype.nexus.repository.docker.internal.DockerGCFacetImpl.maybeCommit(DockerGCFacetImpl.java:219)
      
          at org.sonatype.nexus.repository.docker.internal.DockerGCFacetImpl.handleV2Assets(DockerGCFacetImpl.java:207)
      
          at org.sonatype.nexus.repository.docker.internal.DockerGCFacetImpl.processRepository(DockerGCFacetImpl.java:92)
      
          at org.sonatype.nexus.repository.docker.internal.DockerGCFacetImpl$$EnhancerByGuice$$506be339.CGLIB$processRepository$0(<generated>)
      
          at org.sonatype.nexus.repository.docker.internal.DockerGCFacetImpl$$EnhancerByGuice$$506be339$$FastCl
      
       
      {quote}
      
      The event thread it is waiting for is running "BrowseNodeEntityAdapter.maybeDeleteParents":
      
      
      {quote}"event-6-thread-7994 <command>sql.select count(*) from browse_node where (repository_name=:repository_name and parent_path=:base_path)</command>" id=10713 state=RUNNABLE
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.checkForSystemClusters(OCommandExecutorSQLSelect.java:698)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.addResult(OCommandExecutorSQLSelect.java:722)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.handleResult(OCommandExecutorSQLSelect.java:670)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearchRecord(OCommandExecutorSQLSelect.java:627)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.serialIterator(OCommandExecutorSQLSelect.java:1638)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchFromTarget(OCommandExecutorSQLSelect.java:1585)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchValuesFromIndexCursor(OCommandExecutorSQLSelect.java:2466)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchForIndexes(OCommandExecutorSQLSelect.java:2280)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchInClasses(OCommandExecutorSQLSelect.java:1017)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:203)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:527)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:509)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:485)
      
          at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:70)
      
          at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3400)
      
          at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3318)
      
          at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
      
          at org.sonatype.nexus.repository.storage.BrowseNodeEntityAdapter.maybeDeleteParents(BrowseNodeEntityAdapter.java:423)
      
          at org.sonatype.nexus.repository.storage.BrowseNodeEntityAdapter.deleteAssetNode(BrowseNodeEntityAdapter.java:369)
      
          at org.sonatype.nexus.repository.storage.BrowseNodeStoreImpl.lambda$3(BrowseNodeStoreImpl.java:154)
      
          at org.sonatype.nexus.repository.storage.BrowseNodeStoreImpl$$Lambda$427/479889005.accept(Unknown Source)
      
          at org.sonatype.nexus.orient.transaction.OrientOperations.lambda$2(OrientOperations.java:63)
      
          at org.sonatype.nexus.orient.transaction.OrientOperations$$Lambda$175/75352542.run(Unknown Source)
      
          at org.sonatype.nexus.transaction.OperationPoint.lambda$0(OperationPoint.java:53)
      
          at org.sonatype.nexus.transaction.OperationPoint$$Lambda$176/1844077848.call(Unknown Source)
      
          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.transactional(Operations.java:200)
      
          at org.sonatype.nexus.transaction.Operations.run(Operations.java:155)
      
       
      
       
      {quote}
       
      
      And there are 90 more event threads queued up waiting to run the same thing:
      
      
      {quote}"event-6-thread-7906" id=10625 state=BLOCKED
      
          - waiting to lock <0x5c104d14> (a com.google.common.eventbus.Subscriber$SynchronizedSubscriber)
      
          owned by event-6-thread-7994 <command>sql.select count(*) from browse_node where (repository_name=:repository_name and parent_path=:base_path)</command> id=10713
      
          at com.google.common.eventbus.Subscriber$SynchronizedSubscriber.invokeSubscriberMethod(Subscriber.java:143)
      
          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.internal.event.AffinityBarrier$$Lambda$418/952964078.run(Unknown Source)
      
          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:1142)
      
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      
          at java.lang.Thread.run(Thread.java:745)
      

      The task thread is being starved.

        Attachments

          Activity

            People

            Assignee:
            mjohnson Matt Johnson
            Reporter:
            rseddon Rich Seddon
            Last Updated By:
            Rich Seddon Rich Seddon
            Team:
            NXRM - Neo
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:
              Date of First Response:

                tigCommentSecurity.panel-title