Synchronized code section causes Tomcat to hang on shutdown

[Bai Shen]

I'm not sure why this is happening. Any help is appreciated.

I have a context listener that creates a thread pool and populates it full of jobs. These jobs occasionally require access to the same resource, so I have a section of code that's synchronized with the static log.

	static final Logger log = LoggerFactory.getLogger(Clazz.class);

	private String doStuff() throws IOException {
        //code
		synchronized (log) {
                //more code
		}
	}

Any time any of the jobs go through the synchronized section, Tomcat will not shutdown properly. Even if I comment out all of the "more code" section so that it's just the synchronized part, this happens. If I comment out the synchronized line, or the code doesn't call that method, Tomcat shuts down correctly.

What would cause Tomcat to hang like that? I can only think that it's not locking and unlocking correctly, but the code works fine, limiting access as it should. It's just that Tomcat won't shutdown properly.

[Vijitha Kumara]

Are there any warnings (if no errors) in the logs? Are you sure this is the code causes this issue? And as you said you created a thread pool within your code, are they properly terminated?

[Rob Spoor]

Is this synchronized block executed inside another synchronized block or method? If so you could have deadlock if some other thread tries to get the locks in reverse order.

A short example:

class A
{
    public synchronized void doSomething(B b)
    {
        synchronized (b)
        {
            ...
        }
    }
}

class B
{
    public synchronized void doSomething(A a)
    {
        synchronized (a)
        {
            ...
        }
    }
}

Let's assume we have one instance "a" of class A and one instance "b" of class B. If thread X calls a.doSomething(b) and thread Y calls b.doSomething(a) you risk deadlock. The following time line shows you:
- thread X enters the a.doSomething method and acquires the lock for object "a".
- thread Y enters the b.doSomething method and acquires the lock for object "b".
- thread X tries to enter the synchronized block but must wait for thread Y to release the lock.
- thread Y tries to enter the synchronized block but must wait for thread X to release the lock.

Threads X and Y are now forever waiting on each other, and therefore you will have deadlock.

The solution is simple: always use the same ordering when acquiring multiple locks. So in this case, always first get the lock for "a" and then for "b" or vice versa:

class B
{
    public void doSomething(A a)
    {
        synchronized (a)
        {
            synchronized (this)
            {
                ...
            }
        }
    }
}

[Bai Shen]

Vijitha Kumara wrote:Are there any warnings (if no errors) in the logs? Are you sure this is the code causes this issue? And as you said you created a thread pool within your code, are they properly terminated?

No warnings or errors that I can find. As I mentioned, the code executes correctly. It's only when I go to shut down Tomcat that I have a problem. And it's only that stop on it's own. I have to terminate it.

I'm sure this is the code that causes the issue. If this method doesn't get called, Tomcat shuts down correctly. If I comment out the synchronized line, Tomcat shuts down correctly. I've already commented out everything inside the synchronized block with no effect.

What do you mean by your last question? I'm calling shutdownNow() on my thread pool in the contextDestroyed method of the context listener.

[Bai Shen]

Rob Spoor wrote:Is this synchronized block executed inside another synchronized block or method? If so you could have deadlock if some other thread tries to get the locks in reverse order.

I'm not AFAIK. Some of the other jobs use synchronized code, but they don't call each other. The only other thing I have synchronized is the listener code that kicks off a lot of the various jobs.

Although I had forgotten that some of the other jobs have synchronized code, and they don't see to cause the problem. But they each have their own thread pools, whereas this one is in the main thread pool. Also, this job is called from another job which waits for a return value. The others are all fire and forget jobs.

Hmm.

[Bai Shen]

ARGH! Apparently something weird is going on. If I leave the "more stuff" code uncommented and comment out the synchronized line, it hangs. If I comment out the "more stuff" but leave the synchronized line, it hangs. If I comment out both, it doesn't hang.

I wonder if Eclipse is not recompiling correctly.

[Paul Clapham]

Yeah, I often have that problem that I forget to have Eclipse build the project before I deploy it. Drives you crazy when you're running a previous version and debugging based on the current version.

But anyway I have one suggestion: is it possible that something else is synchronizing on the Logger? Like maybe some logging code? I would suggest creating a new Object for your code to synchronize on, rather than using the Logger.

[Bai Shen]

Paul Clapham wrote:Yeah, I often have that problem that I forget to have Eclipse build the project before I deploy it. Drives you crazy when you're running a previous version and debugging based on the current version.

I'm running Tomcat in Eclipse, so it should be the latest version. But I have seen Eclipse based products not recompile correctly before. And something is definately off, as now I have that entire section commented out and I'm still getting the issue. So I'm not sure what the problem is, but it's not the synchronized code.

But anyway I have one suggestion: is it possible that something else is synchronizing on the Logger? Like maybe some logging code? I would suggest creating a new Object for your code to synchronize on, rather than using the Logger.

I did change it to a more appropriate item. It was originally done to the logger as that was the only static variable I had in the object.

[Bai Shen]

Still tracking it down, but it looks like it's a Hibernate issue.

Thanks anyways.