Question about tty lock rank

[David Holmes]

On 14/02/2019 5:28 pm, Thomas Stüfe wrote:
> Thank you David.
> 
> Do you still remember what the intent of the ttyLock is? To prevent 
> tearing multi-line output? 

I've always assumed so.

> If yes, why only when we print to tty?

No idea.

David
-----

> 
> ..Thomas
> 
> On Wed, Feb 13, 2019 at 10:55 PM David Holmes <david.holmes at oracle.com 
> <mailto:david.holmes at oracle.com>> wrote:
> 
>     Hi Thomas,
> 
>     There are known limits on trying to use tty too early, or from certain
>     places. I doubt anyone recalls the exact design around the lock rank
>     placement and that design has been distorted over time to allow other
>     locks to be jammed in to the scheme. Getting rid of, or completely
>     re-doing lock ranking, is something we've been musing on for a while
>     now.
> 
>     Cheers,
>     David
> 
>     On 14/02/2019 1:58 am, Thomas Stüfe wrote:
>      > 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
>      >
>