Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-19474

Fix random WorkManager errors in TestDefaultFileSystemItemFactory logs

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Duplicate
    • Affects Version/s: 8.3-SNAPSHOT
    • Fix Version/s: None
    • Component/s: Events / Works, Nuxeo Drive

      Description

      I often see the following traces when running TestDefaultFileSystemItemFactory, not always exactly the same stack though.

      Visible here: http://qa.nuxeo.org/jenkins/view/Drive/job/addons_nuxeo-drive-server-master/

      It doesn't make the test fail.

      Running org.nuxeo.drive.service.adapter.TestDefaultFileSystemItemFactory
      11:51:13,428 WARN  [MemoryWorkQueuing] Running a work with the same ID test:635f5dfb-10c5-4592-9d10-efa82dc3da95:sqlFulltextExtractor multiple time, already running SQLFulltextExtractorWork(635f5dfb-10c5-4592-9d10-efa82dc3da95, , Progress(?%, ?/0), null), new work: SQLFulltextExtractorWork(635f5dfb-10c5-4592-9d10-efa82dc3da95, , Progress(?%, ?/0), null)
      11:51:13,681 WARN  [MemoryWorkQueuing] Running a work with the same ID test:f7e1845d-9828-48c0-ae8f-b918c29bb65d:sqlFulltextExtractor multiple time, already running SQLFulltextExtractorWork(f7e1845d-9828-48c0-ae8f-b918c29bb65d, , Progress(?%, ?/0), null), new work: SQLFulltextExtractorWork(f7e1845d-9828-48c0-ae8f-b918c29bb65d, , Progress(?%, ?/0), null)
      11:51:20,260 ERROR [WorkManagerImpl$NamedThreadFactory$1] Uncaught error on thread Nuxeo-Work-default-4
      java.lang.IllegalStateException: default was not configured yet
          at org.nuxeo.ecm.core.work.MemoryWorkQueuing.getWorkQueue(MemoryWorkQueuing.java:106)
          at org.nuxeo.ecm.core.work.MemoryWorkQueuing.workSchedule(MemoryWorkQueuing.java:113)
          at org.nuxeo.ecm.core.work.WorkManagerImpl$WorkThreadPoolExecutor.beforeExecute(WorkManagerImpl.java:563)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      StorageConfiguration: Deploying JDBC using DatabaseH2
      StorageConfiguration: Deploying a VCS repository
      Tests run: 11, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 17.617 sec - in org.nuxeo.drive.service.adapter.TestDefaultFileSystemItemFactory
      Running org.nuxeo.drive.service.adapter.TestFileSystemItemAdapterService
      11:51:31,092 ERROR [AbstractWork] Exception during work: SQLFulltextExtractorWork(b2320bbe-f095-43e9-ac12-d44fe4a70871, , Progress(?%, ?/0), null)
      org.nuxeo.ecm.core.api.NuxeoException: javax.resource.ResourceException: Interrupted while requesting permit.
          at org.nuxeo.ecm.core.storage.sql.ra.ConnectionFactoryImpl.getConnection(ConnectionFactoryImpl.java:117)
          at org.nuxeo.ecm.core.storage.sql.ra.ConnectionFactoryImpl.getSession(ConnectionFactoryImpl.java:166)
          at org.nuxeo.ecm.core.repository.RepositoryService.getSession(RepositoryService.java:227)
          at org.nuxeo.ecm.core.api.local.LocalSession.createSession(LocalSession.java:123)
          at org.nuxeo.ecm.core.api.local.LocalSession.connect(LocalSession.java:89)
          at org.nuxeo.ecm.core.api.CoreInstance.acquireCoreSession(CoreInstance.java:195)
          at org.nuxeo.ecm.core.api.CoreInstance.openCoreSession(CoreInstance.java:187)
          at org.nuxeo.ecm.core.api.CoreInstance.openCoreSessionSystem(CoreInstance.java:130)
          at org.nuxeo.ecm.core.work.AbstractWork.openSystemSession(AbstractWork.java:270)
          at org.nuxeo.ecm.core.storage.FulltextExtractorWork.work(FulltextExtractorWork.java:97)
          at org.nuxeo.ecm.core.work.AbstractWork.runWorkWithTransaction(AbstractWork.java:416)
          at org.nuxeo.ecm.core.work.AbstractWork.runWorkWithTransactionAndCheckExceptions(AbstractWork.java:377)
          at org.nuxeo.ecm.core.work.AbstractWork.run(AbstractWork.java:338)
          at org.nuxeo.ecm.core.work.WorkHolder.run(WorkHolder.java:54)
          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)
      Caused by: javax.resource.ResourceException: Interrupted while requesting permit.
          at org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.getConnection(AbstractSinglePoolConnectionInterceptor.java:97)
          at org.apache.geronimo.connector.outbound.ThreadLocalCachingConnectionInterceptor.getConnection(ThreadLocalCachingConnectionInterceptor.java:70)
          at org.apache.geronimo.connector.outbound.TransactionEnlistingInterceptor.getConnection(TransactionEnlistingInterceptor.java:49)
          at org.apache.geronimo.connector.outbound.TransactionCachingInterceptor.getConnection(TransactionCachingInterceptor.java:101)
          at org.apache.geronimo.connector.outbound.ConnectionHandleInterceptor.getConnection(ConnectionHandleInterceptor.java:43)
          at org.apache.geronimo.connector.outbound.TCCLInterceptor.getConnection(TCCLInterceptor.java:39)
          at org.apache.geronimo.connector.outbound.ConnectionTrackingInterceptor.getConnection(ConnectionTrackingInterceptor.java:66)
          at org.apache.geronimo.connector.outbound.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:77)
          at org.nuxeo.runtime.jtajca.NuxeoContainer$ConnectionManagerWrapper.allocateConnection(NuxeoContainer.java:851)
          at org.nuxeo.ecm.core.storage.sql.ra.ConnectionFactoryImpl.getConnection(ConnectionFactoryImpl.java:103)
          ... 16 more
      Caused by: java.lang.InterruptedException
          at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1326)
          at java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:409)
          at org.apache.geronimo.connector.outbound.AbstractSinglePoolConnectionInterceptor.getConnection(AbstractSinglePoolConnectionInterceptor.java:78)
          ... 25 more
      11:51:31,092 ERROR [AbstractWork] Exception during work: FulltextUpdaterWork(a4dd5251-27fb-421e-a27f-44797a47c22c, , Progress(0.0%, ?/0), Updating)
      11:51:31,095 ERROR [WorkManagerImpl$NamedThreadFactory$1] Uncaught error on thread Nuxeo-Work-fulltextUpdater-1
      java.lang.NullPointerException
          at org.nuxeo.ecm.core.work.WorkManagerImpl$WorkThreadPoolExecutor.afterExecute(WorkManagerImpl.java:587)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1150)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      11:51:41,094 ERROR [WorkManagerImpl$NamedThreadFactory$1] Uncaught error on thread Nuxeo-Work-default-4
      java.lang.NullPointerException
          at org.nuxeo.ecm.core.work.WorkManagerImpl$WorkThreadPoolExecutor.afterExecute(WorkManagerImpl.java:587)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1150)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      11:51:41,117 ERROR [AbstractWork] Exception during work: SQLFulltextExtractorWork(a4dd5251-27fb-421e-a27f-44797a47c22c, , Progress(0.0%, ?/0), Extracting)
      11:51:41,117 ERROR [AbstractWork] Exception during work: FulltextUpdaterWork(a4dd5251-27fb-421e-a27f-44797a47c22c, , Progress(0.0%, ?/0), Saving)
      11:51:41,118 ERROR [WorkManagerImpl$NamedThreadFactory$1] Uncaught error on thread Nuxeo-Work-fulltextUpdater-1
      java.lang.NullPointerException
          at org.nuxeo.ecm.core.work.WorkManagerImpl$WorkThreadPoolExecutor.afterExecute(WorkManagerImpl.java:587)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1150)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      11:51:41,118 ERROR [WorkManagerImpl$NamedThreadFactory$1] Uncaught error on thread Nuxeo-Work-default-1
      java.lang.NullPointerException
          at org.nuxeo.ecm.core.work.WorkManagerImpl$WorkThreadPoolExecutor.afterExecute(WorkManagerImpl.java:587)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1150)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 15.203 sec - in org.nuxeo.drive.service.adapter.TestFileSystemItemAdapterService
      

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: