stan/jdk-24
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

8303682: Simplify HttpClient DebugLogger

Browse Source 
Reviewed-by: jpai
This commit is contained in:
Daniel Fuchs 2023-03-08 13:52:52 +00:00
parent 8eaf84f094
commit 56512cfe1f
10 changed files with 606 additions and 227 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

6
src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java
View File

@ -116,11 +116,11 @@ import static jdk.internal.net.http.frame.SettingsFrame.*;
*/
class Http2Connection {
final Logger debug = Utils.getDebugLogger(this::dbgString, Utils.DEBUG);
final Logger debug = Utils.getDebugLogger(this::dbgString);
static final Logger DEBUG_LOGGER =
Utils.getDebugLogger("Http2Connection"::toString, Utils.DEBUG);
Utils.getDebugLogger("Http2Connection"::toString);
private final Logger debugHpack =
Utils.getHpackLogger(this::dbgString, Utils.DEBUG_HPACK);
Utils.getHpackLogger(this::dbgString);
static final ByteBuffer EMPTY_TRIGGER = ByteBuffer.allocate(0);
private static final int MAX_CLIENT_STREAM_ID = Integer.MAX_VALUE; // 2147483647

4
src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2018, 2020, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2018, 2023, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -74,7 +74,7 @@ public class RawChannelTube implements RawChannel {
this.writePublisher = new WritePublisher();
this.readSubscriber = new ReadSubscriber();
dbgTag = "[WebSocket] RawChannelTube(" + tube +")";
debug = Utils.getWebSocketLogger(dbgTag::toString, Utils.DEBUG_WS);
debug = Utils.getWebSocketLogger(dbgTag::toString);
connection.client().webSocketOpen();
connectFlows();
if (Utils.ASSERTIONSENABLED && Utils.DEBUG_WS) {

192
src/java.net.http/share/classes/jdk/internal/net/http/common/DebugLogger.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2015, 2018, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2015, 2023, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -41,10 +41,85 @@ import java.util.function.Supplier;
* format string. MessageFormat-like formatting is enabled by the presence of
* "{0" or "{1".
*
* <p> See {@link Utils#getDebugLogger(Supplier, boolean)} and
* {@link Utils#getHpackLogger(Supplier, boolean)}.
* <p> See {@link Utils#getDebugLogger(Supplier)} and
* {@link Utils#getHpackLogger(Supplier)}.
*/
final class DebugLogger implements Logger {
/**
* A DebugLogger configuration is composed of three levels.
* The three levels can be configured independently, but are
* typically either Level.ALL or Level.OFF.
*
* @param outLevel the level at or above which messages will be directly
* printed to {@link System#out}
* @param errLevel the level at or above which messages will be directly
* printed to {@link System#err}
* @param logLevel the level at or above which messages will be forwarded
* to an underlying {@link System.Logger}
*/
public record LoggerConfig(Level outLevel, Level errLevel, Level logLevel) {
public LoggerConfig {
Objects.requireNonNull(outLevel);
Objects.requireNonNull(errLevel);
Objects.requireNonNull(logLevel);
}
// true if at least one of the three levels is not Level.OFF
public boolean on() {
return minSeverity() < Level.OFF.getSeverity();
}
// The minimal severity of the three level. Messages below
// that severity will not be logged anywhere.
public int minSeverity() {
return Math.min(outLevel.getSeverity(),
Math.min(errLevel.getSeverity(), logLevel.getSeverity()));
}
// Whether the given level can be logged with the given logger
public boolean levelEnabledFor(Level level, System.Logger logger) {
if (level == Level.OFF) return false;
int severity = level.getSeverity();
if (severity >= errLevel.getSeverity()) return true;
if (severity >= outLevel.getSeverity()) return true;
if (severity >= logLevel.getSeverity()) return logger.isLoggable(level);
return false;
}
// The same configuration, but with the given {@link #errLevel}
public LoggerConfig withErrLevel(Level errLevel) {
return new LoggerConfig(outLevel, errLevel, logLevel);
}
// The same configuration, but with the given {@link #outLevel}
public LoggerConfig withOutLevel(Level outLevel) {
return new LoggerConfig(outLevel, errLevel, logLevel);
}
// The same configuration, but with the given {@link #logLevel}
public LoggerConfig withLogLevel(Level logLevel) {
return new LoggerConfig(outLevel, errLevel, logLevel);
}
/** Logs on {@link System#err} only, does not forward to System.Logger **/
public static final LoggerConfig STDERR = new LoggerConfig(Level.OFF, Level.ALL, Level.OFF);
/** Logs on {@link System#out} only, does not forward to System.Logger **/
public static final LoggerConfig STDOUT = new LoggerConfig(Level.ALL, Level.OFF, Level.OFF);
/** Forward to System.Logger, doesn't log directly to System.out or System.err **/
public static final LoggerConfig LOG = new LoggerConfig(Level.OFF, Level.OFF, Level.ALL);
/** does not log anywhere **/
public static final LoggerConfig OFF = new LoggerConfig(Level.OFF, Level.OFF, Level.OFF);
/** logs on both System.err and System.Logger **/
public static final LoggerConfig ERRLOG = new LoggerConfig(Level.OFF, Level.ALL, Level.ALL);
public static LoggerConfig of(LoggerConfig config) {
if (config.equals(OFF)) return OFF;
if (config.equals(ERRLOG)) return ERRLOG;
if (config.equals(STDERR)) return STDERR;
if (config.equals(STDOUT)) return STDOUT;
if (config.equals(LOG)) return LOG;
return config;
}
};
// deliberately not in the same subtree than standard loggers.
static final String HTTP_NAME = "jdk.internal.httpclient.debug";
static final String WS_NAME = "jdk.internal.httpclient.websocket.debug";
@ -53,16 +128,16 @@ final class DebugLogger implements Logger {
static final System.Logger WS = System.getLogger(WS_NAME);
static final System.Logger HPACK = System.getLogger(HPACK_NAME);
private static final DebugLogger NO_HTTP_LOGGER =
new DebugLogger(HTTP, "HTTP"::toString, Level.OFF, Level.OFF);
new DebugLogger(HTTP, "HTTP"::toString, LoggerConfig.OFF);
private static final DebugLogger NO_WS_LOGGER =
new DebugLogger(HTTP, "WS"::toString, Level.OFF, Level.OFF);
new DebugLogger(WS, "WS"::toString, LoggerConfig.OFF);
private static final DebugLogger NO_HPACK_LOGGER =
new DebugLogger(HTTP, "HPACK"::toString, Level.OFF, Level.OFF);
new DebugLogger(HPACK, "HPACK"::toString, LoggerConfig.OFF);
static final long START_NANOS = System.nanoTime();
private final Supplier<String> dbgTag;
private final Level errLevel;
private final Level outLevel;
private final LoggerConfig config;
private final int minSeverity;
private final System.Logger logger;
private final boolean debugOn;
private final boolean traceOn;
@ -70,43 +145,48 @@ final class DebugLogger implements Logger {
/**
* Create a logger for debug traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
*
* By default, this logger will forward all messages logged to the supplied
* {@code logger}.
* But in addition, if the message severity level is {@code >=} to
* the provided {@code errLevel} it will print the messages on System.err,
* and if the message severity level is {@code >=} to
* the provided {@code outLevel} it will also print the messages on System.out.
* <p>
* By default, this logger will print message whose severity is
* above the severity configured in the logger {@code config}
* <ul>
* <li>If {@code config.outLevel()} is not Level.OFF, messages
* whose severity are at or above that severity will be directly
* printed on System.out</li>
* <li>If {@code config.errLevel()} is not Level.OFF, messages
* whose severity are at or above that severity will be directly
* printed on System.err</li>
* <li>If {@code config.logLevel()} is not Level.OFF, messages
* whose severity are at or above that severity will be forwarded
* to the supplied {@code logger}.</li>
* </ul>
* <p>
* The logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code new DebugLogger(logger, this::dbgTag, Level.OFF, Level.ALL);}.
* {@code new DebugLogger(logger, this::dbgTag,
* LoggerConfig.LOG.withErrLevel(Level.ALL));}.
* To obtain a logger that will only forward to the internal logger,
* use {@code new DebugLogger(logger, this::dbgTag, Level.OFF, Level.OFF);}.
* use {@code new DebugLogger(logger, this::dbgTag, LoggerConfig.LOG);}.
*
* @param logger The internal logger to which messages will be forwarded.
* This should be either {@link #HPACK} or {@link #HTTP};
* This is typically either {@link #WS}, {@link #HPACK}, or {@link #HTTP};
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "SocketTube(3)", or "Http2Connection(SocketTube(3))")
* @param outLevel The level above which messages will be also printed on
* System.out (in addition to being forwarded to the internal logger).
* @param errLevel The level above which messages will be also printed on
* System.err (in addition to being forwarded to the internal logger).
* @param config The levels at or above which messages will be printed to the
* corresponding destination.
*
* @return A logger for HTTP internal debug traces
*/
private DebugLogger(System.Logger logger,
Supplier<String> dbgTag,
Level outLevel,
Level errLevel) {
LoggerConfig config) {
this.dbgTag = dbgTag;
this.errLevel = errLevel;
this.outLevel = outLevel;
this.config = LoggerConfig.of(Objects.requireNonNull(config));
this.logger = Objects.requireNonNull(logger);
this.minSeverity = config.minSeverity();
// support only static configuration.
this.debugOn = isEnabled(Level.DEBUG);
this.traceOn = isEnabled(Level.TRACE);
@ -118,7 +198,9 @@ final class DebugLogger implements Logger {
}
private boolean isEnabled(Level level) {
return levelEnabledFor(level, outLevel, errLevel, logger);
int severity = level.getSeverity();
if (severity < minSeverity) return false;
return levelEnabledFor(level, config, logger);
}
@Override
@ -126,13 +208,9 @@ final class DebugLogger implements Logger {
return debugOn;
}
static boolean levelEnabledFor(Level level, Level outLevel, Level errLevel,
System.Logger logger) {
if (level == Level.OFF) return false;
int severity = level.getSeverity();
return severity >= errLevel.getSeverity()
|| severity >= outLevel.getSeverity()
|| logger.isLoggable(level);
private static boolean levelEnabledFor(Level level, LoggerConfig config,
System.Logger logger) {
return config.levelEnabledFor(level, logger);
}
@Override
@ -151,17 +229,23 @@ final class DebugLogger implements Logger {
// support only static configuration.
if (level == Level.DEBUG && !debugOn) return;
if (level == Level.TRACE && !traceOn) return;
int severity = level.getSeverity();
if (severity < minSeverity) return;
var errLevel = config.errLevel();
if (errLevel != Level.OFF
&& errLevel.getSeverity() <= severity) {
print(System.err, level, format, params, null);
}
var outLevel = config.outLevel();
if (outLevel != Level.OFF
&& outLevel.getSeverity() <= severity) {
print(System.out, level, format, params, null);
}
if (logger.isLoggable(level)) {
var logLevel = config.logLevel();
if (logLevel != Level.OFF
&& logLevel.getSeverity() <= severity
&& logger.isLoggable(level)) {
logger.log(level, unused,
getFormat(new StringBuilder(), format, params).toString(),
params);
@ -174,16 +258,23 @@ final class DebugLogger implements Logger {
// fast path, we assume these guys never change.
if (level == Level.DEBUG && !debugOn) return;
if (level == Level.TRACE && !traceOn) return;
int severity = level.getSeverity();
if (severity < minSeverity) return;
var errLevel = config.errLevel();
if (errLevel != Level.OFF
&& errLevel.getSeverity() <= level.getSeverity()) {
&& errLevel.getSeverity() <= severity) {
print(System.err, level, msg, null, thrown);
}
var outLevel = config.outLevel();
if (outLevel != Level.OFF
&& outLevel.getSeverity() <= level.getSeverity()) {
&& outLevel.getSeverity() <= severity) {
print(System.out, level, msg, null, thrown);
}
if (logger.isLoggable(level)) {
var logLevel = config.logLevel();
if (logLevel != Level.OFF
&& logLevel.getSeverity() <= severity
&& logger.isLoggable(level)) {
logger.log(level, unused,
getFormat(new StringBuilder(), msg, null).toString(),
thrown);
@ -226,7 +317,6 @@ final class DebugLogger implements Logger {
return sb;
}
private StringBuilder getFormat(StringBuilder sb, String format, Object[] params) {
if (format == null || params == null || params.length == 0) {
return decorate(sb, format);
@ -260,10 +350,9 @@ final class DebugLogger implements Logger {
}
public static DebugLogger createHttpLogger(Supplier<String> dbgTag,
Level outLevel,
Level errLevel) {
if (levelEnabledFor(Level.DEBUG, outLevel, errLevel, HTTP)) {
return new DebugLogger(HTTP, dbgTag, outLevel, errLevel);
LoggerConfig config) {
if (levelEnabledFor(Level.DEBUG, config, HTTP)) {
return new DebugLogger(HTTP, dbgTag, config);
} else {
// return a shared instance if debug logging is not enabled.
return NO_HTTP_LOGGER;
@ -271,21 +360,18 @@ final class DebugLogger implements Logger {
}
public static DebugLogger createWebSocketLogger(Supplier<String> dbgTag,
Level outLevel,
Level errLevel) {
if (levelEnabledFor(Level.DEBUG, outLevel, errLevel, WS)) {
return new DebugLogger(WS, dbgTag, outLevel, errLevel);
LoggerConfig config) {
if (levelEnabledFor(Level.DEBUG, config, WS)) {
return new DebugLogger(WS, dbgTag, config);
} else {
// return a shared instance if logging is not enabled.
return NO_WS_LOGGER;
}
}
public static DebugLogger createHpackLogger(Supplier<String> dbgTag,
Level outLevel,
Level errLevel) {
if (levelEnabledFor(Level.DEBUG, outLevel, errLevel, HPACK)) {
return new DebugLogger(HPACK, dbgTag, outLevel, errLevel);
public static DebugLogger createHpackLogger(Supplier<String> dbgTag, LoggerConfig config) {
if (levelEnabledFor(Level.DEBUG, config, HPACK)) {
return new DebugLogger(HPACK, dbgTag, config);
} else {
// return a shared instance if logging is not enabled.
return NO_HPACK_LOGGER;

8
src/java.net.http/share/classes/jdk/internal/net/http/common/Logger.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2018, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2018, 2023, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -40,9 +40,9 @@ import java.util.function.Supplier;
*
* @implSpec
* This interface is implemented by loggers returned by
* {@link Utils#getDebugLogger(Supplier, boolean)},
* {@link Utils#getWebSocketLogger(Supplier, boolean)}and
* {@link Utils#getHpackLogger(Supplier, boolean)}.
* {@link Utils#getDebugLogger(Supplier)},
* {@link Utils#getWebSocketLogger(Supplier)} and
* {@link Utils#getHpackLogger(Supplier)}.
* It is not designed to be implemented by any other
* loggers. Do not use outside of this module.
*/

282
src/java.net.http/share/classes/jdk/internal/net/http/common/Utils.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2015, 2022, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2015, 2023, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -25,10 +25,6 @@
package jdk.internal.net.http.common;
import sun.net.NetProperties;
import sun.net.util.IPAddressUtil;
import sun.net.www.HeaderParser;
import javax.net.ssl.ExtendedSSLSession;
import javax.net.ssl.SSLException;
import javax.net.ssl.SSLHandshakeException;
@ -73,10 +69,16 @@ import java.util.function.Supplier;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import jdk.internal.net.http.common.DebugLogger.LoggerConfig;
import jdk.internal.net.http.HttpRequestImpl;
import sun.net.NetProperties;
import sun.net.util.IPAddressUtil;
import sun.net.www.HeaderParser;
import static java.lang.String.format;
import static java.nio.charset.StandardCharsets.US_ASCII;
import static java.util.stream.Collectors.joining;
import jdk.internal.net.http.HttpRequestImpl;
/**
* Miscellaneous utilities
@ -98,17 +100,55 @@ public final class Utils {
// TESTING = AccessController.doPrivileged(action) != null;
// } else TESTING = false;
// }
public static final boolean DEBUG = // Revisit: temporary dev flag.
getBooleanProperty(DebugLogger.HTTP_NAME, false);
public static final boolean DEBUG_WS = // Revisit: temporary dev flag.
getBooleanProperty(DebugLogger.WS_NAME, false);
public static final boolean DEBUG_HPACK = // Revisit: temporary dev flag.
getBooleanProperty(DebugLogger.HPACK_NAME, false);
public static final LoggerConfig DEBUG_CONFIG =
getLoggerConfig(DebugLogger.HTTP_NAME, LoggerConfig.OFF);
public static final LoggerConfig DEBUG_WS_CONFIG =
getLoggerConfig(DebugLogger.WS_NAME, LoggerConfig.OFF);
public static final LoggerConfig DEBUG_HPACK_CONFIG =
getLoggerConfig(DebugLogger.HPACK_NAME, LoggerConfig.OFF);
public static final boolean DEBUG = DEBUG_CONFIG.on(); // Revisit: temporary dev flag.
public static final boolean DEBUG_WS = DEBUG_WS_CONFIG.on(); // Revisit: temporary dev flag.
public static final boolean TESTING = DEBUG;
public static final boolean isHostnameVerificationDisabled = // enabled by default
hostnameVerificationDisabledValue();
private static LoggerConfig getLoggerConfig(String loggerName, LoggerConfig def) {
PrivilegedAction<String> action = () -> System.getProperty(loggerName);
@SuppressWarnings("removal")
var prop = AccessController.doPrivileged(action);
if (prop == null) return def;
var config = LoggerConfig.OFF;
for (var s : prop.split(",")) {
s = s.trim();
if (s.isEmpty()) continue;
int len = s.length();
switch (len) {
case 3 -> {
if (s.regionMatches(true, 0, "err", 0, 3)) {
config = config.withErrLevel(Level.ALL);
continue;
}
if (s.regionMatches(true, 0, "out", 0, 3)) {
config = config.withOutLevel(Level.ALL);
continue;
}
if (s.regionMatches(true, 0, "log", 0, 3)) {
config = config.withLogLevel(Level.ALL);
}
}
case 4 -> {
if (s.regionMatches(true, 0, "true", 0, 4)) {
config = config.withErrLevel(Level.ALL).withLogLevel(Level.ALL);
}
}
default -> { continue; }
}
}
return config;
}
private static boolean hostnameVerificationDisabledValue() {
String prop = getProperty("jdk.internal.httpclient.disableHostnameVerification");
if (prop == null)
@ -773,13 +813,24 @@ public final class Utils {
/**
* Get a logger for debug HTTP traces.
*
* <p>
* The logger should only be used with levels whose severity is
* {@code <= DEBUG}. By default, this logger will forward all messages
* logged to an internal logger named "jdk.internal.httpclient.debug".
* In addition, if the property -Djdk.internal.httpclient.debug=true is set,
* it will print the messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* {@code <= DEBUG}.
* <p>
* The output of this logger is controlled by the system property
* -Djdk.internal.httpclient.debug. The value of the property is
* a comma separated list of tokens. The following tokens are
* recognized:
* <ul>
* <li> err: the messages will be logged on System.err</li>
* <li> out: the messages will be logged on System.out</li>
* <li> log: the messages will be forwarded to an internal
* System.Logger named "jdk.internal.httpclient.debug"</li>
* <li> true: this is equivalent to "err,log": the messages will be logged
* both on System.err, and forwarded to the internal logger.</li>
* </ul>
*
* This logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @param dbgTag A lambda that returns a string that identifies the caller
@ -788,72 +839,26 @@ public final class Utils {
* @return A logger for HTTP internal debug traces
*/
public static Logger getDebugLogger(Supplier<String> dbgTag) {
return getDebugLogger(dbgTag, DEBUG);
return DebugLogger.createHttpLogger(dbgTag, DEBUG_CONFIG);
}
/**
* Get a logger for debug HTTP traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
*
* By default, this logger will forward all messages logged to an internal
* logger named "jdk.internal.httpclient.debug".
* In addition, if the message severity level is >= to
* the provided {@code errLevel} it will print the messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code getDebugLogger(this::dbgTag, Level.ALL);}.
* This is also equivalent to calling
* {@code getDebugLogger(this::dbgTag, true);}.
* To obtain a logger that will only forward to the internal logger,
* use {@code getDebugLogger(this::dbgTag, Level.OFF);}.
* This is also equivalent to calling
* {@code getDebugLogger(this::dbgTag, false);}.
* If {@code on} is false, returns a logger that doesn't log anything.
* Otherwise, returns a logger equivalent to {@link #getDebugLogger(Supplier)}.
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "SocketTube(3)", or "Http2Connection(SocketTube(3))")
* @param errLevel The level above which messages will be also printed on
* stderr (in addition to be forwarded to the internal logger).
*
* @return A logger for HTTP internal debug traces
*/
static Logger getDebugLogger(Supplier<String> dbgTag, Level errLevel) {
return DebugLogger.createHttpLogger(dbgTag, Level.OFF, errLevel);
}
/**
* Get a logger for debug HTTP traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
*
* By default, this logger will forward all messages logged to an internal
* logger named "jdk.internal.httpclient.debug".
* In addition, the provided boolean {@code on==true}, it will print the
* messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code getDebugLogger(this::dbgTag, true);}.
* This is also equivalent to calling
* {@code getDebugLogger(this::dbgTag, Level.ALL);}.
* To obtain a logger that will only forward to the internal logger,
* use {@code getDebugLogger(this::dbgTag, false);}.
* This is also equivalent to calling
* {@code getDebugLogger(this::dbgTag, Level.OFF);}.
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "SocketTube(3)", or "Http2Connection(SocketTube(3))")
* @param on Whether messages should also be printed on
* stderr (in addition to be forwarded to the internal logger).
* @param on Whether the logger is enabled.
*
* @return A logger for HTTP internal debug traces
*/
public static Logger getDebugLogger(Supplier<String> dbgTag, boolean on) {
Level errLevel = on ? Level.ALL : Level.OFF;
return getDebugLogger(dbgTag, errLevel);
LoggerConfig config = on ? DEBUG_CONFIG : LoggerConfig.OFF;
return DebugLogger.createHttpLogger(dbgTag, config);
}
/**
@ -887,22 +892,12 @@ public final class Utils {
* Get a logger for debug HPACK traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
*
* By default, this logger will forward all messages logged to an internal
* logger named "jdk.internal.httpclient.hpack.debug".
* In addition, if the message severity level is >= to
* the provided {@code errLevel} it will print the messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code getHpackLogger(this::dbgTag, Level.ALL);}.
* This is also equivalent to calling
* {@code getHpackLogger(this::dbgTag, true);}.
* To obtain a logger that will only forward to the internal logger,
* use {@code getHpackLogger(this::dbgTag, Level.OFF);}.
* This is also equivalent to calling
* {@code getHpackLogger(this::dbgTag, false);}.
* By default, this logger has a configuration equivalent to that
* returned by {@link #getHpackLogger(Supplier)}. This original
* configuration is amended by the provided {@code errLevel} in
* the following way: if the message severity level is >= to
* the provided {@code errLevel} the message will additionally
* be printed on stderr.
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "Http2Connection(SocketTube(3))/hpack.Decoder(3)")
@ -912,107 +907,72 @@ public final class Utils {
* @return A logger for HPACK internal debug traces
*/
public static Logger getHpackLogger(Supplier<String> dbgTag, Level errLevel) {
Level outLevel = Level.OFF;
return DebugLogger.createHpackLogger(dbgTag, outLevel, errLevel);
return DebugLogger.createHpackLogger(dbgTag, DEBUG_HPACK_CONFIG.withErrLevel(errLevel));
}
/**
* Get a logger for debug HPACK traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
*
* By default, this logger will forward all messages logged to an internal
* logger named "jdk.internal.httpclient.hpack.debug".
* In addition, the provided boolean {@code on==true}, it will print the
* messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
* The logger should only be used with levels whose severity is
* {@code <= DEBUG}.
* <p>
* The output of this logger is controlled by the system property
* -Djdk.internal.httpclient.hpack.debug. The value of the property is
* a comma separated list of tokens. The following tokens are
* recognized:
* <ul>
* <li> err: the messages will be logged on System.err</li>
* <li> out: the messages will be logged on System.out</li>
* <li> log: the messages will be forwarded to an internal
* System.Logger named "jdk.internal.httpclient.hpack.debug"</li>
* <li> true: this is equivalent to "err,log": the messages will be logged
* both on System.err, and forwarded to the internal logger.</li>
* </ul>
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code getHpackLogger(this::dbgTag, true);}.
* This is also equivalent to calling
* {@code getHpackLogger(this::dbgTag, Level.ALL);}.
* To obtain a logger that will only forward to the internal logger,
* use {@code getHpackLogger(this::dbgTag, false);}.
* This is also equivalent to calling
* {@code getHpackLogger(this::dbgTag, Level.OFF);}.
* This logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "Http2Connection(SocketTube(3))/hpack.Decoder(3)")
* @param on Whether messages should also be printed on
* stderr (in addition to be forwarded to the internal logger).
*
* @return A logger for HPACK internal debug traces
*/
public static Logger getHpackLogger(Supplier<String> dbgTag, boolean on) {
Level errLevel = on ? Level.ALL : Level.OFF;
return getHpackLogger(dbgTag, errLevel);
public static Logger getHpackLogger(Supplier<String> dbgTag) {
return DebugLogger.createHpackLogger(dbgTag, DEBUG_HPACK_CONFIG);
}
/**
* Get a logger for debug WebSocket traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
* <p>
* The logger should only be used with levels whose severity is
* {@code <= DEBUG}.
* <p>
* The output of this logger is controlled by the system property
* -Djdk.internal.httpclient.websocket.debug. The value of the property is
* a comma separated list of tokens. The following tokens are
* recognized:
* <ul>
* <li> err: the messages will be logged on System.err</li>
* <li> out: the messages will be logged on System.out</li>
* <li> log: the messages will be forwarded to an internal
* System.Logger named "jdk.internal.httpclient.websocket.debug"</li>
* <li> true: this is equivalent to "err,log": the messages will be logged
* both on System.err, and forwarded to the internal logger.</li>
* </ul>
*
* By default, this logger will forward all messages logged to an internal
* logger named "jdk.internal.httpclient.websocket.debug".
* In addition, if the message severity level is >= to
* the provided {@code errLevel} it will print the messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* This logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code getWebSocketLogger(this::dbgTag, Level.ALL);}.
* This is also equivalent to calling
* {@code getWSLogger(this::dbgTag, true);}.
* To obtain a logger that will only forward to the internal logger,
* use {@code getWebSocketLogger(this::dbgTag, Level.OFF);}.
* This is also equivalent to calling
* {@code getWSLogger(this::dbgTag, false);}.
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "WebSocket(3)")
* @param errLevel The level above which messages will be also printed on
* stderr (in addition to be forwarded to the internal logger).
*
* @return A logger for HPACK internal debug traces
*/
public static Logger getWebSocketLogger(Supplier<String> dbgTag, Level errLevel) {
Level outLevel = Level.OFF;
return DebugLogger.createWebSocketLogger(dbgTag, outLevel, errLevel);
}
/**
* Get a logger for debug WebSocket traces.The logger should only be used
* with levels whose severity is {@code <= DEBUG}.
*
* By default, this logger will forward all messages logged to an internal
* logger named "jdk.internal.httpclient.websocket.debug".
* In addition, the provided boolean {@code on==true}, it will print the
* messages on stderr.
* The logger will add some decoration to the printed message, in the form of
* {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}
*
* @apiNote To obtain a logger that will always print things on stderr in
* addition to forwarding to the internal logger, use
* {@code getWebSocketLogger(this::dbgTag, true);}.
* This is also equivalent to calling
* {@code getWebSocketLogger(this::dbgTag, Level.ALL);}.
* To obtain a logger that will only forward to the internal logger,
* use {@code getWebSocketLogger(this::dbgTag, false);}.
* This is also equivalent to calling
* {@code getHpackLogger(this::dbgTag, Level.OFF);}.
*
* @param dbgTag A lambda that returns a string that identifies the caller
* (e.g: "WebSocket(3)")
* @param on Whether messages should also be printed on
* stderr (in addition to be forwarded to the internal logger).
*
* @return A logger for WebSocket internal debug traces
*/
public static Logger getWebSocketLogger(Supplier<String> dbgTag, boolean on) {
Level errLevel = on ? Level.ALL : Level.OFF;
return getWebSocketLogger(dbgTag, errLevel);
public static Logger getWebSocketLogger(Supplier<String> dbgTag) {
return DebugLogger.createWebSocketLogger(dbgTag, DEBUG_WS_CONFIG);
}
/**

2
src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageDecoder.java
View File

@ -51,7 +51,7 @@ import static jdk.internal.net.http.websocket.StatusCodes.isLegalToReceiveFromSe
class MessageDecoder implements Frame.Consumer {
private static final Logger debug =
Utils.getWebSocketLogger("[Input]"::toString, Utils.DEBUG_WS);
Utils.getWebSocketLogger("[Input]"::toString);
private final MessageStreamConsumer output;
private final UTF8AccumulatingDecoder decoder = new UTF8AccumulatingDecoder();

2
src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageEncoder.java
View File

@ -50,7 +50,7 @@ import java.security.SecureRandom;
public class MessageEncoder {
private static final Logger debug =
Utils.getWebSocketLogger("[Output]"::toString, Utils.DEBUG_WS);
Utils.getWebSocketLogger("[Output]"::toString);
private final SecureRandom maskingKeySource = new SecureRandom();
private final Frame.HeaderWriter headerWriter = new Frame.HeaderWriter();

2
src/java.net.http/share/classes/jdk/internal/net/http/websocket/TransportImpl.java
View File

@ -53,7 +53,7 @@ public class TransportImpl implements Transport {
// -- Debugging infrastructure --
private static final Logger debug =
Utils.getWebSocketLogger("[Transport]"::toString, Utils.DEBUG_WS);
Utils.getWebSocketLogger("[Transport]"::toString);
/* Used for correlating enters to and exists from a method */
private final AtomicLong counter = new AtomicLong();

2
src/java.net.http/share/classes/jdk/internal/net/http/websocket/WebSocketImpl.java
View File

@ -77,7 +77,7 @@ import static jdk.internal.net.http.websocket.WebSocketImpl.State.WAITING;
public final class WebSocketImpl implements WebSocket {
private static final Logger debug =
Utils.getWebSocketLogger("[WebSocket]"::toString, Utils.DEBUG_WS);
Utils.getWebSocketLogger("[WebSocket]"::toString);
private final AtomicLong sendCounter = new AtomicLong();
private final AtomicLong receiveCounter = new AtomicLong();

333
test/jdk/java/net/httpclient/DebugLoggerTest.java Normal file
View File

@ -0,0 +1,333 @@
/*
* Copyright (c) 2023, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
* under the terms of the GNU General Public License version 2 only, as
* published by the Free Software Foundation.
*
* This code is distributed in the hope that it will be useful, but WITHOUT
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
* version 2 for more details (a copy is included in the LICENSE file that
* accompanied this code).
*
* You should have received a copy of the GNU General Public License version
* 2 along with this work; if not, write to the Free Software Foundation,
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
*
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
* or visit www.oracle.com if you need additional information or have any
* questions.
*/
import java.io.ByteArrayOutputStream;
import java.io.OutputStream;
import java.io.PrintStream;
import java.lang.ref.Reference;
import java.nio.charset.Charset;
import java.util.Arrays;
import java.util.EnumSet;
import java.util.HashSet;
import java.util.List;
import java.util.Locale;
import java.util.Objects;
import java.util.Set;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.function.Predicate;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import jdk.internal.net.http.common.Utils;
import static java.nio.charset.StandardCharsets.UTF_8;
/*
* @test
* @summary Verify the behaviour of the debug logger.
* @library /test/lib /test/jdk/java/net/httpclient/lib
* @build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext
* DebugLoggerTest
* @run main/othervm DebugLoggerTest
* @run main/othervm -Djdk.internal.httpclient.debug=errr DebugLoggerTest
* @run main/othervm -Djdk.internal.httpclient.debug=err DebugLoggerTest ERR
* @run main/othervm -Djdk.internal.httpclient.debug=out DebugLoggerTest OUT
* @run main/othervm -Djdk.internal.httpclient.debug=log DebugLoggerTest LOG
* @run main/othervm -Djdk.internal.httpclient.debug=true DebugLoggerTest ERR LOG
* @run main/othervm -Djdk.internal.httpclient.debug=err,OUT DebugLoggerTest ERR OUT
* @run main/othervm -Djdk.internal.httpclient.debug=err,out,log DebugLoggerTest ERR OUT LOG
* @run main/othervm -Djdk.internal.httpclient.debug=true,log DebugLoggerTest ERR LOG
* @run main/othervm -Djdk.internal.httpclient.debug=true,out DebugLoggerTest ERR OUT LOG
* @run main/othervm -Djdk.internal.httpclient.debug=err,OUT,foo DebugLoggerTest ERR OUT
*/
public class DebugLoggerTest {
static final PrintStream stdErr = System.err;
static final PrintStream stdOut = System.out;
static final String LOGGER_NAME = "jdk.internal.httpclient.debug";
static final String MESSAGE = "May the luck of the Irish be with you!";
static final String MESSAGE2 = "May the wind be at your back!";
static final String MESSAGE3 = "May the sun shine warm upon your face!";
static RecordingPrintStream err = null;
static RecordingPrintStream out = null;
/**
* A {@code RecordingPrintStream} is a {@link PrintStream} that makes
* it possible to record part of the data stream in memory while still
* forwarding everything to a delegated {@link OutputStream}.
* @apiNote
* For instance, a {@code RecordingPrintStream} might be used as an
* interceptor to record anything printed on {@code System.err}
* at specific times. Recording can be started and stopped
* at any time, and multiple times. For instance, a typical
* usage might be:
* <pre>static final PrintStream stderr = System.err;
* static final RecordingPrintString recorder =
* new RecordingPrintStream(stderr, true, UTF_8);
* static {
* System.setErr(recorder);
* }
*
* ...
* // ....
* recorder.startRecording();
* try {
* // do something
* String str1 = recorder.drainRecordedData();
* // do something else
* String str2 = recorder.drainRecordedData();
* // ....
* } finally {
* recorder.stopRecording();
* }
* // ....
* ...
* </pre>
* <p>Though the methods are thread safe, {@link #startRecording()}
* {@link #stopRecording()} and {@link #drainRecordedData()} must
* not be called concurrently by different threads without external
* orchestration, as calling these methods mutate the state of
* the recorder in a way that can be globally observed by all
* threads.
*/
public static final class RecordingPrintStream extends PrintStream {
private final Charset charset;
private final ByteArrayOutputStream recordedData;
private volatile boolean recording;
/**
* Creates a new {@code RecordingPrintStream} instance that wraps
* the provided {@code OutputStream}.
* @implSpec Calls {@link PrintStream#PrintStream(
* OutputStream, boolean, Charset)}.
* @param out An {@code OutputStream} instance to which all bytes will
* be forwarded.
* @param autoFlush Whether {@linkplain PrintStream#PrintStream(
* OutputStream, boolean, Charset) autoFlush} is on.
* @param charset A {@linkplain Charset} used to transform text to
* bytes and bytes to string.
*/
public RecordingPrintStream(OutputStream out, boolean autoFlush, Charset charset) {
super(out, autoFlush, charset);
this.charset = charset;
recordedData = new ByteArrayOutputStream();
}
/**
* Flushes the stream and starts recording.
* If recording is already started, this method has no effect beyond
* {@linkplain PrintStream#flush() flushing} the stream.
*/
public void startRecording() {
flush(); // make sure everything that was printed before is flushed
synchronized (recordedData) {
recording = true;
}
}
/**
* Flushes the stream and stops recording.
* If recording is already stopped, this method has no effect beyond
* {@linkplain PrintStream#flush() flushing} the stream.
*/
public void stopRecording() {
flush(); // make sure everything that was printed before is flushed
synchronized (recordedData) {
recording = false;
}
}
/**
* Flushes the stream, drains the recorded data, convert it
* to a string, and returns it. This has the effect of
* flushing any recorded data from memory: the next call
* to {@code drainRecordedData()} will not return any data
* previously returned.
* This method can be called regardless of whether recording
* is started or stopped.
*/
public String drainRecordedData() {
flush(); // make sure everything that was printed before is flushed
synchronized (recordedData) {
String data = recordedData.toString(charset);
recordedData.reset();
return data;
}
}
@Override
public void write(int b) {
super.write(b);
if (recording) {
synchronized (recordedData) {
if (recording) recordedData.write(b);
}
}
}
@Override
public void write(byte[] buf, int off, int len) {
super.write(buf, off, len);
if (recording) {
synchronized (recordedData) {
if (recording) recordedData.write(buf, off, len);
}
}
}
}
static class TestHandler extends Handler {
final CopyOnWriteArrayList logs = new CopyOnWriteArrayList();
TestHandler() {
setLevel(Level.ALL);
}
@Override
public void publish(LogRecord record) {
logs.add(record);
}
@Override
public void flush() {
}
@Override
public void close() throws SecurityException {
}
}
enum Destination {OUT, ERR, LOG}
static Set<Destination> getDestinations(String prop) {
if (prop == null) return Set.of();
String[] values = prop.split(",");
if (values.length == 0) return Set.of();
Set<Destination> dest = HashSet.newHashSet(3);
for (var v : values) {
v = v.trim().toLowerCase(Locale.ROOT);
if ("log".equals(v)) dest.add(Destination.LOG);
if ("err".equals(v)) dest.add(Destination.ERR);
if ("out".equals(v)) dest.add(Destination.OUT);
if ("true".equals(v)) dest.addAll(EnumSet.of(Destination.ERR, Destination.LOG));
}
return Set.copyOf(dest);
}
public static void main(String[] args) {
err = new RecordingPrintStream(stdErr, true, UTF_8);
out = new RecordingPrintStream(stdOut, true, UTF_8);
System.setErr(err);
System.setOut(out);
TestHandler logHandler = new TestHandler();
Logger julLogger = Logger.getLogger(LOGGER_NAME);
julLogger.setLevel(Level.ALL);
julLogger.setUseParentHandlers(false);
julLogger.addHandler(logHandler);
System.Logger sysLogger = System.getLogger(LOGGER_NAME);
var debug = Utils.getDebugLogger(() -> "DebugLoggerTest", Utils.DEBUG);
String prop = System.getProperty(LOGGER_NAME);
stdOut.printf("DebugLoggerTest: [\"%s\", %s] start%n", prop, Arrays.asList(args));
var dest = getDestinations(prop);
var dest2 = Stream.of(args)
.map(Destination::valueOf)
.collect(Collectors.toSet());
assertEquals(debug.on(), !dest.isEmpty());
assertEquals(dest, dest2);
Predicate<LogRecord> matcher1 = (r) -> r.getMessage() != null && r.getMessage().contains(MESSAGE);
doTest(() -> debug.log(MESSAGE), debug, logHandler, dest, MESSAGE, matcher1);
Exception thrown = new Exception(MESSAGE3);
Predicate<LogRecord> matcher2 = (r) -> r.getMessage() != null
&& r.getMessage().contains(MESSAGE2)
&& thrown.equals(r.getThrown());
doTest(() -> debug.log(MESSAGE2, thrown), debug, logHandler, dest, MESSAGE2, matcher2);
stdOut.printf("Test [\"%s\", %s] passed%n", prop, Arrays.asList(args));
Reference.reachabilityFence(julLogger);
}
private static void doTest(Runnable test,
System.Logger logger,
TestHandler logHandler,
Set<Destination> dest,
String msg,
Predicate<LogRecord> logMatcher) {
logHandler.logs.clear();
err.drainRecordedData();
out.drainRecordedData();
err.startRecording();
out.startRecording();
test.run();
err.stopRecording();
out.stopRecording();
String outStr = out.drainRecordedData();
String errStr = err.drainRecordedData();
List<LogRecord> logs = logHandler.logs.stream().toList();
if (!(logger instanceof jdk.internal.net.http.common.Logger debug)) {
throw new AssertionError("Unexpected logger type for: " + logger);
}
assertEquals(debug.on(), !dest.isEmpty(), "Unexpected debug.on() for " + dest);
assertEquals(debug.isLoggable(System.Logger.Level.DEBUG), !dest.isEmpty());
if (dest.contains(Destination.ERR)) {
if (!errStr.contains(msg)) {
throw new AssertionError("stderr does not contain the expected message");
}
} else if (errStr.contains(msg)) {
throw new AssertionError("stderr should not contain the log message");
}
if (dest.contains(Destination.OUT)) {
if (!outStr.contains(msg)) {
throw new AssertionError("stdout does not contain the expected message");
}
} else if (outStr.contains(msg)) {
throw new AssertionError("stdout should not contain the log message");
}
boolean logMatches = logs.stream().anyMatch(logMatcher);
if (dest.contains(Destination.LOG)) {
if (!logMatches) {
throw new AssertionError("expected message not found in logs");
}
} else {
if (logMatches) {
throw new AssertionError("logs should not contain the message!");
}
}
}
static void assertEquals(Object o1, Object o2) {
if (!Objects.equals(o1, o2)) {
throw new AssertionError("Not equals: \""
+ o1 + "\" != \"" + o2 + "\"");
}
}
static void assertEquals(Object o1, Object o2, String message) {
if (!Objects.equals(o1, o2)) {
throw new AssertionError(message + ": \""
+ o1 + "\" != \"" + o2 + "\"");
}
}
}