RFR (S) 8210562: Change the verbosity threshold of logging for [oopstorage,ref]
kim.barrett at oracle.com
Wed Sep 12 13:00:05 UTC 2018
> On Sep 11, 2018, at 11:32 PM, Man Cao <manc at google.com> wrote:
> Hi all,
> I noticed that excessive logging messages appear in JDK11 with -Xlog:ref*=debug, which is the documented replacement for -XX:+PrintReferenceGC.
> I have a fix for it. Could someone review it?
> Webrev: http://cr.openjdk.java.net/~jcbeyler/8210562/webrev.00/
> Bug: https://bugs.openjdk.java.net/browse/JDK-8210562
> It changed the log tag "ref" to "oops" in oopStorage.cpp, and improved and increased verbosity level. I find that "ref" is mainly used for logging about processing java.lang.ref.Reference, but oopStorage is for JNI handles. Currently "oops" tag seems unused in HotSpot.
> The change uses debug level for messages about OopStorage::Block and unusual events, and trace level for the common alloc/release of individual oops.
> Below are some test results in terms of lines of logging messages:
> With varying levels of verbosity for oopstorage*:
> $ java -Xlog:oopstorage*=<level> -Xms500m -Xmx500m -jar dacapo-9.12-bach.jar tradesoap
> info debug trace
> without patch 107934 112990 112701
> with patch 0 5425 112805
> For -Xlog:ref*=debug:
> $ java -Xlog:ref*=debug -Xms500m -Xmx500m -jar dacapo-9.12-bach.jar tradesoap
> jdk10 1008
> tip without patch 108394
> tip with patch 1054
> Alternative is to advise users to change PrintReferenceGC and -Xlog:ref*=debug to -Xlog:gc+ref*=debug, as Kim suggested in https://bugs.openjdk.java.net/browse/JDK-8210562. However, that possibly involves changing the official flag mapping documentation in JDK9 and JDK10, and imposes extra work on users who have migrated old print flags to new UL flags from JDK8 to JDK9/JDK10 according to the official doc.
As I noted in the bug, I think the problem here is the documented translation from the old
-XX:+PrintReferenceGC to using UL. Rather than -Xlog:ref*=debug, it should be
-Xlog:gc+ref*=debug. And then the output is entirely reasonable.
So I don’t think this change is needed.
OopStorage is used for a lot more than JNI handles; StringTable (weak) refs, class
holder (weak) handles, JNI (weak and string) handles, possibly more coming.
“ref” seems like a reasonable tag there. Having to choose an otherwise unused
tag to avoid problems would, to me, indicate a serious design flaw in UL. Fortunately,
I don’t think it’s that bad, just that the documented usage is wrong.
Reducing the levels for the logging in OopStorage might be reasonable, but I think
that’s a separate issue.
More information about the hotspot-gc-dev