Why does it seem to take a long time for this synchronized block to get a lock?

Question

I am new to multi-threading in java, and I have a question some might find trivial.

I have to debug a third party piece of code and I need some basic information, to know where to look for the problem because the code is very large.

When the following code runs:

public void method()
{
   long startTime = System.currentTimeMillis();
   synchronized (obj)
   {
      log( "time:" + System.currentTimeMillis() - startTime + " ms" );
      ...
   }
}

I get:

11:13:12 - time: 3816 ms
...
11:14:14 - time: 0 ms

Why is taking so long (3816 ms) to get the lock for the object? Where should I look? For example, I would imagine a possible answer would be to look for code which acquires the lock for "obj" i.e. block such as:

synchronized (obj) { ... }

Or is it possible that any modification at the object "obj" without "synchronized" can also lock the object?

Glyceric

Is it the first log you got? – Badgett

@CommuSoft yes this is the first log i got – Glyceric

@fge the object is a complex object. It is used in many different classes and does many different things. Could you explain why you asked this question, so that I can give you a precise answer? – Glyceric

Perhaps the JVM does JIT compilation at that point. The first time a code block is executed is "burn in" time: it needs to translate Java bytecode first. – Badgett

@CommuSoft if this is Oracle's JVM and therefore HotSpot, optimizations start to trigger only after 10k executions AFAIK; as such, I doubt that the JIT is the answer here – Mistiemistime

@fge: that's why it's a comment. But JIT always results in some delay. And it explains some time differences one measures between two statements to some extend. Although a differences of 3.8s is indeed too much... – Badgett

You are waiting outside a locked bathroom door. What is taking so long in there? The answer to that question has absolutely nothing to do with the qualities of the lock on the door, and everything to do with who is in the room. Remember, the advice for using locks is: (1) don't spend any time in locks, to avoid contention, and (2) have as few locks as possible, to avoid deadlock bugs. The clever reader will note that these two excellent bits of advice are in fact opposites, which makes for problems when trying to follow it. Funny game, concurrency; the only way to win is to not play. – Acrid

for the record: I found out what was locking. The answer from the user @malt helped me. Both point 1 and 2 from his answer were relevant. Now I have to realize why the locking thread is taking so long. But know it has nothing to do with concurrency. Thanks to all of you. – Glyceric

Answer 1

If it takes a thread that long to obtain a lock, it's because someone else is currently holding it.

You should look for two things:

1. Code blocks which synchronize on the same object or on other references to it (known as synchronized statements) :

   synchronized (obj) {
    ... 
   }
   

2. Synchronized methods within the object itself.

   Say obj is of type MyObject, then you should look for methods such as these:

   public class MyObject{
       public synchronized void myMethod() {
        ...
       }
   }
   

   Because they are essentially the same as

   public class MyObject{
       public void myMethod() {
           synchronized (this) {
            ...
           }
       }
   }
   

   So if a thread is executing obj.myMethod(), threads that want to enter a synchronized (obj) block will have to wait, as they all lock on the same object. This, by the way, is the reason why I strongly recommend never using the synchronized method syntax, and always locking over a private (or protected) class member.

If another thread is currently executing code within such a block, the current thread will be locked out until the other thread finishes.

You can use jvisualvm's Threads tab or Jstack to take snapshots of the current execution state of all threads and the locks they're holding. If you're on android, see this answer on how to get a thread dump on there.

Rondarondeau

@Glyceric yes, of course. I've added that detail now. To avoid this issue I strongly recommended you avoid declaring synchronized methods, and instead synchronize on a private class member. – Rondarondeau

You can use jvisualvm's Threads tab or Jstack to take snapshots of the current execution state of all threads and the locks they're holding. ==> I am developing on android. Do you have a suggestion for this environment? – Glyceric

@Glyceric I don't, but stack overflow does - #13589574 – Rondarondeau

Just noticed that Point 2 of the answer was relevant. There were other synchronized methods which were called by other threads – Glyceric

Answer 2

The jstack utility that is part of the jdk can help with this. The -l (long listing) option will print all of the locks held by various threads. If you can catch your program in the midst of the issue then you can find the other thread that is holding the lock. You do this by finding your thread, seeing what condition object it is waiting on, then searching the rest of the stack traces for that condition object.

This article has more detailed information about how to look at the thread dump.

Claudio

The question tagged [android], so JDK utilities may not be the most useful. – Wilhelminawilhelmine

@Wilhelminawilhelmine It wasn't tagged "android" when this answer was posted – Rondarondeau

Answer 3

You need to check the following:

• Are there any method/block in your obj class, which is synchronized on this. If yes then there must be multiple threads where one is your above code, while other might be using the methods of same obj.
• Where all you are sharing obj? If it's shared by multiple classes, then check out who locks on same obj.

Mazard

You should also look if obj is used not only with synchronized but also with notifyand lock that can have interactions. It should be avoided to mix those two synchronization modes, but when debugging third party code, you should be ready for the worst. – Gomar

Yeah but see that if it's not notified then OP's output would have never printed anything. Also it's but obvious that if you use synchronize then you would use notify/wait but yeah as you say can't really say for sure.. – Mazard