-
Type: Bug
-
Status: Resolved
-
Priority: Minor
-
Resolution: Fixed
-
Affects Version/s: 7.10, 8.10, 9.10, 10.1, 10.2
-
Fix Version/s: 10.3
-
Component/s: Events / Works
- install Nuxeo
- add the following contribution :
<extension target="org.nuxeo.ecm.core.work.service" point="queues"> <queue id="*" processing="false" /> </extension>
- add the following logger in $NUXEO_HOME/lib/log4j.xml
- start Nuxeo server
- observe the following in the logs:
2018-07-17 09:53:39,268 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue escalation WorkQueueDescriptor[id=escalation categories=[routingEscalation]] 2018-07-17 09:53:43,559 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Setting on all work queues: processing=false 2018-07-17 09:53:43,559 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue blobs WorkQueueDescriptor[id=blobs categories=[blobListZip] processing=false maxThreads=2] 2018-07-17 09:53:43,559 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue default WorkQueueDescriptor[id=default categories=[] processing=false maxThreads=4] 2018-07-17 09:53:43,559 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue permissionsPurge WorkQueueDescriptor[id=permissionsPurge categories=[permissionsPurge] processing=false maxThreads=1] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue updateACEStatus WorkQueueDescriptor[id=updateACEStatus categories=[updateACEStatus] processing=false maxThreads=1] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue fulltextUpdater WorkQueueDescriptor[id=fulltextUpdater categories=[fulltextUpdater] processing=false maxThreads=1] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue collections WorkQueueDescriptor[id=collections categories=[duplicateCollectionMember, removeFromCollection, removedCollectionMember, removedCollection] processing=false maxThreads=1] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue videoConversion WorkQueueDescriptor[id=videoConversion categories=[videoConversion] processing=false maxThreads=1] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue escalation WorkQueueDescriptor[id=escalation categories=[routingEscalation] processing=false] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue pictureViewsGeneration WorkQueueDescriptor[id=pictureViewsGeneration categories=[pictureViewsGeneration] processing=false maxThreads=1] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue elasticSearchIndexing WorkQueueDescriptor[id=elasticSearchIndexing categories=[elasticSearchIndexing] processing=false maxThreads=4] 2018-07-17 09:53:43,560 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Registered work queue renditionBuilder WorkQueueDescriptor[id=renditionBuilder categories=[renditionBuilder] processing=false maxThreads=1] 2018-07-17 09:53:45,916 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue blobs WorkQueueDescriptor(id=blobs categories=[blobListZip] queuing=true processing=false maxThreads=2 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,917 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue default WorkQueueDescriptor(id=default categories=[] queuing=true processing=false maxThreads=4 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,917 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue permissionsPurge WorkQueueDescriptor(id=permissionsPurge categories=[permissionsPurge] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,917 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue updateACEStatus WorkQueueDescriptor(id=updateACEStatus categories=[updateACEStatus] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,918 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue fulltextUpdater WorkQueueDescriptor(id=fulltextUpdater categories=[fulltextUpdater] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,918 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue collections WorkQueueDescriptor(id=collections categories=[duplicateCollectionMember, removeFromCollection, removedCollectionMember, removedCollection] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,918 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue videoConversion WorkQueueDescriptor(id=videoConversion categories=[videoConversion] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,919 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue escalation WorkQueueDescriptor(id=escalation categories=[routingEscalation] queuing=true processing=false maxThreads=4 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,919 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue pictureViewsGeneration WorkQueueDescriptor(id=pictureViewsGeneration categories=[pictureViewsGeneration] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,920 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue elasticSearchIndexing WorkQueueDescriptor(id=elasticSearchIndexing categories=[elasticSearchIndexing] queuing=true processing=false maxThreads=4 capacity=-1 clearCompletedAfterSeconds=) 2018-07-17 09:53:45,920 INFO [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Initialized work queue renditionBuilder WorkQueueDescriptor(id=renditionBuilder categories=[renditionBuilder] queuing=true processing=false maxThreads=1 capacity=-1 clearCompletedAfterSeconds=)
- observe right after the queues intialization, some work is already running:
2018-07-17 10:07:01,646 DEBUG [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Scheduling work after commit: FulltextUpdaterWork(f4af1adf-40bd-48d3-a370-0eb8645bb184, , Progress(?%, ?/0), null) 2018-07-17 10:07:01,847 DEBUG [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Scheduling work after commit: FulltextUpdaterWork(d4f7c7a9-779a-4d2e-b8e4-0748e47f9593, , Progress(?%, ?/0), null) 2018-07-17 10:07:02,042 DEBUG [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Scheduling work immediately: ListenerWork(Listener annotationsVersionEventListener [documentRemoved/a936182a-08d0-4638-b3ab-3423fe269a6d, documentRemoved/65877826-18f1-4701-b22d-aeb06fe2c5f0], Progress(?%, ?/0), null) 2018-07-17 10:07:02,044 DEBUG [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Scheduling work immediately: ListenerWork(Listener docRemovedCommentListener [documentRemoved/a936182a-08d0-4638-b3ab-3423fe269a6d, documentRemoved/65877826-18f1-4701-b22d-aeb06fe2c5f0], Progress(?%, ?/0), null) 2018-07-17 10:07:02,044 DEBUG [localhost-startStop-1] [org.nuxeo.ecm.core.work.WorkManagerImpl] Scheduling work immediately: ListenerWork(Listener notificationListener [documentCreated/f4af1adf-40bd-48d3-a370-0eb8645bb184, documentCreated/3842b94c-d603-43e1-987d-004948fb0348, documentCreated/d18e5ef8-c8f4-473e-a1fb-396e2b332b52, documentCreated/e4afdaa9-cd1a-422e-937f-8dbda2a9cb47, documentCreated/faa8347a-2dc7-49d4-b51a-fefa8960772d, documentCreated/c7560924-ac87-47d7-9ab2-82471839ee2d, documentCreated/4399989b-6d9b-4dca-b77a-2aadb33b0886, documentCreated/f7996f04-cd87-4a63-8997-5eb5832a6050, documentModified/f4af1adf-40bd-48d3-a370-0eb8645bb184, documentCreated/d4f7c7a9-779a-4d2e-b8e4-0748e47f9593, documentCreated/fceb1463-7fd0-4af4-9fd0-b60dfe1f811c, documentCreated/6b1aa66c-d82e-4bc6-8dfa-986b39201d9b, documentCreated/94dfa057-6414-4b91-aa06-71f335e3b289, documentCreated/037039bf-c97d-4194-80b8-5c3308e84a33, documentCreated/473e98eb-944f-4010-a194-32214d74e3b4, documentModified/d4f7c7a9-779a-4d2e-b8e4-0748e47f9593], Progress(?%, ?/0), null)
- try several actions like starting a test work, reindexing Elasticsearch, creating a document. They are all executed.
Expected behavior: the works should not be processed according to the following documentation:
https://doc.nuxeo.com/nxdoc/work-and-workmanager/#persistent-work-queues
Impact: this prevents dedicated nodes for specific processing
Note: the behavior can be reproduced from 6.0 to 10.1 (didn't try master but didn't find any open bug on the topic).
Note 2: contribution files attached to this ticket and to be placed in $NUXEO_HOME/nxserver/config
Note 3: while debugging, it seems there is no check on the queue activation status before starting a Work. For instance awaitCompletion is never called and thus noScheduledOrRunningWork is not called either, not checking here the queue processing status.
- is related to
-
NXP-15680 Fix TestRedisWorkManager.testWorkManagerDisableProcessing
- Open