RFR: 8229517: Support for optional asynchronous/buffered logging

Xin Liu xliu at openjdk.java.net
Tue May 25 07:30:23 UTC 2021


On Tue, 25 May 2021 06:49:41 GMT, David Holmes <david.holmes at oracle.com> wrote:

> It isn't at all clear why it was necessary to introduce the io_sem just
so some gtest will pass. Why did these tests fail?

You brought up this issue when you ran into crashes. https://github.com/openjdk/jdk/pull/3135#issuecomment-845993038
Here is my analysis. AsyncLogWriter::flush() was unsafe.  Previously,  flush() only flushed data out of the buffer. yes, it try to write what it dequeued, but there's a race condition I didn't think of!

Here is the case:
A thread invokes AsyncLogWriter::flush() and the buffer is empty() at that time. Previously, write() returned because it had nothing to write. However, the following code in log writer thread may be executing in parallel!  


  while (!it.is_empty()) {
    AsyncLogMessage* e = it.next();
    char* msg = e->message();

    if (msg != nullptr) {
      e->output()->write_blocking(e->decorations(), msg);
      os::free(msg);
    }
  }

If that race condition happens, it's unsafe to read log files after AsyncLogWriter::flush(). log writer thread is writing them!
It's even not safe to destroy LogOutput instances here. (That's the byproduct bug I discovered).
https://github.com/openjdk/jdk/pull/3135/files#diff-64ba5a15efefc31cf8bc2b1c51100933075913fc8ed6028ad348197e086c3c33R287

How to guarantee file writings have done?  That's why I introduced _io_sem. 
Now write() acquires and releases _io_sem no matter what. Even the buffer is empty.
This can guarantee that the buffer used to be empty and all dequeued messages are written by flush(). 

After I strengthen `flush()`, I found I could even enable all unified logging tests in async mode.

-------------

PR: https://git.openjdk.java.net/jdk/pull/3135


More information about the hotspot-dev mailing list