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(ClusteredLock
Manager.java:123)
at
org.apache.servicemix.file.FilePollerEndpoint.unlockAsyncFile(FilePoller
Endpoint.java:481)
at
org.apache.servicemix.file.FilePollerEndpoint.processFileNow(FilePollerE
ndpoint.java:376)
at
org.apache.servicemix.file.FilePollerEndpoint$1.run(FilePollerEndpoint.j
ava: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