RFR: 8229517: Support for optional asynchronous/buffered logging [v16]

Wed May 19 17:07:57 UTC 2021

On Mon, 17 May 2021 18:27:16 GMT, Xin Liu <xliu at openjdk.org> wrote:

>> This patch provides a buffer to store asynchrounous messages and flush them to
>> underlying files periodically.
>
> Xin Liu has updated the pull request incrementally with one additional commit since the last revision:
> 
>   Implement the new discard policy: drop the incoming message.
>   
>   This patch also fix a bug. meta messages append to the temp logs instead
>   of directly calling output->write_blocking(). This guranatees logsites are non-blocking.

Hi Xin,

thanks a lot for constantly improving this change. It looks pretty good now. I only have minor comments and some questions. Once these are fixed/answered I'll approve the PR.

Best regards,
Volker

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

> 62:     }
> 63:     // drop the enqueueing message.
> 64:     return;

I don't understand this? If we drop the incoming message `msg`, why do we increment the drop counter for the `LogFileOutput` of the first (i.e. `front()`) enqueued message?
Shouldn't this simply be:

if (_buffer.size() >= _buffer_max_size)  {
  bool p_created;
  uint32_t* counter = _stats.add_if_absent(msg->output(), 0, &p_created);
  *counter = *counter + 1;
  return;

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

> 123: 
> 124: void AsyncLogWriter::perform_IO() {
> 125:   // use kind of copy-and-swap idiom here.

Can you please start new sentences with an uppercase letter.

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

> 124: void AsyncLogWriter::perform_IO() {
> 125:   // use kind of copy-and-swap idiom here.
> 126:   // Empty 'logs' 'swaps' the content with _buffer.

Only quote variables, i.e.: Empty 'logs' swaps the content with '_buffer'.

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

> 127:   // Along with logs destruction, all procceeded messages are deleted.
> 128:   //
> 129:   // the atomic operation 'move' is done in O(1). All I/O jobs are done without lock.

Start with uppercase letter. Replace 'move' by 'pop_all()' because at this point it in´s not obvious that 'pop_all()' eventually calls 'LinkedList::move()'.
What do you mean with "atomic" here? Maybe better remove?

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

> 173:     if (self->_state == ThreadState::Initialized) {
> 174:       Atomic::release_store_fence(&AsyncLogWriter::_instance, self);
> 175:       // all readers of _instance after fence see NULL,

Please start sentences with uppercase letter.

I don't understand this? Wouldn't all readers of '_instance' see 'self' *after* it was stored there with 'Atomic::release_store_fence()`? Or do you wanted to say *before* the fence here?

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

> 175:       // all readers of _instance after fence see NULL,
> 176:       // but we still need to ensure no active reader of any tagset.
> 177:       // After then, we start AsyncLog Thread and it exclusively takes

After **that**...

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

> 178:       // over all logging I/O.
> 179:       for (LogTagSet* ts = LogTagSet::first(); ts != NULL; ts = ts->next()) {
> 180:         ts->wait_until_no_readers();

This loop is the only thing I'm not understanding in this whole PR but that doesn't mean it is wrong (it's probably just caused by my limited understanding of UL).
So why do we have to wait here until "there are no more readers" and what does that actually means? Is this necessary to prevent mixing log messages which have been printed before async logging was started?

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

> 87: 
> 88:   LinkedListNode<E>* head() const {
> 89:     return static_cast<const LinkedList<E>* >(this)->head();

Why not simply `return this->_head`?

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

> 130:   // and a variable-length c-string message.
> 131:   // A normal logging  message is smaller than vwrite_buffer_size, which is defined in logtagset.cpp
> 132:   const size_t _buffer_max_size = {AsyncLogBufferSize / (sizeof(AsyncLogMessage) + sizeof(LogDecorations) + vwrite_buffer_size)};

Isn't the `LogDecorations` object part of the `AsyncLogMessage` object? It is stored there as a "value object" not as a reference so its size should already be included in `sizeof(AsyncLogMessage)`.

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

> 555:   out->print_cr("\nAsynchronous logging(off by default):");
> 556:   out->print_cr(" -Xlog:async");
> 557:   out->print_cr("  All log messages write to an intermediate buffer first and then will be flushed"

All log messages are written to an intermediate buffer first and will then be flushed

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

> 604:   out->print_cr(" -Xlog:async -Xlog:gc=debug:file=gc.log -Xlog:safepoint=trace");
> 605:   out->print_cr("\t Write logs asynchronously. Enable messages tagged with 'safepoint' up to 'trace' level to stdout ");
> 606:   out->print_cr("\t and messages tagged with 'gc' up to 'trace' level to file 'gc.log'.");

This should read "..up to 'debug' level.."

src/hotspot/share/logging/logDecorations.hpp line 2:

> 1: /*
> 2:  * Copyright (c) 2015, 2021, Oracle and/or its affiliates. All rights reserved.

No reason to update copyright year if there are no other changes in this file.

src/hotspot/share/runtime/flags/jvmFlagConstraintsRuntime.hpp line 2:

> 1: /*
> 2:  * Copyright (c) 2015, 2021, Oracle and/or its affiliates. All rights reserved.

No reason to update copyright year if there are no other changes in this file.

src/hotspot/share/runtime/thread.hpp line 106:

> 104: //     - WatcherThread
> 105: //     - JfrThreadSampler
> 106: //     - LogAsyncFlusher

I think this should be `AsyncLogWriter`

test/hotspot/gtest/logging/logTestUtils.inline.hpp line 24:

> 22:  */
> 23: 
> 24: #include "jvm.h"

Why do you need this extra include if there are no other changes in this file?

test/hotspot/gtest/logging/test_logDecorations.cpp line 2:

> 1: /*
> 2:  * Copyright (c) 2016, 2021, Oracle and/or its affiliates. All rights reserved.

No reason to update copyright year if there are no other changes in this file.

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

Changes requested by simonis (Reviewer).

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