RFR(XL): 8181917: Refactor UL LogStreams to avoid using resource area

[Thomas Stüfe]

Dear all,

please take a look at this change. It attempts to solve the problem of UL
using resource area in LogStream classes and tripping over ResourceMark
when logging. There have been a couple of issues in that area and it
continues to be an accident waiting to happen.

issue: https://bugs.openjdk.java.net/browse/JDK-8181917
Prior discussion at hs-dev:
http://mail.openjdk.java.net/pipermail/hotspot-dev/2017-June/027090.html

The problem is that LogStreams use resource area backed memory to assemble
a log output line. Log output lines can be lengthy, so this memory may need
to be expanded. If that expansion happens down the stack in a sub function
which spans an own ResourceMark, we do assert or crash, see e.g. JDK-8181807
<https://bugs.openjdk.java.net/browse/JDK-8181807>, JDK-8149557
<https://bugs.openjdk.java.net/browse/JDK-8149557>, JDK-8167995
<https://bugs.openjdk.java.net/browse/JDK-8167995> . There is no real good
way around this but refraining from using resource area at all.

Please see the bug report description for more details.

The way to solve this is not to use Resource Memory for the Line memory but
instead to use C-Heap memory. Refraining from using Resource Memory also
makes UL more robust (not dependent on the Arena memory subsystem to work
correctly and not dependent of having a current Thread* available). It also
means it is less likely to change application behaviour - something logging
should avoid if possible.

Now, replacing resource area memory with C-Heap would be very simple, if
only for one detail: deallocation. Currently, most LogStream instances are
never deleted explicitly. They (both the instance and its line memory)
usually live in resource area: They are returned from the
"(trace|debug|info|warning|error)_stream()" function of LogImpl and used
like this or similar to this:

Log(jit, compilation) log;
if (log.is_debug()) {
          print_impl(log.debug_stream(), ... );
}

log.debug_stream() returns a one-time-use-only-resource-area-allocated
instance of LogStream(), which is never cleaned up. So, its destructor is
never run. That means that simply replacing the internal line memory of
LogStream with C-Heap alone is not sufficient, because the memory could
never get freed.

This problem has been discussed in hotspot-dev and in #openjdk IRC with the
UL developers. There are various solutions, but in the discussions the UL
developers preferred a plain and simple solution: to just remove the
"(trace|debug|info|warning|error)_stream()" completely and make LogStream a
stack-allocatable object only. That way it is used as a plain RAII object
and will free its internal memory when going out of scope.

In the above example, the callsite would have to be changed to something
like this:

Log(jit, compilation) log;
if (log.is_debug()) {
          LogStream ls(log.debug());
          print_impl(&ls, ... );
}

This solution requires fixing up a large number of callsites, but has the
benefit of making the API simpler.

----

This is the first draft of the fix mentioned above. All callsites were
fixed (but maybe it can be done better) and the LogStream API was greatly
simplified.

This is the complete webrev:

http://cr.openjdk.java.net/~stuefe/webrevs/8181917-refactor-ul-logstream/all-together-changes.webrev.00/webrev/index.html

Because it is a bit lengthy, but many changes are mechanical and
unexciting, I split the webrev in parts for easier review.

--

http://cr.openjdk.java.net/~stuefe/webrevs/8181917-refactor-ul-logstream/callsite-changes.webrev.00/webrev/

These are the - mostly mechanical - changes to the many callsites. Most of
these changes follow the same pattern. A code sequence using "xxx_stream()"
was split into declaration of LogTarget or Log (usually the former), an
"is_enabled()" query and declaration of LogStream on the stack afterwards.
This follows the principle that the logging itself should be cheap if
unused: the declaration of LogTarget is a noop, because LogTarget has no
members. Only if is_enabled() is true, more expensive things are done, e.g.
initializing the outputStream object and allocating ResourceMarks.

Note that I encountered some places where logging was done without
enclosing "is_enabled()" query - for instance, see gc/g1/heapRegion.cpp, or
cms/compactibleFreeListSpace.cpp. As far as I understand, in these cases we
actually do print (assemble the line to be printed), only to discard all
that work in the UL backend because logging is not enabled for that log
target. So, we pay quite a bit for nothing. I marked these questionable
code sections with an "// Unconditional write?" comment and we may want to
fix those later in a follow up issue?

--

http://cr.openjdk.java.net/~stuefe/webrevs/8181917-refactor-ul-logstream/api-changes.webrev.00/webrev/

The API changes mostly are simplifications. Before, we had a whole
hierarchy of LogStream... classes whose only difference was how the backing
memory was allocated. Because we now always use C-Heap, all this can be
folded together into a single simple LogStream class which uses Cheap as
line memory. Please note that I left "LogStreamNoResourceMark" and
"LogStreamCHeap" for now and typedef'ed them to the one single LogStream
class; I will fix those later as part of this refactoring.

--

http://cr.openjdk.java.net/~stuefe/webrevs/8181917-refactor-ul-logstream/logstream-optimization.webrev.00/webrev/

Finally, this is a small optimization for LogStream (in case we are worried
switching from resource area to malloc would be a performance issue).
LogStream was changed to use, for small log lines, a small internal fixed
sized char buffer and only switch to malloced memory for larger lines. The
small char array is a member of LogStream and therefore placed on the stack.

-----

The fix builds on Windows and Linux x64, and I found not yet any
regressions. Will run more jtreg tests next week.


Thanks in advance for the reviewing effort!

Kind Regards, Thomas