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

Deleting a repository of non-trivial sizes lags and floods the log with exceptions

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 3.0.0-m4, 3.0.2, 3.1.0
    • Fix Version/s: 3.2.1
    • Component/s: Repository, Scalability
    • Labels:
      None
    • Story Points:
      3
    • Sprint:
      Sprint 86, Sprint 87

      Description

      I tried to delete the maven-central proxy out of my dev instance which contained 1000+ assets (from building goodies or nexus-internal). After clicking "Delete repository" from the UI no immediate user feedback about the operation was provided, the repo screen was still there showing the deleted "maven-central" repo. Meanwhile, the NX log got filled with the below exception, about every 5 seconds. After some time, the delete operations seems to finally have completed.

      2016-08-30 14:44:54,783+0200 ERROR [qtp1716242542-378] admin org.sonatype.nexus.extdirect.internal.ExtDirectServlet - Failed to invoke action method: coreui_Repository.coreui_Repository_readStatus, java-method: org.sonatype.nexus.coreui.RepositoryComponent.readStatus
      java.lang.IllegalStateException: Invalid state: DELETED; allowed: [STARTED]
              at org.sonatype.nexus.common.stateguard.StateGuard._ensure(StateGuard.java:115) [na:na]
              at org.sonatype.nexus.common.stateguard.StateGuard.access$1(StateGuard.java:108) [na:na]
              at org.sonatype.nexus.common.stateguard.StateGuard$GuardImpl.run(StateGuard.java:269) [na:na]
              at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:53) [na:na]
              at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source) [na:na]
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [na:1.8.0_74]
              at java.lang.reflect.Method.invoke(Method.java:498) [na:1.8.0_74]
              at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93) [na:na]
              at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325) [na:na]
              at org.codehaus.groovy.runtime.metaclass.MethodMetaProperty$GetBeanMethodMetaProperty.getProperty(MethodMetaProperty.java:76) [na:na]
              at org.codehaus.groovy.runtime.callsite.GetEffectivePojoPropertySite.getProperty(GetEffectivePojoPropertySite.java:64) [na:na]
              at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callGetProperty(AbstractCallSite.java:296) [na:na]
              at org.sonatype.nexus.coreui.RepositoryComponent.buildStatus(RepositoryComponent.groovy:249) [na:na]
              at sun.reflect.GeneratedMethodAccessor128.invoke(Unknown Source) [na:na]
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [na:1.8.0_74]
              at java.lang.reflect.Method.invoke(Method.java:498) [na:1.8.0_74]
              at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93) [na:na]
              at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325) [na:na]
              at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:384) [na:na]
              at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1019) [na:na]
              at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:69) [na:na]
              at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:166) [na:na]
              at org.sonatype.nexus.coreui.RepositoryComponent$_readStatus_closure6.doCall(RepositoryComponent.groovy:237) [na:na]
              at sun.reflect.GeneratedMethodAccessor127.invoke(Unknown Source) [na:na]
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [na:1.8.0_74]
              at java.lang.reflect.Method.invoke(Method.java:498) [na:1.8.0_74]
              at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93) [na:na]
              at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325) [na:na]
              at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:294) [na:na]
              at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1019) [na:na]
              at groovy.lang.Closure.call(Closure.java:426) [na:na]
              at groovy.lang.Closure.call(Closure.java:442) [na:na]
              at org.codehaus.groovy.runtime.DefaultGroovyMethods.collect(DefaultGroovyMethods.java:3170) [na:na]
              at org.codehaus.groovy.runtime.DefaultGroovyMethods.collect(DefaultGroovyMethods.java:3140) [na:na]
              at org.codehaus.groovy.runtime.dgm$66.invoke(Unknown Source) [na:na]
              at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite$PojoMetaMethodSiteNoUnwrapNoCoerce.invoke(PojoMetaMethodSite.java:274) [na:na]
              at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite.call(PojoMetaMethodSite.java:56) [na:na]
              at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:125) [na:na]
              at org.sonatype.nexus.coreui.RepositoryComponent.readStatus(RepositoryComponent.groovy:237) [na:na]
              at org.apache.shiro.guice.aop.AopAllianceMethodInvocationAdapter.proceed(AopAllianceMethodInvocationAdapter.java:49) [na:na]
              at org.apache.shiro.authz.aop.AuthorizingAnnotationMethodInterceptor.invoke(AuthorizingAnnotationMethodInterceptor.java:68) [na:na]
              at org.apache.shiro.guice.aop.AopAllianceMethodInterceptorAdapter.invoke(AopAllianceMethodInterceptorAdapter.java:36) [na:na]
              at sun.reflect.GeneratedMethodAccessor140.invoke(Unknown Source) [na:na]
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [na:1.8.0_74]
              at java.lang.reflect.Method.invoke(Method.java:498) [na:1.8.0_74]
              at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeJavaMethod(DispatcherBase.java:142) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeMethod(DispatcherBase.java:133) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at org.sonatype.nexus.extdirect.internal.ExtDirectServlet$3.invokeMethod(ExtDirectServlet.java:221) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.dispatch(DispatcherBase.java:63) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at com.softwarementors.extjs.djn.router.processor.poll.PollRequestProcessor.process(PollRequestProcessor.java:145) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at org.sonatype.nexus.extdirect.internal.ExtDirectServlet$4.processPollRequest(ExtDirectServlet.java:315) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.processRequest(DirectJNgineServlet.java:621) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.doPost(DirectJNgineServlet.java:580) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at org.sonatype.nexus.extdirect.internal.ExtDirectServlet.doPost(ExtDirectServlet.java:127) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.doGet(DirectJNgineServlet.java:553) [org.sonatype.nexus.extdirect:3.1.0.SNAPSHOT]
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) [javax.servlet-api:3.1.0]
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [javax.servlet-api:3.1.0]
              at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:287) [com.google.inject:4.0.0]
              at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:277) [com.google.inject:4.0.0]
              at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:182) [com.google.inject:4.0.0]
              at com.google.inject.servlet.DynamicServletPipeline.service(DynamicServletPipeline.java:71) [com.google.inject:4.0.0]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85) [com.google.inject:4.0.0]
              at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:112) [org.apache.shiro.web:1.2.4]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:112) [org.apache.shiro.web:1.2.4]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449) [org.apache.shiro.web:1.2.4]
              at org.sonatype.nexus.security.SecurityFilter.executeChain(SecurityFilter.java:85) [org.sonatype.nexus.security:3.1.0.SNAPSHOT]
              at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365) [org.apache.shiro.web:1.2.4]
              at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90) [org.apache.shiro.core:1.2.4]
              at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83) [org.apache.shiro.core:1.2.4]
              at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383) [org.apache.shiro.core:1.2.4]
              at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362) [org.apache.shiro.web:1.2.4]
              at org.sonatype.nexus.security.SecurityFilter.doFilterInternal(SecurityFilter.java:101) [org.sonatype.nexus.security:3.1.0.SNAPSHOT]
              at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [org.apache.shiro.web:1.2.4]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at com.sonatype.nexus.licensing.internal.LicensingRedirectFilter.doFilter(LicensingRedirectFilter.java:112) [com.sonatype.nexus.plugins.nexus-licensing-plugin:3.1.0.SNAPSHOT]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97) [com.codahale.metrics.servlet:3.0.2]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at org.sonatype.nexus.internal.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:63) [org.sonatype.nexus.base:3.1.0.SNAPSHOT]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at org.sonatype.nexus.internal.web.EnvironmentFilter.doFilter(EnvironmentFilter.java:97) [org.sonatype.nexus.base:3.1.0.SNAPSHOT]
              at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.0.0]
              at com.google.inject.servlet.DynamicFilterPipeline.dispatch(DynamicFilterPipeline.java:104) [com.google.inject:4.0.0]
              at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:133) [com.google.inject:4.0.0]
              at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:130) [com.google.inject:4.0.0]
              at com.google.inject.servlet.GuiceFilter$Context.call(GuiceFilter.java:203) [com.google.inject:4.0.0]
              at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:130) [com.google.inject:4.0.0]
              at org.sonatype.nexus.bootstrap.osgi.DelegatingFilter.doFilter(DelegatingFilter.java:73) [org.sonatype.nexus.bootstrap:3.1.0.SNAPSHOT]
              at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) [org.eclipse.jetty.servlet:9.3.7.v20160115]
              at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) [org.eclipse.jetty.servlet:9.3.7.v20160115]
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [org.eclipse.jetty.security:9.3.7.v20160115]
              at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1158) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) [org.eclipse.jetty.servlet:9.3.7.v20160115]
              at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1090) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119) [org.eclipse.jetty.server:9.3.7.v20160115]
              at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:175) [com.codahale.metrics.jetty9:3.0.2]
              at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.Server.handle(Server.java:517) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:242) [org.eclipse.jetty.server:9.3.7.v20160115]
              at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [org.eclipse.jetty.io:9.3.7.v20160115]
              at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [org.eclipse.jetty.io:9.3.7.v20160115]
              at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:75) [org.eclipse.jetty.io:9.3.7.v20160115]
              at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:213) [org.eclipse.jetty.util:9.3.7.v20160115]
              at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:147) [org.eclipse.jetty.util:9.3.7.v20160115]
              at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654) [org.eclipse.jetty.util:9.3.7.v20160115]
              at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) [org.eclipse.jetty.util:9.3.7.v20160115]
              at java.lang.Thread.run(Thread.java:745) [na:1.8.0_74]
      ...
      2016-08-30 14:44:59,903+0200 ERROR [qtp1716242542-429] admin org.sonatype.nexus.extdirect.internal.ExtDirectServlet - Failed to invoke action method: coreui_Repository.coreui_Repository_readStatus, java-method: org.sonatype.nexus.coreui.RepositoryComponent.readStatus
      java.lang.IllegalStateException: Invalid state: DELETED; allowed: [STARTED]
      
      2016-08-30 14:45:04,936+0200 ERROR [qtp1716242542-383] admin org.sonatype.nexus.extdirect.internal.ExtDirectServlet - Failed to invoke action method: coreui_Repository.coreui_Repository_readStatus, java-method: org.sonatype.nexus.coreui.RepositoryComponent.readStatus
      java.lang.IllegalStateException: Invalid state: DELETED; allowed: [STARTED]
      

      cf. https://github.com/sonatype/nexus-internal/blob/0a364dc7b5085ad1f02781a0752f23a268c5125d/components/nexus-repository/src/main/java/org/sonatype/nexus/repository/storage/StorageFacetImpl.java#L190

        Issue Links

          Activity

          Hide
          jtom Joe Tom added a comment -

          Ends up generating every 10 min by design.

          2017-01-30 16:30:00,016-0500 INFO  [quartz-2-thread-1] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Storage facet cleanup' [repository.storage-facet-cleanup] state change WAITING -> RUNNING
          2017-01-30 16:30:00,032-0500 INFO  [quartz-2-thread-1] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Storage facet cleanup' [repository.storage-facet-cleanup] state change RUNNING -> WAITING (OK)
          
          Show
          jtom Joe Tom added a comment - Ends up generating every 10 min by design. 2017-01-30 16:30:00,016-0500 INFO [quartz-2-thread-1] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Storage facet cleanup' [repository.storage-facet-cleanup] state change WAITING -> RUNNING 2017-01-30 16:30:00,032-0500 INFO [quartz-2-thread-1] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Storage facet cleanup' [repository.storage-facet-cleanup] state change RUNNING -> WAITING (OK)
          Hide
          wwannemacher Wes Wannemacher added a comment -

          Tested in HA and non-HA setups. Also tested by shutting down nexus after deleting the repo and then starting nexus back up and the Storage facet cleanup task found the deleted repo. Deleted a repo and then created a new one with the same name and type. New repo did not contain any assets from the old repo, and the cleanup task found the old bucket and removed it (verified by running a compact blobstore task subsequently and watched the blobstore size decrease to zero).

          Show
          wwannemacher Wes Wannemacher added a comment - Tested in HA and non-HA setups. Also tested by shutting down nexus after deleting the repo and then starting nexus back up and the Storage facet cleanup task found the deleted repo. Deleted a repo and then created a new one with the same name and type. New repo did not contain any assets from the old repo, and the cleanup task found the old bucket and removed it (verified by running a compact blobstore task subsequently and watched the blobstore size decrease to zero).

            People

            • Assignee:
              wwannemacher Wes Wannemacher
              Reporter:
              bentmann Benjamin Bentmann
              Last Updated By:
              Benjamin Bentmann
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:
                Date of First Response:

                Agile