stringStream in UL and nested ResourceMarks
Erik Helin
erik.helin at oracle.com
Wed Jun 14 09:39:55 UTC 2017
On 06/13/2017 06:23 PM, Thomas Stüfe wrote:
> So, I changed a whole bunch of callsites to stack-only LogStreams and my
> brain is slowly turning to cheese :) therefore, lets do a sanity check
> if this is still what we want. Current snapshot of my work here:
>
> http://cr.openjdk.java.net/~stuefe/webrevs/8181917-UL-should-not-use-resource-memory-for-LogStream/current-work-2/webrev/
I think this looks really good! A few comments:
--- old/src/cpu/sparc/vm/vm_version_sparc.cpp
+++ new/src/cpu/sparc/vm/vm_version_sparc.cpp
@@ -381,7 +382,8 @@
- outputStream* log = Log(os, cpu)::info_stream();
+ LogStream ls(Log(os, cpu)::info());
+ outputStream* log = &ls;
I think the above pattern, LogStream ls(Log(foo, bar)::info()), turned
out very good, succinct and readable. Great work.
--- old/src/share/vm/classfile/classLoaderData.cpp
+++ new/src/share/vm/classfile/classLoaderData.cpp
@@ -831,16 +833,17 @@
- outputStream* log = Log(class, loader, data)::debug_stream();
- log->print("create class loader data " INTPTR_FORMAT, p2i(cld));
- log->print(" for instance " INTPTR_FORMAT " of %s", p2i((void
*)cld->class_loader()),
+ Log(class, loader, data) log;
+ LogStream ls(log.debug());
+ ls.print("create class loader data " INTPTR_FORMAT, p2i(cld));
+ ls.print(" for instance " INTPTR_FORMAT " of %s", p2i((void
*)cld->class_loader()),
cld->loader_name());
if (string.not_null()) {
- log->print(": ");
- java_lang_String::print(string(), log);
+ ls.print(": ");
+ java_lang_String::print(string(), &ls);
}
- log->cr();
+ ls.cr();
Do you really need the `log` variable here? It seems to that only `ls`
is used? Or did you mean to do the `outputStream* log = &ls` pattern
here as well? Or maybe I missed something?
--- old/src/share/vm/classfile/loaderConstraints.cpp
+++ new/src/share/vm/classfile/loaderConstraints.cpp
@@ -98,14 +101,14 @@
if (klass != NULL &&
klass->class_loader_data()->is_unloading()) {
probe->set_klass(NULL);
- if (log_is_enabled(Info, class, loader, constraints)) {
+ if (lt.is_enabled()) {
ResourceMark rm;
- outputStream* out = Log(class, loader,
constraints)::info_stream();
- out->print_cr("purging class object from constraint for name %s,"
+ LogStream ls(lt);
+ ls.print_cr("purging class object from constraint for name %s,"
" loader list:",
probe->name()->as_C_string());
for (int i = 0; i < probe->num_loaders(); i++) {
- out->print_cr(" [%d]: %s", i,
+ ls.print_cr(" [%d]: %s", i,
probe->loader_data(i)->loader_name());
}
}
Could the pattern
LogStream ls(lt);
ls.print_cr("hello, brave new logging world");
become
LogStream(lt).print_cr("hello, brave new logging world");
in order to have less line? Not sure if it is better, but it is at least
shorter :) Seems to be a rather common pattern as well...
--- old/src/share/vm/gc/g1/g1AllocRegion.cpp
+++ new/src/share/vm/gc/g1/g1AllocRegion.cpp
@@ -211,12 +213,9 @@
if ((actual_word_size == 0 && result == NULL) || detailed_info) {
ResourceMark rm;
- outputStream* out;
- if (detailed_info) {
- out = log.trace_stream();
- } else {
- out = log.debug_stream();
- }
+ LogStream ls_trace(log.trace());
+ LogStream ls_debug(log.debug());
+ outputStream* out = detailed_info ? &ls_trace : &ls_debug;
Could this be
LogStream out = LogStream(detailed_info ? log.trace() : log.debug());
or is this too succinct? Anyways, nice use of the ternary operator here,
makes the code much more readable.
I didn't have to look through the entire patch (got approx 50% of the
way), but I think the patch is becoming really good.
> Some thoughts:
>
> After talking this over with Eric off-list,
Well, off-list, but on IRC ;) #openjdk on irc.oftc.net for those that
want to follow along or join in on the discussion.
> I do not think anymore that reducing the:
>
> LogTarget(...) log;
> if (log.is_enabled()) {
> LogStream ls(log)...
> }
>
> to just
>
> LogStream ls(..);
> if (ls.is_enabled()) {
> ..
> }
>
> is really a good idea. We want logging to not cause costs if logging is
> disabled. But this way, we would always to pay the cost for initializing
> the LogStream, which means initializing outputStream at least once (for
> the parent class) and maybe twice (if the line buffer is an outputStream
> class too). outputStream constructor just assigns a bunch of member
> variables, but this is still more than nothing.
Yep, I still agree with this.
> ---
>
> Funnily, when translating all these callsites, I almost never used Log,
> but mostly LogTarget. This is because I wanted to avoid repeating the
> (level, tag, tag..) declarations, and the only way to do this is via
> LogTarget. Compare:
>
> Log(gc, metaspace, freelist) log;
> if (log.is_debug()) {
> LogStream ls(log.debug());
> }
>
> repeats the "debug" info. Even worse are cases where the whole taglist
> would be repeated:
>
> if (log_is_enabled(Info, class, loader, constraints)) {
> LogStream ls(Log( class, loader, constraints)::info());
> }
I think using LogTarget makes a lot sense in these situations, I prefer
that solution.
> ---
>
> I found cases where the usage of "xx_stream()" was not guarded by any
> is_enabled() flag but executed unconditionally, e.g. metaspace.cpp
> (VirtualSpaceNode::take_from_committed()):
>
> 1016 if (!is_available(chunk_word_size)) {
> 1017 Log(gc, metaspace, freelist) log;
> 1018 log.debug("VirtualSpaceNode::take_from_committed() not
> available " SIZE_FORMAT " words ", chunk_word_size);
> 1019 // Dump some information about the virtual space that is nearly
> full
> 1020 ResourceMark rm;
> 1021 print_on(log.debug_stream());
> 1022 return NULL;
> 1023 }
>
> So I really wondered: print_on(log.debug_stream()) is executed
> unconditionally, what happens here? What happens is that the whole
> printing is executed, first inside the LogStream, then down to
> LogTargetImpl, and somewhere deep down in UL (in LogTagSet::log()) the
> assembled message is ignored because there is no output connected to it.
> So we always pay for the whole printing. I consider this an error,
> right? I wonder how this could be prevented.
Hmm, I'm not an expert on UL internals, so take my ideas with a large
grain of salt :) Would be possible to have log.debug() do the
is_enabled() check (and just do nothing if the check is false)? That
would unfortunately penalize code that want to call log multiple times,
such as:
Log(foo, bar) log;
if (log.is_enabled()) {
log.debug(...);
log.debug(...);
log.debug(...);
}
In the above snippet, we would with my suggestion do the is_enabled
check 4 times instead of 1. OTOH, then one could then remove the first
check and just have:
Log(foo, bar) log;
log.debug(...);
log.debug(...);
log.debug(...);
(but still, this is 3 checks compared to 1).
How expensive is the is_enabled check? I _think_ (others, please correct
me if I'm wrong) that code is meant to use the "if (is_enabled()"
pattern if either the logging or getting the data for logging is
expensive. Hence, if code doesn't do this (and instead rely on
log.debug() to discard the data), then it should be fine with this
costing a bit more (or we have a bug).
> ---
>
> After doing all these changes, I am unsure. Is this the right direction?
> The alternative would still be my original proposal (tying the LogStream
> instances as members to the LogTarget instance on the stack). What do
> you think? I also think that if we go this direction, it might make
> sense to do this in jdk9, because auto-merging jdk9 to jdk10 may be a
> problem with so many changes. Or am I too pessimistic?
IMHO you are definitely heading in the right direction. Again, IMO, I
don't think we should do this in JDK 9. Focus on 10 and if backporting
turns to be problematic due to this change, then we fix it then ;)
Again, others might have a different view (if so, please chime in).
Thanks,
Erik
> Kind regards, Thomas
>
>
>
>
>
More information about the hotspot-dev
mailing list