Question about tty lock rank

[Thomas Stüfe]

Hi all,

Since tty lock rank is 3, this means that we cannot use tty when holding a
lock whose rank is <= 3, right?

For analysis reasons, I attempted to call EventLog::print_all(tty) at VM
exit.
That asserts right away in Monitor::set_owner_implementation() because
- event log printing obtains the event log mutex, which has rank 0
- then we attempt to print to tty, which obtains the tty lock on every call
to write(), which has rank 3
(A)

Ironically, then we attempt to write the owned locks as a debug help, write
again to tty and now get an owner!=self assert (B).

(gdb) bt
#0  0x00007ffff5eca9f2 in Monitor::lock_without_safepoint_check
(this=0x7ffff0013ae0, self=0x7ffff001c800) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/mutex.cpp:97
#1  0x00007ffff5ecaa93 in Monitor::lock_without_safepoint_check
(this=0x7ffff0013ae0) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/mutex.cpp:104
(B)
#2  0x00007ffff5f58271 in defaultStream::hold (this=0x7ffff0000930,
writer_id=25522) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:810
#3  0x00007ffff5f58356 in defaultStream::write (this=0x7ffff0000930,
s=0x7ffff7fd3660 " Locks owned:\n", len=14) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:838
#4  0x00007ffff5f56035 in
outputStream::do_vsnprintf_and_write_with_automatic_buffer
(this=0x7ffff0000930, format=0x7ffff68a6401 " Locks owned:",
ap=0x7ffff7fd3e98, add_cr=true) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:127
#5  0x00007ffff5f56112 in outputStream::do_vsnprintf_and_write
(this=0x7ffff0000930, format=0x7ffff68a6401 " Locks owned:",
ap=0x7ffff7fd3e98, add_cr=true) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:140
#6  0x00007ffff5f5626a in outputStream::print_cr (this=0x7ffff0000930,
format=0x7ffff68a6401 " Locks owned:") at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:154
#7  0x00007ffff6208f06 in Thread::print_owned_locks_on
(this=0x7ffff001c800, st=0x7ffff0000930) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/thread.cpp:992
#8  0x00007ffff5ecc325 in Thread::print_owned_locks (this=0x7ffff001c800)
at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/thread.hpp:741
(A)
#9  0x00007ffff5ecbc60 in Monitor::set_owner_implementation
(this=0x7ffff0013ae0, new_owner=0x7ffff001c800) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/mutex.cpp:413
#10 0x00007ffff5ecc29f in Monitor::set_owner (this=0x7ffff0013ae0,
owner=0x7ffff001c800) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/mutex.hpp:189
#11 0x00007ffff5ecaa6c in Monitor::lock_without_safepoint_check
(this=0x7ffff0013ae0, self=0x7ffff001c800) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/mutex.cpp:100
#12 0x00007ffff5ecaa93 in Monitor::lock_without_safepoint_check
(this=0x7ffff0013ae0) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/mutex.cpp:104
#13 0x00007ffff5f58271 in defaultStream::hold (this=0x7ffff0000930,
writer_id=25522) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:810
#14 0x00007ffff5f58356 in defaultStream::write (this=0x7ffff0000930,
s=0x7ffff7fd4140 "Compilation events (10 events):\n", len=32) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:838
#15 0x00007ffff5f56035 in
outputStream::do_vsnprintf_and_write_with_automatic_buffer
(this=0x7ffff0000930, format=0x7ffff64a32e5 "%s (%d events):",
ap=0x7ffff7fd4978, add_cr=true) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:127
#16 0x00007ffff5f56112 in outputStream::do_vsnprintf_and_write
(this=0x7ffff0000930, format=0x7ffff64a32e5 "%s (%d events):",
ap=0x7ffff7fd4978, add_cr=true) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:140
#17 0x00007ffff5f5626a in outputStream::print_cr (this=0x7ffff0000930,
format=0x7ffff64a32e5 "%s (%d events):") at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/ostream.cpp:154
#18 0x00007ffff576b507 in EventLogBase<StringLogMessage>::print_log_impl
(this=0x7ffff02b51b0, out=0x7ffff0000930) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/events.hpp:263
#19 0x00007ffff576b4bb in EventLogBase<StringLogMessage>::print_log_on
(this=0x7ffff02b51b0, out=0x7ffff0000930) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/events.hpp:256
#20 0x00007ffff590334a in Events::print_all (out=0x7ffff0000930) at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/utilities/events.cpp:56
#21 0x00007ffff5abcb50 in print_statistics () at
/shared/projects/openjdk/jdk-jdk/source/src/hotspot/share/runtime/java.cpp:361

Is this by design?

I would have thought that tty is one of the low level things which I would
always expect work, since it is often used for debug output.

Thank you,

Thomas