14:34:54,106 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:34:54,109 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-29) msg: 868cefad-811b-412f-8436-41eb7b8cfb97 handling task completed, results:true, at: 1402396494109, took:89
14:34:54,112 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:34:54,122 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:34:54,124 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 18ms
14:34:54,218 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:34:54,224 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:34:54,264 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 15626fac-98b5-4462-9895-ebb470ddc311
14:34:54,268 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 15626fac-98b5-4462-9895-ebb470ddc311 handling task scheduled
14:34:54,268 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-30) handling task: 15626fac-98b5-4462-9895-ebb470ddc311 begin, at: 1402396494268
14:34:54,272 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 54ms
14:34:54,328 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-30) Message 15626fac-98b5-4462-9895-ebb470ddc311 completed.
14:34:54,348 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-17-thread-30) message finished: 15626fac-98b5-4462-9895-ebb470ddc311, took 73
14:34:54,349 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:34:54,351 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-30) msg: 15626fac-98b5-4462-9895-ebb470ddc311 handling task completed, results:true, at: 1402396494351, took:83
14:34:54,354 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:34:54,371 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:34:54,373 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 24ms
14:34:54,489 INFO  [org.drools.compiler.kie.builder.impl.KieRepositoryImpl] (http--127.0.0.1-8180-5) KieModule was added:MemoryKieModule[ ReleaseId=EmiratesRepo:proj_emiratesRepo:1.0]
14:35:10,964 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:10,966 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:10,996 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 5c1eeeab-fb97-41a6-8c6f-9c89af3f3711
14:35:10,999 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 5c1eeeab-fb97-41a6-8c6f-9c89af3f3711 handling task scheduled
14:35:11,001 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 37ms
14:35:11,012 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-31) handling task: 5c1eeeab-fb97-41a6-8c6f-9c89af3f3711 begin, at: 1402396511012
14:35:11,049 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-31) Message 5c1eeeab-fb97-41a6-8c6f-9c89af3f3711 completed.
14:35:11,079 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-17-thread-31) message finished: 5c1eeeab-fb97-41a6-8c6f-9c89af3f3711, took 64
14:35:11,084 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-31) msg: 5c1eeeab-fb97-41a6-8c6f-9c89af3f3711 handling task completed, results:true, at: 1402396511084, took:72
14:35:11,090 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:11,094 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:11,100 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:11,102 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 12ms
14:35:11,154 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:11,160 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:11,204 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 47e40ca4-01a2-4f18-ba93-61a2583dbf0a
14:35:11,209 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 47e40ca4-01a2-4f18-ba93-61a2583dbf0a handling task scheduled
14:35:11,218 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 64ms
14:35:11,221 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-32) handling task: 47e40ca4-01a2-4f18-ba93-61a2583dbf0a begin, at: 1402396511221
14:35:11,281 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-32) Message 47e40ca4-01a2-4f18-ba93-61a2583dbf0a completed.
14:35:11,313 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-17-thread-32) message finished: 47e40ca4-01a2-4f18-ba93-61a2583dbf0a, took 71
14:35:11,316 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:11,317 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-32) msg: 47e40ca4-01a2-4f18-ba93-61a2583dbf0a handling task completed, results:true, at: 1402396511317, took:96
14:35:11,320 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:11,327 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:11,340 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 24ms
14:35:11,796 INFO  [org.apache.helix.messaging.CriteriaEvaluator] (http--127.0.0.1-8180-5) JOSQL query: SELECT DISTINCT  mapSubKey, recordId, '', ''  FROM EXTERNALVIEW.Table WHERE mapSubKey LIKE '%' AND recordId LIKE 'vfs-repo' AND mapKey LIKE '%'  AND mapValue LIKE '%'  AND mapSubKey IN ((SELECT [*]id FROM :LIVEINSTANCES))
14:35:11,814 INFO  [org.apache.helix.messaging.CriteriaEvaluator] (http--127.0.0.1-8180-5) JOSQL query return 2 rows
14:35:11,817 INFO  [org.apache.helix.messaging.DefaultMessagingService] (http--127.0.0.1-8180-5) Send 1 messages with criteria instanceName=%resourceName=vfs-repopartitionName=partitionState=
14:35:12,494 INFO  [org.apache.helix.messaging.CriteriaEvaluator] (http--127.0.0.1-8180-5) JOSQL query: SELECT DISTINCT  mapSubKey, recordId, '', ''  FROM EXTERNALVIEW.Table WHERE mapSubKey LIKE '%' AND recordId LIKE 'vfs-repo' AND mapKey LIKE '%'  AND mapValue LIKE '%'  AND mapSubKey IN ((SELECT [*]id FROM :LIVEINSTANCES))
14:35:12,502 INFO  [org.apache.helix.messaging.CriteriaEvaluator] (http--127.0.0.1-8180-5) JOSQL query return 2 rows
14:35:12,504 INFO  [org.apache.helix.messaging.DefaultMessagingService] (http--127.0.0.1-8180-5) Send 1 messages with criteria instanceName=%resourceName=vfs-repopartitionName=partitionState=
14:35:12,973 INFO  [org.apache.helix.messaging.CriteriaEvaluator] (http--127.0.0.1-8180-5) JOSQL query: SELECT DISTINCT  mapSubKey, recordId, '', ''  FROM EXTERNALVIEW.Table WHERE mapSubKey LIKE '%' AND recordId LIKE 'vfs-repo' AND mapKey LIKE '%'  AND mapValue LIKE '%'  AND mapSubKey IN ((SELECT [*]id FROM :LIVEINSTANCES))
14:35:12,985 INFO  [org.apache.helix.messaging.CriteriaEvaluator] (http--127.0.0.1-8180-5) JOSQL query return 2 rows
14:35:12,987 INFO  [org.apache.helix.messaging.DefaultMessagingService] (http--127.0.0.1-8180-5) Send 1 messages with criteria instanceName=%resourceName=vfs-repopartitionName=partitionState=
14:35:13,264 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:13,268 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:13,312 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: bc5e600e-c5e0-4f1f-a4d9-0e2f90830a45
14:35:13,326 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: bc5e600e-c5e0-4f1f-a4d9-0e2f90830a45 handling task scheduled
14:35:13,328 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 64ms
14:35:13,337 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-33) handling task: bc5e600e-c5e0-4f1f-a4d9-0e2f90830a45 begin, at: 1402396513337
14:35:13,380 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-33) Message bc5e600e-c5e0-4f1f-a4d9-0e2f90830a45 completed.
14:35:13,412 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-17-thread-33) message finished: bc5e600e-c5e0-4f1f-a4d9-0e2f90830a45, took 70
14:35:13,413 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:13,421 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-33) msg: bc5e600e-c5e0-4f1f-a4d9-0e2f90830a45 handling task completed, results:true, at: 1402396513421, took:84
14:35:13,425 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:13,437 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:13,439 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 26ms
14:35:13,488 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:13,492 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:13,612 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 5198ccef-eaac-48d8-8d00-b638c9f4d855
14:35:13,615 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 5198ccef-eaac-48d8-8d00-b638c9f4d855 handling task scheduled
14:35:13,615 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-34) handling task: 5198ccef-eaac-48d8-8d00-b638c9f4d855 begin, at: 1402396513615
14:35:13,623 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 135ms
14:35:13,648 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-34) Message 5198ccef-eaac-48d8-8d00-b638c9f4d855 completed.
14:35:13,680 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-17-thread-34) message finished: 5198ccef-eaac-48d8-8d00-b638c9f4d855, took 52
14:35:13,681 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:13,684 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-17-thread-34) msg: 5198ccef-eaac-48d8-8d00-b638c9f4d855 handling task completed, results:true, at: 1402396513684, took:69
14:35:13,687 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:13,694 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:13,696 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 15ms
14:35:13,744 INFO  [org.drools.compiler.kie.builder.impl.KieRepositoryImpl] (http--127.0.0.1-8180-5) KieModule was added:MemoryKieModule[ ReleaseId=EmiratesRepo:proj_emiratesRepo:1.0]
14:35:35,113 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:35,117 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:35,184 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 98d771f8-f21b-4119-bb9f-fd629463e7d7
14:35:35,195 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 98d771f8-f21b-4119-bb9f-fd629463e7d7 handling task scheduled
14:35:35,207 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-17) handling task: 98d771f8-f21b-4119-bb9f-fd629463e7d7 begin, at: 1402396535207
14:35:35,216 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 103ms
14:35:35,394 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:35,397 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:35,399 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-17) Message 98d771f8-f21b-4119-bb9f-fd629463e7d7 completed.
14:35:35,685 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-17) message finished: 98d771f8-f21b-4119-bb9f-fd629463e7d7, took 466
14:35:35,687 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-17) msg: 98d771f8-f21b-4119-bb9f-fd629463e7d7 handling task completed, results:true, at: 1402396535687, took:480
14:35:35,803 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 9c129051-4d4a-463d-a739-9479a54251e2
14:35:35,896 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 9c129051-4d4a-463d-a739-9479a54251e2 handling task scheduled
14:35:36,007 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 613ms
14:35:36,005 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-18) handling task: 9c129051-4d4a-463d-a739-9479a54251e2 begin, at: 1402396536004
14:35:36,185 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:36,194 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-18) Message 9c129051-4d4a-463d-a739-9479a54251e2 completed.
14:35:36,194 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:36,341 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-18) message finished: 9c129051-4d4a-463d-a739-9479a54251e2, took 161
14:35:36,344 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-18) msg: 9c129051-4d4a-463d-a739-9479a54251e2 handling task completed, results:true, at: 1402396536344, took:340
14:35:36,446 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:36,449 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 264ms
14:35:36,583 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:36,588 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:36,597 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:36,610 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 27ms
14:35:42,795 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:42,797 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:42,877 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 0ba53ca8-23c3-4c2c-9114-226c4e29968b
14:35:42,880 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 0ba53ca8-23c3-4c2c-9114-226c4e29968b handling task scheduled
14:35:42,880 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-19) handling task: 0ba53ca8-23c3-4c2c-9114-226c4e29968b begin, at: 1402396542880
14:35:42,882 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 87ms
14:35:42,895 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-19) Message 0ba53ca8-23c3-4c2c-9114-226c4e29968b completed.
14:35:42,935 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-19) message finished: 0ba53ca8-23c3-4c2c-9114-226c4e29968b, took 51
14:35:42,937 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-19) msg: 0ba53ca8-23c3-4c2c-9114-226c4e29968b handling task completed, results:true, at: 1402396542937, took:57
14:35:42,938 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:42,948 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:42,952 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:42,953 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 15ms
14:35:44,102 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:44,105 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:44,226 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 99c3f030-8594-413a-848e-3c886c687f17
14:35:44,229 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 99c3f030-8594-413a-848e-3c886c687f17 handling task scheduled
14:35:44,230 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-20) handling task: 99c3f030-8594-413a-848e-3c886c687f17 begin, at: 1402396544230
14:35:44,233 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 131ms
14:35:44,245 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-20) Message 99c3f030-8594-413a-848e-3c886c687f17 completed.
14:35:44,360 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-20) message finished: 99c3f030-8594-413a-848e-3c886c687f17, took 125
14:35:44,363 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-20) msg: 99c3f030-8594-413a-848e-3c886c687f17 handling task completed, results:true, at: 1402396544363, took:133
14:35:44,363 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:35:44,390 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:35:44,475 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:35:44,480 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 117ms
14:39:55,206 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:39:55,208 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:39:55,364 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 8b3b50d5-66c4-4497-8749-59f869384672
14:39:55,366 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 8b3b50d5-66c4-4497-8749-59f869384672 handling task scheduled
14:39:55,366 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-21) handling task: 8b3b50d5-66c4-4497-8749-59f869384672 begin, at: 1402396795366
14:39:55,369 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 162ms
14:39:55,379 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-21) Message 8b3b50d5-66c4-4497-8749-59f869384672 completed.
14:39:55,622 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-21) message finished: 8b3b50d5-66c4-4497-8749-59f869384672, took 252
14:39:55,624 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-21) msg: 8b3b50d5-66c4-4497-8749-59f869384672 handling task completed, results:true, at: 1402396795624, took:258
14:39:55,624 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:39:55,632 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:39:55,638 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:39:55,640 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 16ms
14:39:59,386 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:39:59,389 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:39:59,700 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 06c7f2ef-158e-4526-8d25-5e74e2f8a042
14:39:59,703 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 06c7f2ef-158e-4526-8d25-5e74e2f8a042 handling task scheduled
14:39:59,703 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-22) handling task: 06c7f2ef-158e-4526-8d25-5e74e2f8a042 begin, at: 1402396799703
14:39:59,707 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 321ms
14:39:59,958 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-22) Message 06c7f2ef-158e-4526-8d25-5e74e2f8a042 completed.
14:40:00,210 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-22) message finished: 06c7f2ef-158e-4526-8d25-5e74e2f8a042, took 491
14:40:00,211 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:40:00,213 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-22) msg: 06c7f2ef-158e-4526-8d25-5e74e2f8a042 handling task completed, results:true, at: 1402396800213, took:510
14:40:00,216 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:40:00,221 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:40:00,223 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 12ms
14:42:03,103 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:42:03,105 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:42:03,177 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 6ffc076f-d3f4-4598-977e-06fde4f0e2e1
14:42:03,180 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 6ffc076f-d3f4-4598-977e-06fde4f0e2e1 handling task scheduled
14:42:03,180 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-23) handling task: 6ffc076f-d3f4-4598-977e-06fde4f0e2e1 begin, at: 1402396923180
14:42:03,182 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 79ms
14:42:03,326 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-23) Message 6ffc076f-d3f4-4598-977e-06fde4f0e2e1 completed.
14:42:03,393 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-23) message finished: 6ffc076f-d3f4-4598-977e-06fde4f0e2e1, took 209
14:42:03,395 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-23) msg: 6ffc076f-d3f4-4598-977e-06fde4f0e2e1 handling task completed, results:true, at: 1402396923395, took:215
14:42:03,428 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:42:03,432 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:42:03,506 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:42:03,511 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 83ms
14:42:04,595 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:42:04,597 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:42:04,652 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Scheduling message: 29e81bef-09a8-42b5-8025-f5c14a75a15d
14:42:04,655 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) Message: 29e81bef-09a8-42b5-8025-f5c14a75a15d handling task scheduled
14:42:04,655 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-24) handling task: 29e81bef-09a8-42b5-8025-f5c14a75a15d begin, at: 1402396924655
14:42:04,657 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 62ms
14:42:04,668 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-24) Message 29e81bef-09a8-42b5-8025-f5c14a75a15d completed.
14:42:04,742 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (pool-18-thread-24) message finished: 29e81bef-09a8-42b5-8025-f5c14a75a15d, took 83
14:42:04,744 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 START:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor
14:42:04,744 INFO  [org.apache.helix.messaging.handling.HelixTask] (pool-18-thread-24) msg: 29e81bef-09a8-42b5-8025-f5c14a75a15d handling task completed, results:true, at: 1402396924744, took:89
14:42:04,747 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) nodeTwo_22 subscribes child-change. path: /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES, listener: org.apache.helix.messaging.handling.HelixTaskExecutor@55439b
14:42:04,752 INFO  [org.apache.helix.messaging.handling.HelixTaskExecutor] (ZkClient-EventThread-124-localhost:2199) No Messages to process
14:42:04,755 INFO  [org.apache.helix.manager.zk.CallbackHandler] (ZkClient-EventThread-124-localhost:2199) 124 END:INVOKE /jbpm-cluster/INSTANCES/nodeTwo_22/MESSAGES listener:org.apache.helix.messaging.handling.HelixTaskExecutor Took: 11ms