[jdk17] RFR: 8267952: async logging supports to dynamically change tags and decorators

[David Holmes]

On Wed, 23 Jun 2021 20:18:32 GMT, Xin Liu <xliu at openjdk.org> wrote:

> This patch fixed intermittent crashes of gtest/AsyncLogGtest.java. The root cause 
> is that previous flush() can't guarantee flush all pending messages in AsyncLog
> buffer. This patch implements flush() using a synchronizaton token and waits for
> completion. This approach isn't MT-safe but it can serialize all flush() calls in
> a thread. 
> 
> Two concurrent tests are appended to cover the hazard cases.
> This patch also comments LogConfiguration::configure_output() MT-safety.

Hi Xin,

Thank you for your patience and perseverance with this. 

This looks good to me now. The flush token seems to work well and is preferable to potentially blocking the async log thread.

I have a number of comments below, but they are all about comments.

I'm running this through our tier 1-7 testing again.

I have one remaining concern, which is just something we need to keep an eye on, and that is the potential for delaying VM termination if the async log writer gets blocked/delayed.

Thanks,
David
-----

src/hotspot/share/logging/logAsyncWriter.cpp line 142:

> 140:     } else if (e->output() == nullptr) {
> 141:       // encounter a flush token. take a record for the time being
> 142:       // and notify flush() after the loop.

Suggestion:
// This is a flush token. Record that we found it and then
// signal the flushing thread after the loop.

src/hotspot/share/logging/logAsyncWriter.cpp line 187:

> 185: }
> 186: 
> 187: // NOT MT-safe! see the comments in the header file.

Suggested comment:
// Inserts a flush token into the async output buffer and waits until the AsyncLog thread
// signals that it has seen it and completed all existing message processing.
// This is method is not MT-safe in itself, but is guarded by another lock in the usual
// usecase - see the comments in the header file for more details.

src/hotspot/share/logging/logAsyncWriter.cpp line 196:

> 194:       AsyncLogMessage token(nullptr, d, nullptr);
> 195: 
> 196:       // not disposable

I don't know what "not disposable" means.

src/hotspot/share/logging/logAsyncWriter.hpp line 124:

> 122: // Once async logging is established, there's no way to turn it off.
> 123: //
> 124: // instance() is MT-safe and returns the pointer of the singleton instance if and only if async logging is enabled and has well

s/well/successfully/

src/hotspot/share/logging/logAsyncWriter.hpp line 127:

> 125: // initialized. Clients can use its return value to determine async logging is established or not.
> 126: //
> 127: // enqueue() is the basic operation of AsyncLogWriter. 2 overloading versions of it are provided to match LogOutput::write().

s/2/Two/

src/hotspot/share/logging/logAsyncWriter.hpp line 133:

> 131: // flush() is designated to flush out all pending messages. MT-safety is not provided. It is no-op if async logging is not in use.
> 132: // In normal JVM termination, flush() is invoked in LogConfiguration::finalize(). When the users change logging configurations
> 133: // via jcmd, LogConfiguration::configure_output() invokes it with the protection of ConfigurationLock.

Suggestion:
// flush() ensures that all pending messages have been written out before it returns. It is not MT-safe
// in itself. When users change the logging configuration via jcmd, LogConfiguration::configure_output()
// calls flush() under the protection of the ConfigurationLock. In addition flush() is called during JVM
// termination, via LogConfiguration::finalize, but that occurs during the VM termination safepoint and so
// no calls to LogConfiguration::configure_output() can be active at the same time.

src/hotspot/share/logging/logAsyncWriter.hpp line 143:

> 141:   // It decreases in AsyncLogWriter::run()
> 142:   Semaphore _sem;
> 143:   Semaphore _flush_sem;

Please add a comment:
// _flush_sem ensures flush() only returns after all enqueued messages are processed

src/hotspot/share/logging/logConfiguration.cpp line 216:

> 214: // MT-SAFETY
> 215: //
> 216: // ConfigurationLock can guarantee that only one thread is performing reconfiguration. This function still needs

// The ConfigurationLock guarantees ...

src/hotspot/share/logging/logConfiguration.cpp line 220:

> 218: // logging allows users to dynamically change tags and decorators of a log output via DCMD(logDiagnosticCommand.hpp).
> 219: //
> 220: // A RCU-style synchronization 'wait_until_no_readers()' is imposed inside of 'ts->set_output_level(output, level)'

s/imposed/used/

src/hotspot/share/logging/logConfiguration.cpp line 221:

> 219: //
> 220: // A RCU-style synchronization 'wait_until_no_readers()' is imposed inside of 'ts->set_output_level(output, level)'
> 221: // if setting has changed. It guarantees that all logs either synchronous writing or enqueuing to the async buffer

// if a setting has changed. It guarantees that all logs, either synchronous writes or enqueuing to the async buffer,

src/hotspot/share/logging/logConfiguration.cpp line 222:

> 220: // A RCU-style synchronization 'wait_until_no_readers()' is imposed inside of 'ts->set_output_level(output, level)'
> 221: // if setting has changed. It guarantees that all logs either synchronous writing or enqueuing to the async buffer
> 222: // see the new tags and decorators. It's worth noting that the synchronization happens even level does not change.

s/even/even if the/

src/hotspot/share/logging/logConfiguration.cpp line 277:

> 275:   //
> 276:   // A flush operation guarantees to all pending messages in buffer are written before returning. Therefore,
> 277:   // the two hazards won't appear after it. It's a nop if async logging is not set.

Given all the other comments I think this can be simplified:

// For async logging we have to ensure that all enqueued messages, which may refer to previous decorators,
// or a soon-to-be-deleted outputs, are written out first. The flush() call ensures this. It is a no-op
// if async logging is not enabled.

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

Changes requested by dholmes (Reviewer).

PR: https://git.openjdk.java.net/jdk17/pull/130