In Java, how to log a message every time a given object's monitor is entered or exited?

Question

I am trying to debug some C/Java bindings that use some custom refcounting/locking. I would like to have the JVM print a message every time a given object has its monitor entered or exited. Is there any way to do this? Basically, I want this:

synchronized(lock) {
   ...
   System.out.println("hi");
   ...
}

to print this:

*** "lock" monitorenter
hi
*** "lock" monitorexit

I have looked at the XX options and found nothing. This is OpenJDK 6.

Answer 1

Good question. The only solution I could come up with is basically this:

Use a custom class-loader and preprocess the files with using a bytecode manipulation library such as ASM. (ASM has a good example of how to work with bytecode rewriting in class loaders.)

Then simply add a call to System.out.println before each monitorenter and monitorexit.

Thanks to the nice visitor pattern in the ASM library, this shouldn't be more than a screen or two of code.

Answer 2

Trying to debug a concurreny issue with creative uses of print statements is a losing battle, as your print statements could have their own concurrency bug and not print in the order you expect. Trying to debug or println your way out of a concurreny bug may sound good, but I don't think it will get you the result you want. You need to use careful thinking and logic to reason that your code is correct (more Computer Science than Software Engineering).

Concurrency issues are very hard. If you haven't read Concurrency in Practice, make sure you go read it. Then look at all the possible ways that your synchronized block can be reached, all the things it can change that are outside the scope of the lock, etc.

Answer 3

This would be a perfect situation to use dTrace.

Unfortunately that requires Solaris or OS X.

Fortunately OpenSolaris can still be downloaded and run in a virtual machine. It runs best in VirtualBox.

Answer 4

I don't believe there is a way to bind to a "locking" event in java. But you can look into java.lang.management for various locking information. For example, there is ThreadMXBean.findDeadlockedThreads()

Answer 5

Unless you write your own locking class (or modify the existing one) my guess is that it would be rather difficult to do what you want, specially if you are using a synchronized block over a monitor object and not a Lock class. However you can use the jstack command supplied with the JDK to analyze your process at runtime, check here for the man page, and also there is the JVM option -XX:-PrintConcurrentLocks for printing your locks if you stop your JVM process using Ctrl-Break (more options here).

Answer 6

I will suggest you to implement existing implementation of Lock class or implement one of you own (http://download.oracle.com/javase/tutorial/essential/concurrency/newlocks.html). Now you can override the lock and unlock method. So instead of using synchronized methods/statements make use of this facility and in lock/unlock methods put your logging :)