RFR: 8267517: async logging for stdout and stderr [v4]
Xin Liu
xliu at openjdk.java.net
Tue Dec 21 21:51:48 UTC 2021
> This patch refactors LogFileStreamOutput so stdout/stderr can support support -Xlog:async.
>
> With `-Xlog:all=trace:stdout`, the helloworld in Java outputs 16520 log entries to stdout. We are see that the wall time reduces from 84.138ms to 72.914ms, or the throughput increases 15% because of async logging.
>
>
> $perf stat -r 300 ./build/linux-x86_64-server-release/images/jdk/bin/java -Xlog:all=trace:stdout -Xlog:async -XX:AsyncLogBufferSize=48M HelloWorld > /dev/null
>
> Performance counter stats for './build/linux-x86_64-server-release/images/jdk/bin/java -Xlog:all=trace:stdout -Xlog:async -XX:AsyncLogBufferSize=48M HelloWorld' (300 runs):
>
> 107.21 msec task-clock # 1.470 CPUs utilized ( +- 0.17% )
> 2,681 context-switches # 0.025 M/sec ( +- 0.32% )
> 1 cpu-migrations # 0.011 K/sec ( +- 4.56% )
> 4,006 page-faults # 0.037 M/sec ( +- 0.01% )
> ...
> 0.072914 +- 0.000126 seconds time elapsed ( +- 0.17% )
>
> Performance counter stats for './build/linux-x86_64-server-release/images/jdk/bin/java -Xlog:all=trace:stdout -XX:AsyncLogBufferSize=48M HelloWorld' (300 runs):
>
> 88.04 msec task-clock # 1.046 CPUs utilized ( +- 0.10% )
> 310 context-switches # 0.004 M/sec ( +- 0.31% )
> 1 cpu-migrations # 0.008 K/sec ( +- 5.07% )
> 4,004 page-faults # 0.045 M/sec ( +- 0.01% )
> ...
> 0.084138 +- 0.000111 seconds time elapsed ( +- 0.13% )
>
>
> The easiest test of stdout with AsyncLogging is to use tty and XOFF Ctrl^s. Java applications with UL to stdout were blocked by Ctrl-s. The entire java process will be frozen. -Xlog:async now cover both stdout and stderr. It can circumvent this issue.
>
> Add a new jtreg to cover a scenario that unified logging with -Xlog:async will not be frozen even when stdout is blocked.
Xin Liu has updated the pull request incrementally with one additional commit since the last revision:
Sideline BlockedLoggingTest.java
-------------
Changes:
- all: https://git.openjdk.java.net/jdk/pull/6132/files
- new: https://git.openjdk.java.net/jdk/pull/6132/files/396f7cd1..769110a2
Webrevs:
- full: https://webrevs.openjdk.java.net/?repo=jdk&pr=6132&range=03
- incr: https://webrevs.openjdk.java.net/?repo=jdk&pr=6132&range=02-03
Stats: 4 lines in 3 files changed: 2 ins; 0 del; 2 mod
Patch: https://git.openjdk.java.net/jdk/pull/6132.diff
Fetch: git fetch https://git.openjdk.java.net/jdk pull/6132/head:pull/6132
PR: https://git.openjdk.java.net/jdk/pull/6132
More information about the hotspot-runtime-dev
mailing list