RFR: 8273112: -Xloggc and -Xlog should override -verbose

[David Holmes]

On Mon, 30 Aug 2021 07:09:54 GMT, Xiaowei Lu <github.com+39413832+weixlu at openjdk.org> wrote:

> According to java 16 specifications for java command (https://docs.oracle.com/en/java/javase/16/docs/specs/man/java.html), the command line option -Xloggc should override -verbose:gc if both options are given with the same java command. However, gc information still outputs to console even if gc log file is specified.
> 
> $java -Xloggc:gc.log -verbose:gc -version
> [0.000s][warning][gc] -Xloggc is deprecated. Will use -Xlog:gc:gc.log instead.
> [0.003s][info ][gc] Using G1
> $cat gc.log
> [0.003s][info][gc] Using G1
> 
> In addition, since -Xloggc:filename is replaced by -Xlog:gc:filename, can we assume that -Xlog:gc:filename should override -verbose:gc as -Xloggc:filename? Currently, gclog still outputs to both stdout and file if -Xlog and -verbose are given with the same java command.
> 
> $java -Xlog:gc:gc.log -verbose:gc -version
> [0.003s][info][gc] Using G1
> $cat gc.log
> [0.003s][info][gc] Using G1
> 
> As a result, we propose to put off the log configuration of -verbose option until we are confident that there isn’t -Xloggc or -Xlog options.

Before UL `-verbose:gc` simply set `PrintGC=true`. If you specified `-Xloggc:<file>` then it also set `PrintGC=true` and `PrintGCTimestamps=true`. So to describe this as "overriding" is misleading in the extreme - it simply changed the output destination and added a timestamp. It also made no difference what order the flags were specified in, or even if they were passed mutiple times.

With UL `-verbose:gc` enables logging of "gc" at "Info" level to stdout. However `-Xloggc:<file>` sets `_gc_log_filename` which in turns causes logging at either the "gc" or "gc*" levels depending on `PrintGCDetails`. That logging is at the default level - which is Info. So as far as I can see, we are doing the right thing in terms of preserving the pre-UL relationship between `-verbose:gc` and `-Xloggc:<file>` - except that with UL ordering does matter and that is where we have lost the "override" so to speak.

So as far as I can see the only thing we need to fix here is to track the use of both legacy flags, and to hold back on the actual UL configuration until processing of the command-line is complete. That also avoids the need of scanning the entire command-line. This isn't completely trivial to track but I'd be using a simple struct/class as follows:

struct LegacyGCLogging {
  char* tags;  // "gc" or "gc*"
  char* file; // NULL ->stdout
  int lastFlag; // -1 not set; 0 -> -verbose:gc; 1 -> -Xloggc
  }
If lastFlag was 1 and we encounter -verbose:gc then we do nothing - ensuring the override. Then at the end of argument processing we see what has been set and use that to configure GC logging.

This has the side-effect of ignoring some explicit `-Xlog:gc` arguments, but that is okay in my view because we are simply treating the legacy flags as-if they appeared last on the command-line and where converted to -Xlog in place.

Cheers,
David

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

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