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

[Thomas Stuefe]

On Wed, 5 May 2021 22:17:17 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:
> 
>   Use LogTagSetMapping<LogTag::__NO_TAG>::tagset() instead of NULL pointer.

Hi Xin,

I had a first look. This is a massive change, review will take some more time. Had a look at logAsyncFlusher.hpp and the gtests. 

Cheers, Thomas

src/hotspot/share/logging/logAsyncFlusher.hpp line 37:

> 35: 
> 36: template <typename E, MEMFLAGS F>
> 37: class LinkedListDeque : private LinkedListImpl<E, ResourceObj::C_HEAP, F> {

I don't think it is good design to reuse LinkedList as a base class for this. The base class is unaware of the fact that you keep track of the list tail here. If used incorrectly (eg calling base class removal functions) you could damage this structure, because the tail node gets removed. Its also not really clear: a deque has two pointers, and here they are spread over different points in the class hierarchy.

Moreover, this is ambivalent in naming: "LinkedListDeque" suggests a general purpose class, which this is not.

Since a deque is really trivial to implement, I would suggest scrapping this class and just implement a very primitive deque custom tailored to your needs and name it AsyncLogBuffer or AsyncLogBufferDeque. It does not even have to be templatized. All it needs is push_front, pop_back, some sort of "take over" operation to move list content to another list, and the peeks. 

I also would suggest you don't add an explicit node object but just give AsyncLogMessage directly a "next" pointer and use it as its own node; that way, you can save copy constructor calls. You can then make AsyncLogMessage a non-copyable object, perhabs even immutable, just with that one constructor. And you can transform "AsyncLogMessage::destroy" to a real destructor, let the list take care of destruction, and do not need to call "destroy" explicitly on writeback.

An additional advantage of a custom deque is that we can optimize it later for our purposes without inconveniencing anyone: e.g. changing the allocation for the nodes to raw malloc to be able to use UL in the memory allocation layer, or slab-allocation of nodes....

src/hotspot/share/logging/logAsyncFlusher.hpp line 54:

> 52:   }
> 53: 
> 54:   void pop_all(LinkedList<E>* logs) {

If you do your own Deque as proposed above, I would change this to a simple "take_over" operation where you hand over _head and _tail to the new list and NULL them out in the old one. Way easier to read. You do not need the ability of "move()" to append to a non-empty receiver list.

src/hotspot/share/logging/logAsyncFlusher.hpp line 86:

> 84:   LogFileOutput&   _output;
> 85:   LogDecorations*  _decorations;
> 86:   char*            _message;

I would keep decorations by value here. They are small enough.

src/hotspot/share/logging/logAsyncFlusher.hpp line 93:

> 91:     _decorations = new LogDecorations(decorations);
> 92:       // allow to fail here, then _message is NULL
> 93:     _message = os::strdup(msg, mtLogging);

Idea for a future improvement. If we knew here that message is a string literal (many are, since many log messages don't have format specifiers) we could just store the original pointer and save the strdup.

src/hotspot/share/logging/logAsyncFlusher.hpp line 107:

> 105:   void writeback();
> 106: 
> 107:   // two AsyncLogMessage are equal if both _output and _message are same.

Decorators don't matter here?

src/hotspot/share/logging/logAsyncFlusher.hpp line 123:

> 121: 
> 122: typedef LinkedListDeque<AsyncLogMessage, mtLogging> AsyncLogBuffer;
> 123: typedef KVHashtable<LogFileOutput*, uintx, mtLogging> AsyncLogMap;

This is just to keep statistics of dropped messages per output, right? 

I think it would be a lot simpler just to add a reset-able counter to LogFileOutput directly. I don't even think it has to be uintx. 32bit should be sufficient (also, uintx makes no sense - do we somehow expect less message drops on 32bit platforms?)

test/hotspot/gtest/logging/test_asynclog.cpp line 44:

> 42: };
> 43: 
> 44: class AsyncLogTest : public LogTestFixture {

Unless you plan to add other code to this fixture I would prefer a regular RAII object like we do in hotspot, and naming it `AsyncModeMark`, and placing it at the start of each function instead. 

Reason: you can use EXPECT macros inside to test stuff and they fire as part of the test, its easier to debug, and it is common notation so hotspot devs know what this is without looking up rules about googletest fixtures.

But kudos for leaving clean state after your tests.

test/hotspot/gtest/logging/test_asynclog.cpp line 45:

> 43: 
> 44: class AsyncLogTest : public LogTestFixture {
> 45:   bool _saved_async_mode;

const?

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

Changes requested by stuefe (Reviewer).

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