DebugContext.java
/*
* Copyright (c) 2014, 2017 Oracle and/or its affiliates. All rights reserved.
*
* This program and the accompanying materials are made available under the
* terms of the Eclipse Public License v. 2.0, which is available at
* http://www.eclipse.org/legal/epl-2.0.
*
* This Source Code may also be made available under the following Secondary
* Licenses when the conditions for such availability set forth in the
* Eclipse Public License v. 2.0 are satisfied: GNU General Public License,
* version 2 with the GNU Classpath Exception, which is available at
* https://www.gnu.org/software/classpath/license.html.
*
* SPDX-License-Identifier: EPL-2.0 OR GPL-2.0 WITH Classpath-exception-2.0
*/
package org.glassfish.tyrus.core;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.StringTokenizer;
import java.util.UUID;
import java.util.logging.Level;
import java.util.logging.Logger;
import org.glassfish.tyrus.spi.UpgradeResponse;
/**
* A {@link java.util.logging.Logger} wrapper that gives logging records a common formatting and temporarily stores log
* records and postpones their logging until they can be provided with a session ID. After a session ID has been
* provided, messages are logged immediately.
* <p>
* Log records are provided with a session ID, so that log records from a single upgrade request can be easily linked
* together in a log of a busy server or client.
*
* @author Petr Janouch
*/
public class DebugContext {
// is not thread safe - it is assumed that it will be used only in the "handshake phase"
private List<LogRecord> logRecords = new ArrayList<LogRecord>();
// is not thread safe - it is assumed that it will be used only in the "handshake phase"
private Map<String, List<String>> tracingHeaders = new HashMap<String, List<String>>();
private final long startTimestamp;
private final Level tracingLevel;
private String sessionId = null;
/**
* Constructor that configures tracing to be ON and accepts tracing threshold as a parameter.
*
* @param tracingThreshold tracing threshold.
*/
public DebugContext(TracingThreshold tracingThreshold) {
startTimestamp = System.nanoTime();
if (TracingThreshold.SUMMARY == tracingThreshold) {
tracingLevel = Level.FINE;
} else {
tracingLevel = Level.FINER;
}
}
/**
* Constructor that configures tracing to be OFF.
*/
public DebugContext() {
startTimestamp = System.nanoTime();
this.tracingLevel = Level.OFF;
}
/**
* Append a message to the log, the logging will be postponed until the message can be provided with a session ID.
* Randomly generated session ID is used if a session has not been created.
*
* @param logger logger to be used to log the message.
* @param loggingLevel message level.
* @param type type of the message.
* @param messageParts message parts that will be concatenated to create a log message.
*/
public void appendLogMessage(Logger logger, Level loggingLevel, Type type, Object... messageParts) {
appendLogMessageWithThrowable(logger, loggingLevel, type, null, messageParts);
}
/**
* Append a message to the log and to the list of trace messages that are sent in handshake response.
* The logging will be postponed until the message can be provided with a session ID. Randomly generated session ID
* is used if a session has not been created.
*
* @param logger logger to be used to log the message.
* @param loggingLevel message level.
* @param type type of the message.
* @param messageParts message parts that will be stringified and concatenated to create a log message.
*/
public void appendTraceMessage(Logger logger, Level loggingLevel, Type type, Object... messageParts) {
appendTraceMessageWithThrowable(logger, loggingLevel, type, null, messageParts);
}
/**
* Append a message to the log, the logging will be postponed until the message can be provided with a session ID.
* Randomly generated session ID is used if a session has not been created.
*
* @param logger logger to be used to log the message.
* @param loggingLevel message level.
* @param type type of the message.
* @param t throwable that has been thrown.
* @param messageParts message parts that will be stringified and concatenated to create a log message.
*/
public void appendLogMessageWithThrowable(Logger logger, Level loggingLevel, Type type, Throwable t,
Object... messageParts) {
if (logger.isLoggable(loggingLevel)) {
String message = stringifyMessageParts(messageParts);
if (sessionId == null) {
logRecords.add(new LogRecord(logger, loggingLevel, type, message, t, false));
} else {
if (t != null) {
logger.log(loggingLevel, formatLogMessage(message, type, System.nanoTime()), t);
} else {
logger.log(loggingLevel, formatLogMessage(message, type, System.nanoTime()));
}
}
}
}
/**
* Append a message to the log and to the list of trace messages that are sent in handshake response.
* The logging will be postponed until the message can be provided with a session ID. Randomly generated session ID
* is used if a session has not been created.
*
* @param logger logger to be used to log the message.
* @param loggingLevel message level.
* @param type type of the message.
* @param t throwable that has been thrown.
* @param messageParts message parts that will be stringified and concatenated to create a log message.
*/
public void appendTraceMessageWithThrowable(Logger logger, Level loggingLevel, Type type, Throwable t,
Object... messageParts) {
if (this.tracingLevel.intValue() <= loggingLevel.intValue()) {
String message = stringifyMessageParts(messageParts);
appendTracingHeader(message);
}
appendLogMessageWithThrowable(logger, loggingLevel, type, t, messageParts);
}
/**
* Write a message to the standard output, the logging will be postponed until the message can be provided with
* a session ID. Randomly generated session ID is used if a session has not been created.
*
* @param message message to be logged.
* @param type type of the message.
*/
public void appendStandardOutputMessage(Type type, String message) {
if (sessionId == null) {
logRecords.add(new LogRecord(null, Level.OFF, type, message, null, true));
} else {
System.out.println(formatLogMessage(message, type, System.nanoTime()));
}
}
/**
* Set a session ID that will be used as a common identifier for logged messages related to the same upgrade
* request. Setting the session ID will cause the pending messages to be written into the log.
*
* @param sessionId session ID.
*/
public void setSessionId(String sessionId) {
this.sessionId = sessionId;
flush();
}
/**
* Write pending messages to the log.
*/
public void flush() {
if (sessionId == null) {
// something went wrong before the session could have been initialized, just give all the messages some id.
sessionId = UUID.randomUUID().toString();
}
for (LogRecord logRecord : logRecords) {
if (logRecord.printToSout) {
System.out.println(formatLogMessage(logRecord.message, logRecord.type, logRecord.timestamp));
} else if (logRecord.logger.isLoggable(logRecord.loggingLevel)) {
if (logRecord.t != null) {
logRecord.logger.log(logRecord.loggingLevel,
formatLogMessage(logRecord.message, logRecord.type, logRecord.timestamp),
logRecord.t);
} else {
logRecord.logger.log(logRecord.loggingLevel,
formatLogMessage(logRecord.message, logRecord.type, logRecord.timestamp));
}
}
}
logRecords.clear();
}
/**
* Get headers containing tracing messages.
*
* @return tracing headers.
*/
public Map<String, List<String>> getTracingHeaders() {
return tracingHeaders;
}
private void appendTracingHeader(String message) {
String headerName = UpgradeResponse.TRACING_HEADER_PREFIX + String.format("%02d", tracingHeaders.size());
tracingHeaders.put(headerName,
Arrays.asList("[" + (System.nanoTime() - startTimestamp) / 1000000 + " ms] " + message));
}
private String formatLogMessage(String message, Type type, long timestamp) {
StringBuilder formattedMessage = new StringBuilder();
List<String> messageLines = new ArrayList<String>();
StringTokenizer tokenizer = new StringTokenizer(message, "\n", true);
while (tokenizer.hasMoreTokens()) {
messageLines.add(tokenizer.nextToken());
}
String prefix;
if (type == Type.MESSAGE_IN) {
prefix = "< ";
} else if (type == Type.MESSAGE_OUT) {
prefix = "> ";
} else {
prefix = "* ";
}
boolean isFirst = true;
for (String line : messageLines) {
if (isFirst) {
formattedMessage.append(prefix).append("Session ").append(sessionId).append(" ");
formattedMessage.append("[").append((timestamp - startTimestamp) / 1000000).append(" ms]: ");
formattedMessage.append(line);
isFirst = false;
} else {
if (!"\n".equals(line)) {
formattedMessage.append(prefix);
}
formattedMessage.append(line);
}
}
return formattedMessage.toString();
}
private String stringifyMessageParts(Object... messageParts) {
StringBuilder sb = new StringBuilder();
for (Object messagePart : messageParts) {
sb.append(messagePart);
}
return sb.toString();
}
private static class LogRecord {
/**
* Logger that will be used to log the message.
*/
private Logger logger;
/**
* Logger level that will be used when logging the message.
*/
private Level loggingLevel;
/**
* Type of the record - used for graphical purposes when logging.
*/
private Type type;
/**
* Message to be logged.
*/
private String message;
/**
* Throwable to be logged.
*/
private Throwable t;
/**
* {@code true} if the record should be printed into standard output - used if a message should be "logged"
* even
* though the logging has been turned off or the configured logging level is too high.
*/
private boolean printToSout;
/**
* Time when a the logged even has occurred.
*/
private long timestamp;
LogRecord(Logger logger, Level loggingLevel, Type Type, String message, Throwable t, boolean printToSout) {
this.logger = logger;
this.loggingLevel = loggingLevel;
this.type = Type;
this.message = message;
this.t = t;
this.printToSout = printToSout;
timestamp = System.nanoTime();
}
}
/**
* Type of the record - used to graphically distinguish these message types in the log.
*/
public enum Type {
MESSAGE_IN,
MESSAGE_OUT,
OTHER
}
/**
* Type of tracing - used for tracing configuration.
*/
public enum TracingType {
/**
* No tracing headers will be ever sent in handshake response.
*/
OFF,
/**
* Tracing headers will be sent in handshake response only if X-Tyrus-Tracing-Accept header is present
* in handshake request.
*/
ON_DEMAND,
/**
* Tracing headers will be present in all handshake responses.
*/
ALL
}
/**
* Tracing threshold - used for configuration granularity of information that will be sent in tracing headers.
*/
public enum TracingThreshold {
/**
* A less verbose tracing, an equivalent to {@link java.util.logging.Level#FINER} logging level.
*/
SUMMARY,
/**
* A more verbose tracing, an equivalent to {@link java.util.logging.Level#FINE} logging level.
* <p>
* The default tracing threshold.
*/
TRACE
}
}