Hi All,
I have an issue with the Jgroups locking problem with the Service mix, here in the below logs you can see the Service Mix File Poller is trying to lock for the same key(same file) two times and fails.
Because of this the unlock call is failing every time this happens, this scenario is sporadic but happens frequently.
Scenario:
First time the File Poller thread will pole the file and try’s to acquire the lock on the same and it was granted successfully
Second time it tries to lock same file and says lock was not granted, and the lock aquire process was failed
But after the second failure of the locking on the same file it tries to unlock immediately as the lock was not granted, but even the unlock will fails saying unlocking is failed
Then again the same file poller thread tries to unlock the lock for the same key and again it fails with exception as below:
2011-03-24T11:20:05.379+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 128 | Lock cannot be unlocked.
org.jgroups.blocks.LockNotReleasedException: Lock cannot be unlocked.
Here in all the above operations you can see that the thread id is same !!
Do anyone has idea on this problem / issue ?
2011-03-24T11:20:05.182+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 92 | Getting lock object for key:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.182+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | DistributedLock | mf.lockmanager.DistributedLock 106 | Trying to obtain a lock with key:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.183+0200 | thridoo | INFO | pool-flow.seda.ne3s-ws-smi-bc-thread-358 | NE3SWS-BC | .ne3sws.endpoints.NE3SWSClient 294 | User credentials used for http://agent84:8971/NE3S/1.0/NE3SBasicOperationsService user :: wsuser password :: *****
2011-03-24T11:20:05.202+0200 | thridoo | DEBUG | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-270 | NE3SWS_MEDIATION | mediation.ne3sws.NE3SWSManager 442 | oper time - null :: 34
2011-03-24T11:20:05.202+0200 | thridoo | INFO | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-270 | NE3SWS_MEDIATION | ediation.ne3sws.NE3SWSEndpoint 168 | Triggered the operation set successfully for agent agent84 user ::wsuser password :: ***** ne3sws endpoint ::http://agent84:8971/NE3S/1.0/NE3SBasicOperationsService operation id :: null time taken (in ms) :: 46. waiting for response from Agent
2011-03-24T11:20:05.203+0200 | thridoo | DEBUG | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-270 | NE3SWS_MEDIATION | ediation.ne3sws.NE3SWSEndpoint 239 | Excptn during exchg cleanup
2011-03-24T11:20:05.204+0200 | thridoo | DEBUG | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-271 | ClusteredLockManager | ckmanager.ClusteredLockManager 92 | Getting lock object for key:an_globalId_502116000000000569_2570905160234671.xml
2011-03-24T11:20:05.205+0200 | thridoo | DEBUG | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-271 | ClusteredLockManager | ckmanager.ClusteredLockManager 107 | Lock already available for the key:an_globalId_502116000000000569_2570905160234671.xml
2011-03-24T11:20:05.205+0200 | thridoo | DEBUG | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-271 | DistributedLock | mf.lockmanager.DistributedLock 149 | Releasing lock:an_globalId_502116000000000569_2570905160234671.xml
2011-03-24T11:20:05.250+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | DistributedLock | mf.lockmanager.DistributedLock 126 | Tried lock was granted:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.250+0200 | thridoo | DEBUG | pool-flow.seda.ne3sws-mediation-enhancer-se-thread-271 | ClusteredLockManager | ckmanager.ClusteredLockManager 121 | removing Distribute lock object for key:an_globalId_502116000000000569_2570905160234671.xml
2011-03-24T11:20:05.252+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 92 | Getting lock object for key:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.252+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 107 | Lock already available for the key:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.252+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | DistributedLock | mf.lockmanager.DistributedLock 149 | Releasing lock:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.281+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-74 | ClusteredLockManager | ckmanager.ClusteredLockManager 92 | Getting lock object for key:an_globalId_502116000000000594_2570887937874621.xml
2011-03-24T11:20:05.281+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-74 | DistributedLock | mf.lockmanager.DistributedLock 106 | Trying to obtain a lock with key:an_globalId_502116000000000594_2570887937874621.xml
2011-03-24T11:20:05.314+0200 | thridoo | WARN | pool-component.servicemix-file-thread-112 | DistributedLock | mf.lockmanager.DistributedLock 156 | Unlocking failed for lock:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.315+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 121 | removing Distribute lock object for key:an_globalId_502116000000000526_2567740520833480.xml
2011-03-24T11:20:05.347+0200 | thridoo | INFO | pool-component.servicemix-file-thread-74 | DistributedLock | mf.lockmanager.DistributedLock 116 | Lock (an_globalId_502116000000000594_2570887937874621.xml) could not be granted!
2011-03-24T11:20:05.378+0200 | thridoo | ERROR | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 126 | LockNotReleasedException during distributed lock release
2011-03-24T11:20:05.379+0200 | thridoo | DEBUG | pool-component.servicemix-file-thread-112 | ClusteredLockManager | ckmanager.ClusteredLockManager 128 | Lock cannot be unlocked.
org.jgroups.blocks.LockNotReleasedException: Lock cannot be unlocked.
at org.jgroups.blocks.DistributedLockManager.unlock(DistributedLockManager.java:311)
at org.jgroups.blocks.DistributedLockManager.unlock(DistributedLockManager.java:253)
at com.nsn.obs.mf.lockmanager.ClusteredLockManager.removeLock(ClusteredLockManager.java:123)
at org.apache.servicemix.file.FilePollerEndpoint.unlockAsyncFile(FilePollerEndpoint.java:481)
at org.apache.servicemix.file.FilePollerEndpoint.processFileNow(FilePollerEndpoint.java:376)
at org.apache.servicemix.file.FilePollerEndpoint$1.run(FilePollerEndpoint.java:320)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Regards
Guruprasad BH