Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

IllegalMonitorStateException: Current thread is not owner of the lock! in Hazelcast 3.6.3 #8730

Closed
pramodterdale opened this issue Aug 16, 2016 · 16 comments

Comments

Projects
None yet
5 participants
@pramodterdale
Copy link

commented Aug 16, 2016

I am getting error "Current thread is not owner of the lock!" in latest version of hazelcast 3.6.3
I am using hazelcast client to perform the actions.

Complete Stack Trace:

java.lang.IllegalMonitorStateException: Current thread is not owner of the lock! -> Owner: 7e390e3d-57fd-4caa-a849-cd0d17438173, thread-id: 86
    at com.hazelcast.concurrent.lock.operations.UnlockOperation.ensureUnlocked(UnlockOperation.java:73) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.concurrent.lock.operations.UnlockOperation.unlock(UnlockOperation.java:65) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.concurrent.lock.operations.UnlockOperation.run(UnlockOperation.java:57) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:172) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationexecutor.classic.ClassicOperationExecutor.runOnCallingThread(ClassicOperationExecutor.java:392) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationexecutor.classic.ClassicOperationExecutor.runOnCallingThreadIfPossible(ClassicOperationExecutor.java:345) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:259) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:243) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.Invocation.invokeInternal(Invocation.java:210) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:180) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:46) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.client.impl.protocol.task.AbstractPartitionMessageTask.processMessage(AbstractPartitionMessageTask.java:65) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.client.impl.protocol.task.AbstractMessageTask.initializeAndProcessMessage(AbstractMessageTask.java:118) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.client.impl.protocol.task.AbstractMessageTask.run(AbstractMessageTask.java:98) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:127) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.processPartitionSpecificRunnable(OperationThread.java:159) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.process(OperationThread.java:142) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.doRun(OperationThread.java:124) ~[hazelcast-3.6.3.jar:3.6.3]
    at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.run(OperationThread.java:99) ~[hazelcast-3.6.3.jar:3.6.3]
    at ------ End remote and begin local stack-trace ------.(Unknown Source) ~[?:?]
    at com.hazelcast.client.spi.impl.ClientInvocationFuture.resolveResponse(ClientInvocationFuture.java:128) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at com.hazelcast.client.spi.impl.ClientInvocationFuture.get(ClientInvocationFuture.java:95) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at com.hazelcast.client.spi.impl.ClientInvocationFuture.get(ClientInvocationFuture.java:74) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at com.hazelcast.client.spi.impl.ClientInvocationFuture.get(ClientInvocationFuture.java:37) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at com.hazelcast.client.spi.ClientProxy.invokeOnPartition(ClientProxy.java:126) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at com.hazelcast.client.spi.ClientProxy.invoke(ClientProxy.java:120) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at com.hazelcast.client.proxy.ClientMapProxy.unlock(ClientMapProxy.java:571) ~[hazelcast-client-3.6.3.jar:3.6.3]
    at org.apache.storm.daemon.executor$fn__7953$tuple_action_fn__7955.invoke(executor.clj:728) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.daemon.executor$mk_task_receiver$fn__7874.invoke(executor.clj:461) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.disruptor$clojure_handler$reify__7390.onEvent(disruptor.clj:40) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.utils.DisruptorQueue.consumeBatchToCursor(DisruptorQueue.java:439) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.utils.DisruptorQueue.consumeBatchWhenAvailable(DisruptorQueue.java:418) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.disruptor$consume_batch_when_available.invoke(disruptor.clj:73) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.daemon.executor$fn__7953$fn__7966$fn__8019.invoke(executor.clj:847) [storm-core-1.0.1.jar:1.0.1]
    at org.apache.storm.util$async_loop$fn__625.invoke(util.clj:484) [storm-core-1.0.1.jar:1.0.1]
    at clojure.lang.AFn.run(AFn.java:22) [clojure-1.7.0.jar:?]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_65]
@jerrinot

This comment has been minimized.

Copy link
Contributor

commented Aug 16, 2016

@pramodterdale: hello, thanks for the report. Do you have a reproducer? Could you describe your scenario a bit?

@pramodterdale

This comment has been minimized.

Copy link
Author

commented Aug 16, 2016

The way i am using the locking mechanism is

HazelcastProvider provider = HazelcastProvider.getInstance(clientConfig);
HazelcastInstance hzInstance = provider.getHzClientInstance();
IMap<String, Integer> keyMap = hzInstance.getMap("KeyMap");
 ..
 ..
 keyMap.lock(cacheKey);
try
{
 ..
 ..
}
 catch (Exception e)
{ 
}
finally
 {
  keyMap.unlock(cacheKey);
 }

I am running the above block of code in Storm bolts with 8 threads so it is running in parallel in 8 threads and i get this error as soon as start processing the incoming data stream from kafka bus.

Let me know if you need more details.

Thanks

@jerrinot

This comment has been minimized.

Copy link
Contributor

commented Aug 23, 2016

@pramodterdale: Can you try it with Hazelcast 3.7?

@pramodterdale

This comment has been minimized.

Copy link
Author

commented Aug 24, 2016

Will try and let you know.

@pramodterdale

This comment has been minimized.

Copy link
Author

commented Sep 30, 2016

I upgraded to Hazelcast 3.7 and have not seen this issue so far, if it appears will reopen the defect, please go ahead and close it for now.

@jerrinot

This comment has been minimized.

Copy link
Contributor

commented Sep 30, 2016

@pramodterdale: great, many thanks for heads-up!

@gthazmatt

This comment has been minimized.

Copy link

commented Sep 28, 2017

I am getting the same error in 3.8.6 also using an IMap. I have three clients connected together. Here are the steps that produce the error:

ClientA: hazelcastInstance.getMap(collection).lock(value); //success
ClientB: hazelcastInstance.getMap(collection).unlock(value); //stack trace prints for IllegalMonitorStateException
ClientC: hazelcastInstance.getMap(collection).unlock(value); //stack trace prints for IllegalMonitorStateException on **ClientB**

I'm ignoring the IllegalMonitorStateException thrown on unlock, but it's being logged from another thread.

SEVERE: [url]:5701 [dev] [3.8.6] Current thread is not owner of the lock! -> Owner: 8181ce8c-8db1-4543-9647-e20ce4b87dd1, thread-id: 1
java.lang.IllegalMonitorStateException: Current thread is not owner of the lock! -> Owner: 8181ce8c-8db1-4543-9647-e20ce4b87dd1, thread-id: 1
        at com.hazelcast.concurrent.lock.operations.UnlockOperation.unlock(UnlockOperation.java:74)
        at com.hazelcast.concurrent.lock.operations.UnlockOperation.run(UnlockOperation.java:63)
        at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:186)
        at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:401)
        at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:115)
        at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:100)
@mmedenjak

This comment has been minimized.

Copy link
Contributor

commented Sep 29, 2017

Hi @gthazmatt !

As far as I can see, the only strange thing here is that on the third statement called on ClientC, the stack trace occurs on ClientB. That is most probably not possible unless ClientB retried to acquire the lock.
The other behaviour is as expected - ClientA is the owner of the lock. And more specifically, only one thread on ClientA is the owner of the lock. All other threads on ClientA and all threads on ClientB or ClientC should get the same exception that they are not the owners of the lock.

@gthazmatt

This comment has been minimized.

Copy link

commented Sep 29, 2017

Thank you for your reply. The three clients are actually just a simple command line app I put together to test locking before incorporating it in our app. The three steps I laid out are the only interactions with the lock.

The behavior of the lock is as I would expect, but I don't expect a stacktrace at all, let alone on a client that isn't attempting an unlock, as I am catching the exception thrown by unlock. At no time did ClientB or ClientC attempt to acquire the lock at all. They only attempted to unlock.

@mmedenjak

This comment has been minimized.

Copy link
Contributor

commented Sep 29, 2017

The unlock on the different member is strange. Can you make a breakpoint and see which method caused the exception to be thrown? Or make a simple reproducer and post it here?
Also, if you want to avoid the exception in the first place, you can use ILock#tryLock() or ILock#isLockedByCurrentThread

@gthazmatt

This comment has been minimized.

Copy link

commented Sep 29, 2017

I looked at the ILock class, but I like the functionality of locking a value in a named collection that is provided by the IMap class.

It looks like the task that is created for the unlock is put on the queue being used in the OperationThread. My guess is that this queue is shared among clients because the task that is created by ClientC is being picked up by ClientB. Regardless of which client picks it up, the following stack trace shows where it is being logged:

com.hazelcast.spi.Operation.logError(Operation.java:488)
        at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.handleOperationError(OperationRunnerImpl.java:343)
        at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:190)
        at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:120)
        at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:100)
@gthazmatt

This comment has been minimized.

Copy link

commented Oct 4, 2017

Should I open a new issue for this?

@mmedenjak

This comment has been minimized.

Copy link
Contributor

commented Oct 5, 2017

I'm not sure how two clients may share an operation thread. If you can provide a reproducer or share some code on how you are instantiating the clients and how they are using the IMap API, please open a new issue.

@sancar

This comment has been minimized.

Copy link
Member

commented Oct 5, 2017

Hi @gthazmatt ,
There seems to be some confusion in this issue.

SEVERE: [url]:5701 [dev] [3.8.6] Current thread is not owner of the lock! -> Owner: 8181ce8c-8db1-4543-9647-e20ce4b87dd1, thread-id: 1
java.lang.IllegalMonitorStateException: Current thread is not owner of the lock! -> Owner: 8181ce8c-8db1-4543-9647-e20ce4b87dd1, thread-id: 1
        at com.hazelcast.concurrent.lock.operations.UnlockOperation.unlock(UnlockOperation.java:74)
        at com.hazelcast.concurrent.lock.operations.UnlockOperation.run(UnlockOperation.java:63)
        at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:186)
        at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:401)
        at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:115)
        at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:100)

The log above is printed on the server threads. An unlock operation triggered by client failed, logged on the server and same exception is propagated to client.

To make sure we are using the terminology right
We are calling the instances created by HazelcastClient.newHazelcastClient(clientConfig); client
Hazelcast.newHazelcastInstance(config); these instances are called server/member

So either you are using server and client in same jvm together or
You are referring hazelcast members as client. In both case, following log is possible and makes sense.

ClientC: hazelcastInstance.getMap(collection).unlock(value); //stack trace prints for IllegalMonitorStateException on ClientB

The exception you share on is actually same exception propagated to user thread in ClientC, and same exception also printed on server(ClientB or server working embedded with ClientB) when operation failed.

@gthazmatt

This comment has been minimized.

Copy link

commented Oct 5, 2017

Ah, I see. These are three members on three different machines (switching to MemberA, MemberB, and MemberC). I still don't understand why the exception would print on MemberB the second time. If MemberB's user thread attempted to unlock the value and failed, why would its server thread care if another member attempts the same thing?

@sancar

This comment has been minimized.

Copy link
Member

commented Oct 6, 2017

All our operations if sending an exception while working logs it on the server they run. In some special cases that we think logging is not necessary we are suppressing.
IllegalMonitorState is not an exception that you implement against. You should always do lock/unlock blocks so that you will never get this exception. Since we assume it should be rare, we don't suppress the exception. Secondly it is really valuable to see in which member operation failed when debugging.

In your case, MemberC initiates unlock.
Operations goes to MemberB.
Illegal monitor state is detected, exception is created and logged on MemberB.
Exception also propagated back to MemberC.
And finally MemberC throws that to waiting user thread.

@gthazmatt
Makes sense ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.