Details
-
Type:
Bug
-
Status: Closed
-
Priority:
Critical
-
Resolution: Fixed
-
Affects Version/s: 3.3.1, 3.4.0, 3.7.1, 3.10.0
-
Fix Version/s: 3.13.0
-
Component/s: Scheduled Tasks
-
Labels:
-
Story Points:3
Description
After restarting Nexus repository manager that has a large number of tasks, one or more tasks may
- transition to Starting state before Nexus boots
- never leaves Starting state to Started state
- the task has the Stop button enabled
- after clicking the Stop button the task is indefinitely in Cancelling state
- after the clicking the task Delete button, the task is indefinitely in Cancelling state
The nexus.log may show the task transitions from WAITING to RUNNING before Nexus reports it has fully booted - example: Rebuild Indexes:
2017-05-09 14:45:16,649+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.extender.NexusLifecycleManager - Start CAPABILITIES 2017-05-09 14:45:16,968+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.MigrationCapability - Loading 2017-05-09 14:45:16,982+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.extender.NexusLifecycleManager - Start TASKS 2017-05-09 14:45:17,118+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.QuartzSchedulerSPI - Scheduler put into ready mode 2017-05-09 14:45:17,125+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.MigrationCapability - Activating 2017-05-09 14:45:17,134+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.MigrationServiceImpl - Transitioning: NEW -> STARTED 2017-05-09 14:45:17,137+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.repository.RepositoryMigrationManagerImpl - Transitioning: NEW -> STARTED 2017-05-09 14:45:17,137+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.repository.RepositoryMigrationManagerImpl - Transitioned: STARTED 2017-05-09 14:45:17,189+0200 INFO [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.MigrationServiceImpl - Created assistant: com.sonatype.nexus.migration.assistant.MigrationAssistantImpl$$EnhancerByGuice$$bf043155@749e3389 2017-05-09 14:45:17,189+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.assistant.MigrationAssistantImpl - Starting 2017-05-09 14:45:17,190+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.assistant.MigrationAssistantImpl - Started 2017-05-09 14:45:17,190+0200 DEBUG [FelixStartLevel] *SYSTEM com.sonatype.nexus.migration.MigrationServiceImpl - Transitioned: STARTED 2017-05-09 14:45:17,275+0200 INFO [quartz-1-thread-1] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Rebuild Indexes' [repository.rebuild-index] state change WAITING -> RUNNING 2017-05-09 14:45:17,279+0200 INFO [quartz-1-thread-2] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Storage facet cleanup' [repository.storage-facet-cleanup] state change WAITING -> RUNNING 2017-05-09 14:45:17,370+0200 WARN [quartz-1-thread-2] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskJob - Task 0fd989ec-c4fc-4c4a-a8cc-004c178a0bde : 'Storage facet cleanup' [repository.storage-facet-cleanup] execution failure org.sonatype.nexus.common.stateguard.InvalidStateException: Invalid state: NEW; allowed: [STARTED] at org.sonatype.nexus.common.stateguard.StateGuard._ensure(StateGuard.java:115) [org.sonatype.nexus.common:3.3.1.01] at org.sonatype.nexus.common.stateguard.StateGuard.access$1(StateGuard.java:108) [org.sonatype.nexus.common:3.3.1.01] at org.sonatype.nexus.common.stateguard.StateGuard$GuardImpl.run(StateGuard.java:269) [org.sonatype.nexus.common:3.3.1.01] at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:53) [org.sonatype.nexus.common:3.3.1.01] at org.sonatype.nexus.repository.storage.internal.StorageFacetCleanupTask.execute(StorageFacetCleanupTask.java:48) [na:na] at org.sonatype.nexus.repository.storage.internal.StorageFacetCleanupTask.execute(StorageFacetCleanupTask.java:1) [na:na] at org.sonatype.nexus.scheduling.TaskSupport.call(TaskSupport.java:89) [org.sonatype.nexus.scheduling:3.3.1.01] at org.sonatype.nexus.quartz.internal.task.QuartzTaskJob.doExecute(QuartzTaskJob.java:145) [org.sonatype.nexus.quartz:3.3.1.01] at org.sonatype.nexus.quartz.internal.task.QuartzTaskJob.execute(QuartzTaskJob.java:106) [org.sonatype.nexus.quartz:3.3.1.01] at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [org.quartz-scheduler.quartz:2.2.2] at org.sonatype.nexus.thread.internal.MDCAwareRunnable.run(MDCAwareRunnable.java:40) [org.sonatype.nexus.thread:3.3.1.01] at org.apache.shiro.subject.support.SubjectRunnable.doRun(SubjectRunnable.java:120) [org.apache.shiro.core:1.3.2] at org.apache.shiro.subject.support.SubjectRunnable.run(SubjectRunnable.java:108) [org.apache.shiro.core:1.3.2] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_131] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_131] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_131] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_131] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131] 2017-05-09 14:45:17,386+0200 INFO [quartz-1-thread-2] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Storage facet cleanup' [repository.storage-facet-cleanup] state change RUNNING -> WAITING (FAILED) 2017-05-09 14:45:17,415+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Health Check: iits-npm-internal' [healthcheck] removed 2017-05-09 14:45:17,453+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Health Check: iits-npm-internal' [healthcheck] : state=WAITING 2017-05-09 14:45:17,483+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.scheduling.internal.TaskSchedulerImpl - Task 'Health Check: iits-npm-internal' [healthcheck] scheduled: hourly 2017-05-09 14:45:17,485+0200 INFO [FelixStartLevel] *SYSTEM com.sonatype.nexus.plugins.healthcheck.service.impl.HealthCheckTaskManagerImpl - Enabled health check for repository iits-npm-internal 2017-05-09 14:45:17,547+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Health Check: docker-public' [healthcheck] removed 2017-05-09 14:45:17,562+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Health Check: docker-public' [healthcheck] : state=WAITING 2017-05-09 14:45:17,578+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.scheduling.internal.TaskSchedulerImpl - Task 'Health Check: docker-public' [healthcheck] scheduled: hourly 2017-05-09 14:45:17,579+0200 INFO [FelixStartLevel] *SYSTEM com.sonatype.nexus.plugins.healthcheck.service.impl.HealthCheckTaskManagerImpl - Enabled health check for repository docker-public 2017-05-09 14:45:17,660+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Health Check: npmjs-public' [healthcheck] removed 2017-05-09 14:45:17,672+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.quartz.internal.task.QuartzTaskInfo - Task 'Health Check: npmjs-public' [healthcheck] : state=WAITING 2017-05-09 14:45:17,694+0200 INFO [FelixStartLevel] *SYSTEM org.sonatype.nexus.scheduling.internal.TaskSchedulerImpl - Task 'Health Check: npmjs-public' [healthcheck] scheduled: hourly 2017-05-09 14:45:17,694+0200 INFO [FelixStartLevel] *SYSTEM com.sonatype.nexus.plugins.healthcheck.service.impl.HealthCheckTaskManagerImpl - Enabled health check for repository npmjs-public 2017-05-09 14:45:17,722+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.bootstrap.osgi.BootstrapListener - Initialized 2017-05-09 14:45:17,738+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.rapture.internal.RaptureWebResourceBundle - UI plugin descriptors: 2017-05-09 14:45:17,739+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.rapture.internal.RaptureWebResourceBundle - nexus-rapture 2017-05-09 14:45:17,740+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.rapture.internal.RaptureWebResourceBundle - nexus-proximanova-plugin 2017-05-09 14:45:17,740+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.rapture.internal.RaptureWebResourceBundle - nexus-coreui-plugin 2017-05-09 14:45:17,741+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.rapture.internal.RaptureWebResourceBundle - nexus-proui-plugin 2017-05-09 14:45:17,750+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.internal.webresources.WebResourceServlet - Max-age: 30 days (2592000 seconds) 2017-05-09 14:45:17,788+0200 INFO [jetty-main-1] *SYSTEM com.softwarementors.extjs.djn.servlet.DirectJNgineServlet - Servlet GLOBAL configuration: debug=false, providersUrl=service/extdirect, minify=false, batchRequestsMultithreadingEnabled=true, batchRequestsMinThreadsPoolSize=16, batchRequestsMaxThreadsPoolSize=80, batchRequestsMaxThreadsPerRequest=8, batchRequestsMaxThreadKeepAliveSeconds=60, gsonBuilderConfiguratorClass=org.sonatype.nexus.extdirect.internal.ExtDirectGsonBuilderConfigurator, dispatcherClass=com.softwarementors.extjs.djn.servlet.ssm.SsmDispatcher, jsonRequestProcessorThreadClass=org.sonatype.nexus.extdirect.internal.ExtDirectJsonRequestProcessorThread, contextPath=--not specified: calculated via Javascript--, createSourceFiles=true 2017-05-09 14:45:17,791+0200 INFO [jetty-main-1] *SYSTEM com.softwarementors.extjs.djn.servlet.DirectJNgineServlet - Servlet GLOBAL configuration: registryConfiguratorClass= 2017-05-09 14:45:17,813+0200 INFO [jetty-main-1] *SYSTEM com.softwarementors.extjs.djn.jscodegen.CodeFileGenerator - Creating source files for APIs... 2017-05-09 14:45:17,998+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.siesta.SiestaServlet - JAX-RS RuntimeDelegate: org.sonatype.nexus.siesta.internal.resteasy.SisuResteasyProviderFactory@7c2f8ed2 2017-05-09 14:45:18,376+0200 INFO [jetty-main-1] *SYSTEM org.jboss.resteasy.plugins.validation.i18n - RESTEASY008550: Unable to find CDI supporting ValidatorFactory. Using default ValidatorFactory 2017-05-09 14:45:18,419+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.siesta.SiestaServlet - Initialized 2017-05-09 14:45:18,424+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.repository.httpbridge.internal.ViewServlet - Initialized 2017-05-09 14:45:18,457+0200 INFO [jetty-main-1] *SYSTEM org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.w.WebAppContext@1287b6bc{/nexus,file:///nexus/nexusV3/nexus-3.3.1-01/public/,AVAILABLE} 2017-05-09 14:45:18,505+0200 INFO [jetty-main-1] *SYSTEM org.eclipse.jetty.server.ServerConnector - Started ServerConnector@3904067{HTTP/1.1,[http/1.1]}{0.0.0.0:8088} 2017-05-09 14:45:18,505+0200 INFO [jetty-main-1] *SYSTEM org.eclipse.jetty.server.Server - Started @52041ms 2017-05-09 14:45:18,506+0200 INFO [jetty-main-1] *SYSTEM org.sonatype.nexus.bootstrap.jetty.JettyServer - ------------------------------------------------- Started Sonatype Nexus OSS 3.3.1-01 -------------------------------------------------
A thread dump from the server may show the task thread stuck as follows:
quartz-1-thread-1 id=163 state=TIMED_WAITING - waiting on <0x28cbf57a> (a java.util.concurrent.CountDownLatch$Sync) - locked <0x28cbf57a> (a java.util.concurrent.CountDownLatch$Sync) at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037) at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328) at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277) at org.sonatype.nexus.quartz.internal.task.QuartzTaskFuture.get(QuartzTaskFuture.java:203) at org.sonatype.nexus.quartz.internal.task.QuartzTaskJob.mayBlock(QuartzTaskJob.java:222) at org.sonatype.nexus.quartz.internal.task.QuartzTaskJob.doExecute(QuartzTaskJob.java:139) 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.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:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Locked synchronizers: count = 1 - java.util.concurrent.ThreadPoolExecutor$Worker@4c7bc7c2
Workaround
A user may want to know how to delete the stuck task. The only way is to explicitly delete the task from the configuration database using a special OrientDB console command. Please contact support if you need the additional information to delete a similarly stuck task.
Attachments
Issue Links
- is related to
-
NEXUS-13772 possible to have more than one Repository Audit task for the same repository
-
- Open
-
-
NEXUS-12780 task scheduler threads may deadlock at QuartzTaskJob.mayBlock() when more than 20 blocking tasks are encountered
-
- Closed
-
-
NEXUS-12828 submitting more than 20 tasks at once causes ERROR QuartzSchedulerThread - ThreadPool.runInThread() return false! for some tasks
-
- Closed
-
-
NEXUS-16935 upgrade to a newer version of Quartz scheduler
-
- Closed
-
- relates
-
NEXUS-16965 Repair - Rebuild repository browse is not cancelable
-
- Closed
-
- mentioned in
-
Page Loading...