diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java b/src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java index 86d9a2648da..bf8ba32bc31 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/Http2Connection.java @@ -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 diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java b/src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java index dcdefc1d76d..a5266ba9aa0 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/RawChannelTube.java @@ -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) { diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/common/DebugLogger.java b/src/java.net.http/share/classes/jdk/internal/net/http/common/DebugLogger.java index 01f962f5bbe..fba56930a6e 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/common/DebugLogger.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/common/DebugLogger.java @@ -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". * - *

See {@link Utils#getDebugLogger(Supplier, boolean)} and - * {@link Utils#getHpackLogger(Supplier, boolean)}. + *

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 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. + *

+ * By default, this logger will print message whose severity is + * above the severity configured in the logger {@code config} + *

*

* The logger will add some decoration to the printed message, in the form of * {@code :[] [] : } * * @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 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 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 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 dbgTag, - Level outLevel, - Level errLevel) { - if (levelEnabledFor(Level.DEBUG, outLevel, errLevel, HPACK)) { - return new DebugLogger(HPACK, dbgTag, outLevel, errLevel); + public static DebugLogger createHpackLogger(Supplier 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; diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/common/Logger.java b/src/java.net.http/share/classes/jdk/internal/net/http/common/Logger.java index ed8e9e0197d..1d84b619976 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/common/Logger.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/common/Logger.java @@ -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. */ diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/common/Utils.java b/src/java.net.http/share/classes/jdk/internal/net/http/common/Utils.java index 511bd94ede3..cea493cd4e3 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/common/Utils.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/common/Utils.java @@ -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 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. - * + *

* 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}. + *

+ * 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: + *

+ * + * This logger will add some decoration to the printed message, in the form of * {@code :[] [] : } * * @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 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 :[] [] : } - * - * @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 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 :[] [] : } - * - * @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 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 :[] [] : } - * - * @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 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 :[] [] : } + * The logger should only be used with levels whose severity is + * {@code <= DEBUG}. + *

+ * 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: + *

    + *
  • err: the messages will be logged on System.err
  • + *
  • out: the messages will be logged on System.out
  • + *
  • log: the messages will be forwarded to an internal + * System.Logger named "jdk.internal.httpclient.hpack.debug"
  • + *
  • true: this is equivalent to "err,log": the messages will be logged + * both on System.err, and forwarded to the internal logger.
  • + *
* - * @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 :[] [] : } * * @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 dbgTag, boolean on) { - Level errLevel = on ? Level.ALL : Level.OFF; - return getHpackLogger(dbgTag, errLevel); + public static Logger getHpackLogger(Supplier 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}. + *

+ * The logger should only be used with levels whose severity is + * {@code <= DEBUG}. + *

+ * 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: + *

    + *
  • err: the messages will be logged on System.err
  • + *
  • out: the messages will be logged on System.out
  • + *
  • log: the messages will be forwarded to an internal + * System.Logger named "jdk.internal.httpclient.websocket.debug"
  • + *
  • true: this is equivalent to "err,log": the messages will be logged + * both on System.err, and forwarded to the internal logger.
  • + *
* - * 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 :[] [] : } * - * @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 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 :[] [] : } - * - * @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 dbgTag, boolean on) { - Level errLevel = on ? Level.ALL : Level.OFF; - return getWebSocketLogger(dbgTag, errLevel); + public static Logger getWebSocketLogger(Supplier dbgTag) { + return DebugLogger.createWebSocketLogger(dbgTag, DEBUG_WS_CONFIG); } /** diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageDecoder.java b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageDecoder.java index 3948b568965..9e66327b7c8 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageDecoder.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageDecoder.java @@ -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(); diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageEncoder.java b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageEncoder.java index 3a154d87778..0dd03e8f4c3 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageEncoder.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/MessageEncoder.java @@ -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(); diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/TransportImpl.java b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/TransportImpl.java index 4a23ec27fdf..df25c889811 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/TransportImpl.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/TransportImpl.java @@ -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(); diff --git a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/WebSocketImpl.java b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/WebSocketImpl.java index fddf6b93f04..aa9b027e200 100644 --- a/src/java.net.http/share/classes/jdk/internal/net/http/websocket/WebSocketImpl.java +++ b/src/java.net.http/share/classes/jdk/internal/net/http/websocket/WebSocketImpl.java @@ -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(); diff --git a/test/jdk/java/net/httpclient/DebugLoggerTest.java b/test/jdk/java/net/httpclient/DebugLoggerTest.java new file mode 100644 index 00000000000..ec36d62e38e --- /dev/null +++ b/test/jdk/java/net/httpclient/DebugLoggerTest.java @@ -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: + *
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();
+     *      }
+     *      // ....
+     * ...
+     * 
+ *

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 getDestinations(String prop) { + if (prop == null) return Set.of(); + String[] values = prop.split(","); + if (values.length == 0) return Set.of(); + Set 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 matcher1 = (r) -> r.getMessage() != null && r.getMessage().contains(MESSAGE); + doTest(() -> debug.log(MESSAGE), debug, logHandler, dest, MESSAGE, matcher1); + Exception thrown = new Exception(MESSAGE3); + Predicate 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 dest, + String msg, + Predicate 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 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 + "\""); + } + } + + +}