/* * Copyright (c) 2001, 2018, 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. */ package nsk.share; import java.io.BufferedReader; import java.io.ByteArrayOutputStream; import java.io.IOException; import java.io.PrintStream; import java.io.PrintWriter; import java.io.StringReader; import java.util.Enumeration; import java.util.HashMap; import java.util.Map; import java.util.Set; import java.util.HashSet; import java.util.Vector; import nsk.share.test.LazyFormatString; /** * This class helps to print test-execution trace messages * and filter them when execution mode is not verbose. *

* Verbose mode if defined by providing -verbose command line * option, handled by ArgumentParser. Use verbose() * method to determine which mode is used. *

* Log provides with two main methods to print messages: *

* No other way to print messages to the log stream should be used. *

* Error messages appeares in log stream in all modes. Additional log massages, * printed with display() method will be filtered out, if log mode * is not verbose. In verbose log made messages of both types are printed. * Additionally, in verbose mode a summary of all occured errors will be printed * at the program exit, by automatically invoking method * printErrorsSummary(). *

* To provide printing messages from different sources into one log * with distinct prefixes use internal Log.Logger class. * * @see #verbose() * @see #complain(String) * @see #display(String) * @see ArgumentParser * @see Log.Logger */ public class Log extends FinalizableObject { /** * Report step-by-step activity to this stream. * * @deprecated Tests should not use this field directly. */ protected PrintStream out = null; /** * Is log-mode verbose? * Default value is false. */ private boolean verbose = false; /** * Should log messages prefixed with timestamps? * Default value is false. */ private boolean timestamp = false; /** * Names for trace levels */ public static final class TraceLevel { public static final int TRACE_NONE = 0; public static final int TRACE_IMPORTANT = 1; public static final int TRACE_NORMAL = 2; public static final int TRACE_VERBOSE = 3; public static final int TRACE_DEBUG = 4; public static final int DEFAULT = TRACE_IMPORTANT; public static final Map NAME_TO_LEVEL_MAP = new HashMap(); static { NAME_TO_LEVEL_MAP.put("none", TRACE_NONE); NAME_TO_LEVEL_MAP.put("important", TRACE_IMPORTANT); NAME_TO_LEVEL_MAP.put("info", TRACE_NORMAL); NAME_TO_LEVEL_MAP.put("verbose", TRACE_VERBOSE); NAME_TO_LEVEL_MAP.put("debug", TRACE_DEBUG); NAME_TO_LEVEL_MAP.put("default", DEFAULT); } public static int nameToLevel(String value) throws IllegalArgumentException { Integer level = NAME_TO_LEVEL_MAP.get(value.toLowerCase()); if ( level == null ) throw new IllegalArgumentException("Wrong trace level: " + value); return level; } public static String getLevelsString() { StringBuffer result = new StringBuffer(); for ( String s : NAME_TO_LEVEL_MAP.keySet() ) { result.append(s).append(", "); } return result.substring(0, result.length() - 3); } } /** * Threshold value for printing trace messages for debugging purpose. * Default value is 0 a.k.a. TraceLevel.INFO; */ private int traceLevel = TraceLevel.DEFAULT; /** * Is printing errors summary enabled? Default value is true; */ private boolean errorsSummaryEnabled = true; /** * Is printing saved verbose messages on error enabled? Default value is true; */ private boolean verboseOnErrorEnabled = true; /** * This errosBuffer will keep all messages printed via * complain() method for final summary output. * Ensure that buffer has enough room for messages to keep, * to minimize probability or OutOfMemory error while keeping * an error message in stress tests. */ private Vector errorsBuffer = new Vector(1000); /** * Most tests in nsk do not log exceptions, they only log an error message. * This makes failure analysis harder. * To solve this we will automatically generate Exceptions for error logs. * To not log too many Exceptions, we try to log each unique error only once. * loggedExceptions contains all messages that have already been logged. */ private Set loggedExceptions = new HashSet(); /** * This logBuffer will keep all messages printed via * display() method in non-verbose mode until * swithching verbose mode on or invoking complain(). * Ensure that buffer has enough room for messages to keep, * to minimize probability or OutOfMemory error while keeping * an error message in stress tests. */ private Vector logBuffer = new Vector(1000); /** * Did I already warned if output stream is not assigned? */ private boolean noOutWarned = false; ///////////////////////////////////////////////////////////////// /** * Create new Log's only with Log(out) or with * Log(out,argsHandler) constructors. * * @deprecated Extending test class with Log is obsolete. */ protected Log() { // install finalizer to print errors summary at exit Finalizer finalizer = new Finalizer(this); finalizer.activate(); // Don't log exceptions from this method. It would just add unnecessary logs. loggedExceptions.add("nsk.share.jdi.SerialExecutionDebugger.executeTests"); } /** * Incarnate new Log for the given stream and * for non-verbose mode. */ public Log(PrintStream stream) { this(); out = stream; } /** * Incarnate new Log for the given stream; and * either for verbose or for non-verbose mode accordingly to * the given verbose key. */ public Log(PrintStream stream, boolean verbose) { this(stream); this.verbose = verbose; } /** * Incarnate new Log for the given stream; and * either for verbose or for non-verbose mode accordingly to * the given argsHandler. */ public Log(PrintStream stream, ArgumentParser argsParser) { this(stream, argsParser.verbose()); traceLevel = argsParser.getTraceLevel(); timestamp = argsParser.isTimestamp(); } ///////////////////////////////////////////////////////////////// /** * Return true if log mode is verbose. */ public boolean verbose() { return verbose; } /** * Return true if printing errors summary at exit is enabled. */ public boolean isErrorsSummaryEnabled() { return errorsSummaryEnabled; } /** * Enable or disable printing errors summary at exit. */ public void enableErrorsSummary(boolean enable) { errorsSummaryEnabled = enable; } /** * Return true if printing saved verbose messages on error is enabled. */ public boolean isVerboseOnErrorEnabled() { return errorsSummaryEnabled; } /** * Enable or disable printing saved verbose messages on error. */ public void enableVerboseOnError(boolean enable) { verboseOnErrorEnabled = enable; } /** * Enable or disable verbose mode for printing messages. */ public void enableVerbose(boolean enable) { if (!verbose) { flushLogBuffer(); } verbose = enable; } public int getTraceLevel() { return traceLevel; } /** * Set threshold for printing trace messages. * Warning: trace level changes may NOT be observed by other threads immediately. */ public void setTraceLevel(int level) { traceLevel = level; } /** * Return output stream of this Log object. */ public PrintStream getOutStream() { return out; } /** * Returns a string that contains prefix concatenated * with Throwable.printStackTrace() output. */ public static String printExceptionToString(Object prefix, Throwable exception) { ByteArrayOutputStream bos = new ByteArrayOutputStream(); PrintWriter pw = new PrintWriter(bos); pw.println(prefix); exception.printStackTrace(pw); pw.close(); return bos.toString(); } /** * Print message to the assigned output stream. * * @deprecated Test ought to be quiet if log mode is non-verbose * and there is no errors found by the test. Methods * display() and complain() * are enough for testing purposes. */ public synchronized void println(String message) { doPrint(message); if (!verbose() && isVerboseOnErrorEnabled()) { keepLog(composeLine(message)); } } /** * Print message to the assigned output stream, * if log mode is non-verbose. * * @deprecated Test ought to be quiet if log mode is non-verbose * and there is no errors found by the test. Methods * display() and complain() * are enough for testing purposes. */ public synchronized void comment(String message) { if (!verbose()) { doPrint(message); } } /** * Print trace message to the assigned output stream, * only if specified level is less or equal for the * trace level specified in command line by -trace.level * option. */ public void trace(int level, Object message) { if (level <= traceLevel) { synchronized ( this ) { doPrint("### TRACE " + level + ": " + message); } } } /** * Print trace message and exception to * the assigned output stream, * only if specified level is less or equal for the * trace level specified in command line by -trace.level * option. */ public void trace(int level, Object message, Throwable exception) { if (level <= traceLevel) { trace(level, printExceptionToString(message, exception)); } } /** * Print message to the assigned output stream, * if log mode is verbose. The message will be lost, * if execution mode is non-verbose, and there is no error messages * printed. */ public synchronized void display(Object message) { if (verbose()) { doPrint(message.toString()); } else if (isVerboseOnErrorEnabled()) { keepLog(composeLine(message.toString())); } else { // ignore } } /** * Print error message to the assigned output stream * (or to stderr if output is not specified) and keep the message * into errorsBuffer. */ public synchronized void complain(Object message) { if (!verbose() && isVerboseOnErrorEnabled()) { PrintStream stream = findOutStream(); stream.println("#> "); stream.println("#> WARNING: switching log to verbose mode,"); stream.println("#> because error is complained"); stream.println("#> "); stream.flush(); enableVerbose(true); } String msgStr = message.toString(); printError(msgStr); if (isErrorsSummaryEnabled()) { keepError(msgStr); } logExceptionForFailureAnalysis(msgStr); } /** * Print error message and exception * to the assigned output stream * (or to stderr if output is not specified) and keep the message * into errorsBuffer. */ public void complain(Object message, Throwable exception) { if ( exception != null ) complain(printExceptionToString(message, exception)); else complain(message); } /** * Create an Exception and print the stack trace for an error msg. * This makes it possible to detect a failure reason for this error. */ private void logExceptionForFailureAnalysis(String msg) { // Some error messages are formatted in multiple lines and with tabs. // We clean the messages to help parse the stack traces for failure analysis. // We keep at most 2 lines, otherwise the error message may be too long. String[] lines = msg.split("[\r\n]+"); msg = lines.length >= 2 ? lines[0] + " " + lines[1] : lines[0]; msg = msg.replaceAll("\t", " "); // Create a dummy exception just so we can print the stack trace. TestFailure e = new TestFailure(msg); StackTraceElement[] elements = e.getStackTrace(); final int callerIndex = 2; // 0=this function, 1=complain(), 2=caller if (elements.length <= callerIndex) { return; } // Only log the first complain message from each function. // The reason is that some functions splits an error message // into multiple lines and call complain() many times. // We do not want a RULE for each of those calls. // This means that we may miss some rules, but that // is better than to create far too many rules. String callerClass = elements[callerIndex].getClassName(); String callerMethod = elements[callerIndex].getMethodName(); String callerKey = callerClass + "." + callerMethod; boolean isAlreadyLogged = loggedExceptions.contains(msg) || loggedExceptions.contains(callerKey); if (!isAlreadyLogged) { PrintStream stream = findOutStream(); stream.println("The following stacktrace is for failure analysis."); e.printStackTrace(stream); } loggedExceptions.add(callerKey); loggedExceptions.add(msg); } ///////////////////////////////////////////////////////////////// /** * Redirect log to the given stream, and switch * log mode to verbose. * Prints errors summary to current stream, cancel current stream * and switches to new stream. Turns on verbose mode for new stream. * * @deprecated This method is obsolete. */ protected synchronized void logTo(PrintStream stream) { finalize(); // flush older log stream out = stream; verbose = true; } ///////////////////////////////////////////////////////////////// /** * Print all messages from log buffer which were hidden because * of non-verbose mode, */ private synchronized void flushLogBuffer() { if (!logBuffer.isEmpty()) { PrintStream stream = findOutStream(); for (int i = 0; i < logBuffer.size(); i++) { stream.println(logBuffer.elementAt(i)); } stream.flush(); } } /** * Return out stream if defined or Sytem.err otherwise; * print a warning message when System.err is used first time. */ private synchronized PrintStream findOutStream() { PrintStream stream = out; if (stream == null) { stream = System.err; if (!noOutWarned) { noOutWarned = true; stream.println("#> "); stream.println("#> WARNING: switching log stream to stderr,"); stream.println("#> because no output stream is assigned"); stream.println("#> "); }; }; stream.flush(); return stream; } /** * Compose line to print possible prefixing it with timestamp. */ private String composeLine(String message) { if (timestamp) { long time = System.currentTimeMillis(); long ms = time % 1000; time /= 1000; long secs = time % 60; time /= 60; long mins = time % 60; time /= 60; long hours = time % 24; return "[" + hours + ":" + mins + ":" + secs + "." + ms + "] " + message; } return message; } /** * Print the given message either to out * stream, or to System.err if out * stream is not specified. */ private synchronized void doPrint(String message) { PrintStream stream = findOutStream(); stream.println(composeLine(message)); stream.flush(); } /** * Print the given error message either to out * stream, or to System.err if out * stream is not specified. */ private synchronized void printError(String message) { // Print each line with the ERROR prefix: BufferedReader br = new BufferedReader(new StringReader(message)); for (String line; ; ) { try { line = br.readLine(); if (line == null) break; doPrint("# ERROR: " + line); } catch (IOException e) { throw new TestBug("Exception in Log.printError(): " + e); }; } } /** * Keep the given log message into logBuffer. */ private synchronized void keepLog(String message) { logBuffer.addElement(message); } /** * Keep the given error message into errorsBuffer. */ private synchronized void keepError(String message) { errorsBuffer.addElement(message); } /** * Print errors messages summary from errors buffer if any; * print a warning message first. */ private synchronized void printErrorsSummary() { if (errorsBuffer.size() <= 0) return; PrintStream stream = findOutStream(); stream.println(); stream.println(); stream.println("#> "); stream.println("#> SUMMARY: Following errors occured"); stream.println("#> during test execution:"); stream.println("#> "); stream.flush(); for (Enumeration e = errorsBuffer.elements(); e.hasMoreElements(); ) { printError((String) e.nextElement()); } } /** * Print errors summary if mode is verbose, flush and cancel output stream. */ protected void finalize() { if (verbose() && isErrorsSummaryEnabled()) { printErrorsSummary(); } if (out != null) out.flush(); out = null; } /** * Perform finalization at the exit. */ public void finalizeAtExit() { finalize(); } /** * This class can be used as a base for each class that use Log * for print messages and errors. * Logger provides with ability to print such messages with * specified prefix to make it possible to distinct messages printed from * different sources. * * @see Log */ public static class Logger { /** * Default prefix for messages. */ public static final String LOG_PREFIX = ""; /** * Log to print messages to. */ protected Log log = null; /** * Prefix for messages. */ protected String logPrefix = LOG_PREFIX; /** * Make Logger object with empty Log and * default prefix. * This method may be used only in derived class, that should specify * the used Log object further and assign it to log. * * @see #log * @see #setLogPrefix */ protected Logger() { } /** * Make Logger object for specified Log * with default prefix. * * @see #setLogPrefix */ public Logger(Log log) { this.log = log; } /** * Make Logger object for specified Log with * given messages prefix. */ public Logger(Log log, String prefix) { this.log = log; this.logPrefix = prefix; } /** * Return Log object. */ public Log getLog() { return log; } /** * Return output stream of this Log object. */ public PrintStream getOutStream() { return log.getOutStream(); } /** * Set prefix for printed messages. */ public void setLogPrefix(String prefix) { logPrefix = prefix; } /** * Make printable message by adding logPrefix to it. */ public String makeLogMessage(String message) { return logPrefix + message; } /** * Print trace message by invoking Log.trace(). * * @see Log#trace */ public void trace(int level, String message) { log.trace(level, makeLogMessage(message)); } /** * Print message by invoking Log.println(). * * @see Log#println */ public void println(String message) { log.println(makeLogMessage(message)); } /** * Print message by invoking Log.display(). * * @see Log#display */ public void display(String message) { log.display(makeLogMessage(message)); } /** * Complain about an error by invoking Log.complain() method. * * @see Log#complain */ public void complain(String message) { log.complain(makeLogMessage(message)); } } }