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 

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

    27 

    28 import java.io.PrintStream;

    29 import java.util.Objects;

    30 import java.util.ResourceBundle;

    31 import java.util.function.Supplier;

    32 

    33 /**

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

    35  * {@code System.Logger}, after adding some decoration. The logger also has the

    36  * ability to additionally send the logged messages to System.err or System.out,

    37  * whether the underlying logger is activated or not. In addition instance of

    38  * {@code DebugLogger} support both {@link String#format(String, Object...)} and

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

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

    41  * format string. MessageFormat-like formatting is enabled by the presence of

    42  * "{0" or "{1".

    43  *

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

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

    46  */

    47 final 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 WS_NAME  = "jdk.internal.httpclient.websocket.debug";

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

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

    53     final static System.Logger WS = System.getLogger(WS_NAME);

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

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

    56 

    57     private final Supplier<String> dbgTag;

    58     private final Level errLevel;

    59     private final Level outLevel;

    60     private final System.Logger logger;

    61     private final boolean debugOn;

    62     private final boolean traceOn;

    63 

    64     /**

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

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

    67      *

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

    69      * {@code logger}.

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

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

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

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

    74      * <p>

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

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

    77      *

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

    79      *          addition to forwarding to the internal logger, use

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

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

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

    83      *

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

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

    86      *

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

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

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

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

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

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

    93      *

    94      * @return A logger for HTTP internal debug traces

    95      */

    96     private DebugLogger(System.Logger logger,

    97                 Supplier<String> dbgTag,

    98                 Level outLevel,

    99                 Level errLevel) {

   100         this.dbgTag = dbgTag;

   101         this.errLevel = errLevel;

   102         this.outLevel = outLevel;

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

   104         // support only static configuration.

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

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

   107     }

   108 

   109     @Override

   110     public String getName() {

   111         return logger.getName();

   112     }

   113 

   114     private boolean isEnabled(Level level) {

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

   116         int severity = level.getSeverity();

   117         return severity >= errLevel.getSeverity()

   118                 || severity >= outLevel.getSeverity()

   119                 || logger.isLoggable(level);

   120     }

   121 

   122     @Override

   123     public final boolean on() {

   124         return debugOn;

   125     }

   126 

   127     @Override

   128     public boolean isLoggable(Level level) {

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

   130         // support only static configuration.

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

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

   133         return isEnabled(level);

   134     }

   135 

   136     @Override

   137     public void log(Level level, ResourceBundle unused,

   138                     String format, Object... params) {

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

   140         // support only static configuration.

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

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

   143 

   144         int severity = level.getSeverity();

   145         if (errLevel != Level.OFF

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

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

   148         }

   149         if (outLevel != Level.OFF

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

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

   152         }

   153         if (logger.isLoggable(level)) {

   154             logger.log(level, unused,

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

   156                     params);

   157         }

   158     }

   159 

   160     @Override

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

   162                     Throwable thrown) {

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

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

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

   166 

   167         if (errLevel != Level.OFF

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

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

   170         }

   171         if (outLevel != Level.OFF

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

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

   174         }

   175         if (logger.isLoggable(level)) {

   176             logger.log(level, unused,

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

   178                     thrown);

   179         }

   180     }

   181 

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

   183                        Object[] params, Throwable t) {

   184         StringBuilder sb = new StringBuilder();

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

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

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

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

   189         if (t != null) {

   190             t.printStackTrace(out);

   191         }

   192     }

   193 

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

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

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

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

   198         long millis = elapsed / 1000_000;

   199         long secs   = millis / 1000;

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

   201                 .append(' ').append('[');

   202         if (secs > 0) {

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

   204         }

   205         millis = millis % 1000;

   206         if (millis > 0) {

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

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

   209         }

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

   211         if (tag != null) {

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

   213         }

   214         sb.append(res);

   215         return sb;

   216     }

   217 

   218 

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

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

   221             return decorate(sb, format);

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

   223             return decorate(sb, format);

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

   225             try {

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

   227             } catch (Throwable t) {

   228                 return decorate(sb, format);

   229             }

   230         } else {

   231             return decorate(sb, format);

   232         }

   233     }

   234 

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

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

   237             return decorate(sb, format);

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

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

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

   241             try {

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

   243             } catch (Throwable t) {

   244                 return decorate(sb, format);

   245             }

   246         } else {

   247             return decorate(sb, format);

   248         }

   249     }

   250 

   251     public static DebugLogger createHttpLogger(Supplier<String> dbgTag,

   252                                                Level outLevel,

   253                                                Level errLevel) {

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

   255     }

   256 

   257     public static DebugLogger createWebSocketLogger(Supplier<String> dbgTag,

   258                                                     Level outLevel,

   259                                                     Level errLevel) {

   260         return new DebugLogger(WS, dbgTag, outLevel, errLevel);

   261     }

   262 

   263     public static DebugLogger createHpackLogger(Supplier<String> dbgTag,

   264                                                 Level outLevel,

   265                                                 Level errLevel) {

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

   267     }

   268 }