[CURATOR-337] LeaderSelector logs stack trace with "The leader threw an exception" message erroneously

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 3.2.1, 2.11.1
• Component/s: Client
• Assignee: Cam McKenzie
• Reporter: Mark Payne
• Created: 27/Jul/16 19:56
• Updated: 01/Jun/18 22:18
• Resolved: 28/Jul/16 00:55

Description

I am using the LeaderSelector to choose a leader for a particular role in my cluster. Every time that I call close() on the leader selector, I end up with the following stack trace in my logs:

2016-07-20 20:20:47,814 ERROR [Leader Election Notification Thread-1] o.a.c.f.recipes.leader.LeaderSelector The leader threw an exception
java.lang.IllegalMonitorStateException: You do not own the lock: /leaders/Cluster Coordinator
        at org.apache.curator.framework.recipes.locks.InterProcessMutex.release(InterProcessMutex.java:140) ~[curator-recipes-2.10.0.jar:na]
        at org.apache.curator.framework.recipes.leader.LeaderSelector.doWork(LeaderSelector.java:425) [curator-recipes-2.10.0.jar:na]
        at org.apache.curator.framework.recipes.leader.LeaderSelector.doWorkLoop(LeaderSelector.java:441) [curator-recipes-2.10.0.jar:na]
        at org.apache.curator.framework.recipes.leader.LeaderSelector.access$100(LeaderSelector.java:64) [curator-recipes-2.10.0.jar:na]
        at org.apache.curator.framework.recipes.leader.LeaderSelector$2.call(LeaderSelector.java:245) [curator-recipes-2.10.0.jar:na]
        at org.apache.curator.framework.recipes.leader.LeaderSelector$2.call(LeaderSelector.java:239) [curator-recipes-2.10.0.jar:na]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_74]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_74]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_74]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_74]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_74]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_74]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_74]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_74]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_74]
        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_74]

This appears to be due to the fact that in LeaderSelector.doWork(), we call mutex.acquire() and then if an InterruptedException is thrown, the finally block calls mutex.release() even though the mutex has not been acquired. The finally block, then, should read:

if ( hasLeadership )
{
    hasLeadership = false;
    try
    {
         mutex.release();
    }
    catch ( Exception e )
    {
        ThreadUtils.checkInterrupted(e);
        log.error("The leader threw an exception", e);
        // ignore errors - this is just a safety
    }
}

That is, we should execute the body of the finally block only if hasLeadership == true.

Issue Links

• is related to: CURATOR-468 Closing an active leader selector always logs spurious error
• relates to: NIFI-2337 IllegalMonitorStateException when disconnecting node
• links to: GitHub Pull Request #158
• links to: GitHub Pull Request #159