13

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?

Malt
  • 28,965
  • 9
  • 65
  • 105
dritan
  • 882
  • 2
  • 8
  • 22
  • Is it the first log you got? – Willem Van Onsem Mar 02 '15 at 17:07
  • @CommuSoft yes this is the first log i got – dritan Mar 02 '15 at 17:10
  • @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? – dritan Mar 02 '15 at 17:12
  • 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. – Willem Van Onsem Mar 02 '15 at 17:12
  • 1
    @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 – fge Mar 02 '15 at 17:15
  • @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... – Willem Van Onsem Mar 02 '15 at 17:17
  • 8
    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. – Eric Lippert Mar 02 '15 at 22:19
  • 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. – dritan Mar 03 '15 at 10:26

3 Answers3

11

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.

Community
  • 1
  • 1
Malt
  • 28,965
  • 9
  • 65
  • 105
  • 1
    @dritan 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. – Malt Mar 02 '15 at 17:25
  • 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? – dritan Mar 02 '15 at 17:26
  • @dritan I don't, but stack overflow does - http://stackoverflow.com/questions/13589074/how-to-make-java-thread-dump-in-android – Malt Mar 02 '15 at 17:27
  • 1
    Just noticed that Point 2 of the answer was relevant. There were other synchronized methods which were called by other threads – dritan Mar 02 '15 at 17:43
5

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.

Martin Serrano
  • 3,727
  • 1
  • 35
  • 48
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.
SMA
  • 36,381
  • 8
  • 49
  • 73
  • You should also look if `obj` is used not only with `synchronized` but also with `notify`and `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. – Serge Ballesta Mar 02 '15 at 17:13
  • 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.. – SMA Mar 02 '15 at 17:16