1 /*

     2  * Copyright (c) 2015, 2018, Oracle and/or its affiliates. All rights reserved.

     3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.

     4  *

     5  * This code is free software; you can redistribute it and/or modify it

     6  * under the terms of the GNU General Public License version 2 only, as

     7  * published by the Free Software Foundation.  Oracle designates this

     8  * particular file as subject to the "Classpath" exception as provided

     9  * by Oracle in the LICENSE file that accompanied this code.

    10  *

    11  * This code is distributed in the hope that it will be useful, but WITHOUT

    12  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or

    13  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License

    14  * version 2 for more details (a copy is included in the LICENSE file that

    15  * accompanied this code).

    16  *

    17  * You should have received a copy of the GNU General Public License version

    18  * 2 along with this work; if not, write to the Free Software Foundation,

    19  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.

    20  *

    21  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA

    22  * or visit www.oracle.com if you need additional information or have any

    23  * questions.

    24  */

    25 package jdk.internal.net.http.common;

    26 

    27 import java.io.PrintStream;

    28 import java.util.Objects;

    29 import java.util.ResourceBundle;

    30 import java.util.function.Supplier;

    31 import java.lang.System.Logger;

    32 

    33 /**

    34  * A {@code System.Logger} that forwards all messages to an underlying

    35  * {@code System.Logger}, after adding some decoration.

    36  * The logger also has the ability to additionally send the logged messages

    37  * to System.err or System.out, whether the underlying logger is activated or not.

    38  * In addition instance of {@code DebugLogger} support both

    39  * {@link String#format(String, Object...)} and

    40  * {@link java.text.MessageFormat#format(String, Object...)} formatting.

    41  * String-like formatting is enabled by the presence of "%s" or "%d" in the format

    42  * string. MessageFormat-like formatting is enabled by the presence of "{0" or "{1".

    43  * <p>

    44  * See {@link Utils#getDebugLogger(Supplier, boolean)} and

    45  * {@link Utils#getHpackLogger(Supplier, boolean)}.

    46  */

    47 class DebugLogger implements Logger {

    48     // deliberately not in the same subtree than standard loggers.

    49     final static String HTTP_NAME  = "jdk.internal.httpclient.debug";

    50     final static String HPACK_NAME = "jdk.internal.httpclient.hpack.debug";

    51     final static Logger HTTP = System.getLogger(HTTP_NAME);

    52     final static Logger HPACK = System.getLogger(HPACK_NAME);

    53     final static long START_NANOS = System.nanoTime();

    54 

    55     private final Supplier<String> dbgTag;

    56     private final Level errLevel;

    57     private final Level outLevel;

    58     private final Logger logger;

    59     private final boolean debugOn;

    60     private final boolean traceOn;

    61 

    62     /**

    63      * Create a logger for debug traces.The logger should only be used

    64      * with levels whose severity is {@code <= DEBUG}.

    65      *

    66      * By default, this logger will forward all messages logged to the supplied

    67      * {@code logger}.

    68      * But in addition, if the message severity level is {@code >=} to

    69      * the provided {@code errLevel} it will print the messages on System.err,

    70      * and if the message severity level is {@code >=} to

    71      * the provided {@code outLevel} it will also print the messages on System.out.

    72      * <p>

    73      * The logger will add some decoration to the printed message, in the form of

    74      * {@code <Level>:[<thread-name>] [<elapsed-time>] <dbgTag>: <formatted message>}

    75      *

    76      * @apiNote To obtain a logger that will always print things on stderr in

    77      *          addition to forwarding to the internal logger, use

    78      *          {@code new DebugLogger(logger, this::dbgTag, Level.OFF, Level.ALL);}.

    79      *          To obtain a logger that will only forward to the internal logger,

    80      *          use {@code new DebugLogger(logger, this::dbgTag, Level.OFF, Level.OFF);}.

    81      *

    82      * @param logger The internal logger to which messages will be forwarded.

    83      *               This should be either {@link #HPACK} or {@link #HTTP};

    84      *

    85      * @param dbgTag A lambda that returns a string that identifies the caller

    86      *               (e.g: "SocketTube(3)", or "Http2Connection(SocketTube(3))")

    87      * @param outLevel The level above which messages will be also printed on

    88      *               System.out (in addition to being forwarded to the internal logger).

    89      * @param errLevel The level above which messages will be also printed on

    90      *               System.err (in addition to being forwarded to the internal logger).

    91      *

    92      * @return A logger for HTTP internal debug traces

    93      */

    94     private DebugLogger(Logger logger,

    95                 Supplier<String> dbgTag,

    96                 Level outLevel,

    97                 Level errLevel) {

    98         this.dbgTag = dbgTag;

    99         this.errLevel = errLevel;

   100         this.outLevel = outLevel;

   101         this.logger = Objects.requireNonNull(logger);

   102         // support only static configuration.

   103         this.debugOn = isEnabled(Level.DEBUG);

   104         this.traceOn = isEnabled(Level.TRACE);

   105     }

   106 

   107     @Override

   108     public String getName() {

   109         return logger.getName();

   110     }

   111 

   112     private boolean isEnabled(Level level) {

   113         if (level == Level.OFF) return false;

   114         int severity = level.getSeverity();

   115         return severity >= errLevel.getSeverity()

   116                 || severity >= outLevel.getSeverity()

   117                 || logger.isLoggable(level);

   118     }

   119 

   120     @Override

   121     public boolean isLoggable(Level level) {

   122         // fast path, we assume these guys never change.

   123         // support only static configuration.

   124         if (level == Level.DEBUG) return debugOn;

   125         if (level == Level.TRACE) return traceOn;

   126         return isEnabled(level);

   127     }

   128 

   129     @Override

   130     public void log(Level level, ResourceBundle unused,

   131                     String format, Object... params) {

   132         // fast path, we assume these guys never change.

   133         // support only static configuration.

   134         if (level == Level.DEBUG && !debugOn) return;

   135         if (level == Level.TRACE && !traceOn) return;

   136 

   137         int severity = level.getSeverity();

   138         if (errLevel != Level.OFF

   139                 && errLevel.getSeverity() <= severity) {

   140             print(System.err, level, format, params, null);

   141         }

   142         if (outLevel != Level.OFF

   143                 && outLevel.getSeverity() <= severity) {

   144             print(System.out, level, format, params, null);

   145         }

   146         if (logger.isLoggable(level)) {

   147             logger.log(level, unused,

   148                     getFormat(new StringBuilder(), format, params).toString(),

   149                     params);

   150         }

   151     }

   152 

   153     @Override

   154     public void log(Level level, ResourceBundle unused, String msg,

   155                     Throwable thrown) {

   156         // fast path, we assume these guys never change.

   157         if (level == Level.DEBUG && !debugOn) return;

   158         if (level == Level.TRACE && !traceOn) return;

   159 

   160         if (errLevel != Level.OFF

   161                 && errLevel.getSeverity() <= level.getSeverity()) {

   162             print(System.err, level, msg, null, thrown);

   163         }

   164         if (outLevel != Level.OFF

   165                 && outLevel.getSeverity() <= level.getSeverity()) {

   166             print(System.out, level, msg, null, thrown);

   167         }

   168         if (logger.isLoggable(level)) {

   169             logger.log(level, unused,

   170                     getFormat(new StringBuilder(), msg, null).toString(),

   171                     thrown);

   172         }

   173     }

   174 

   175     private void print(PrintStream out, Level level, String msg,

   176                        Object[] params, Throwable t) {

   177         StringBuilder sb = new StringBuilder();

   178         sb.append(level.name()).append(':').append(' ');

   179         sb = format(sb, msg, params);

   180         if (t != null) sb.append(' ').append(t.toString());

   181         out.println(sb.toString());

   182         if (t != null) {

   183             t.printStackTrace(out);

   184         }

   185     }

   186 

   187     private StringBuilder decorate(StringBuilder sb, String msg) {

   188         String tag = dbgTag == null ? null : dbgTag.get();

   189         String res = msg == null ? "" : msg;

   190         long elapsed = System.nanoTime() - START_NANOS;

   191         long millis = elapsed / 1000_000;

   192         long secs   = millis / 1000;

   193         sb.append('[').append(Thread.currentThread().getName()).append(']')

   194                 .append(' ').append('[');

   195         if (secs > 0) {

   196             sb.append(secs).append('s');

   197         }

   198         millis = millis % 1000;

   199         if (millis > 0) {

   200             if (secs > 0) sb.append(' ');

   201             sb.append(millis).append("ms");

   202         }

   203         sb.append(']').append(' ');

   204         if (tag != null) {

   205             sb.append(tag).append(' ');

   206         }

   207         sb.append(res);

   208         return sb;

   209     }

   210 

   211 

   212     private StringBuilder getFormat(StringBuilder sb, String format, Object[] params) {

   213         if (format == null || params == null || params.length == 0) {

   214             return decorate(sb, format);

   215         } else if (format.contains("{0}") || format.contains("{1}")) {

   216             return decorate(sb, format);

   217         } else if (format.contains("%s") || format.contains("%d")) {

   218             try {

   219                 return decorate(sb, String.format(format, params));

   220             } catch (Throwable t) {

   221                 return decorate(sb, format);

   222             }

   223         } else {

   224             return decorate(sb, format);

   225         }

   226     }

   227 

   228     private StringBuilder format(StringBuilder sb, String format, Object[] params) {

   229         if (format == null || params == null || params.length == 0) {

   230             return decorate(sb, format);

   231         } else if (format.contains("{0}") || format.contains("{1}")) {

   232             return decorate(sb, java.text.MessageFormat.format(format, params));

   233         } else if (format.contains("%s") || format.contains("%d")) {

   234             try {

   235                 return decorate(sb, String.format(format, params));

   236             } catch (Throwable t) {

   237                 return decorate(sb, format);

   238             }

   239         } else {

   240             return decorate(sb, format);

   241         }

   242     }

   243 

   244     public static DebugLogger createHttpLogger(Supplier<String> dbgTag, Level outLevel, Level errLevel) {

   245         return new DebugLogger(HTTP, dbgTag, outLevel, errLevel);

   246     }

   247 

   248     public static DebugLogger createHpackLogger(Supplier<String> dbgTag, Level outLevel, Level errLevel) {

   249         return new DebugLogger(HPACK, dbgTag, outLevel, errLevel);

   250     }

   251 }