From dee9082f1c5b23ecb229d56eec0ad4b7623a4c89 Mon Sep 17 00:00:00 2001 From: hns Date: Tue, 31 Oct 2006 14:57:55 +0000 Subject: [PATCH] * Add log level info such as [INFO], [ERROR], [WARN] to log output. * Add Logger.Entry class to avoid unnecessary String concatenation. * Unify Logger classes code a little bit, making better use of inheritance. * Run logger thread 3 times per second instead of 4 times. * Add Javadoc comments and tags. --- src/helma/util/FileLogger.java | 83 +++++------------------------ src/helma/util/Logger.java | 96 +++++++++++++++++++++------------- src/helma/util/Logging.java | 20 +++++-- 3 files changed, 90 insertions(+), 109 deletions(-) diff --git a/src/helma/util/FileLogger.java b/src/helma/util/FileLogger.java index 8564ec62..29090e47 100644 --- a/src/helma/util/FileLogger.java +++ b/src/helma/util/FileLogger.java @@ -41,12 +41,11 @@ public class FileLogger extends Logger implements Log { DecimalFormat nformat = new DecimalFormat("000"); DateFormat aformat = new SimpleDateFormat("yyyy-MM-dd"); - // timestamp of last log message - long lastMessage; - /** * Create a file logger. The actual file names do have numbers appended and are * rotated every x bytes. + * @param directory the directory + * @param name the log file base name */ protected FileLogger(String directory, String name) { this.name = name; @@ -59,21 +58,16 @@ public class FileLogger extends Logger implements Log { if (!logdir.exists()) { logdir.mkdirs(); } - - // create a synchronized list for log entries since different threads may - // attempt to modify the list at the same time - entries = Collections.synchronizedList(new LinkedList()); - - lastMessage = System.currentTimeMillis(); } /** - * Open the file and get a writer to it. This will either rotate the log files - * or it will return a writer that appends to an existing file. + * Open the file and get a writer to it. If the file already exists, this will + * return a writer that appends to an existing file if it is from today, or + * otherwise rotate the old log file and start a new one. */ private synchronized void openFile() { try { - if (logfile.exists() && (logfile.lastModified() < lastMidnight())) { + if (logfile.exists() && (logfile.lastModified() < Logging.lastMidnight())) { // rotate if a log file exists and is NOT from today File archive = rotateLogFile(); // gzip rotated log file in a separate thread @@ -105,48 +99,22 @@ public class FileLogger extends Logger implements Log { } /** - * This is called by the runner thread to perform actual output. + * This is called by the runner thread to to make sure we have an open writer. */ - synchronized void write() { - if (entries.isEmpty()) { - return; - } - - try { - int l = entries.size(); - - if (writer == null || !logfile.exists()) { - // open/create the log file if necessary - openFile(); - } - - for (int i = 0; i < l; i++) { - String entry = (String) entries.remove(0); - writer.println(entry); - } - - writer.flush(); - } catch (Exception x) { - int size = entries.size(); - - if (size > 1000) { - // more than 1000 entries queued plus exception - something - // is definitely wrong with this logger. Write a message to std err and - // discard queued log entries. - System.err.println("Error writing log file " + this + ": " + x); - System.err.println("Discarding " + size + " log entries."); - entries.clear(); - } + protected synchronized void ensureOpen() { + // open a new writer if writer is null or the log file has been deleted + if (writer == null || !logfile.exists()) { + openFile(); } } - /** * Rotate log files, closing the file writer and renaming the old * log file. Returns the renamed log file for zipping, or null if * the log file couldn't be rotated. * * @return the old renamed log file, or null + * @throws IOException if an i/o error occurred */ protected synchronized File rotateLogFile() throws IOException { // if the logger is not file based do nothing. @@ -197,36 +165,13 @@ public class FileLogger extends Logger implements Log { } /** - * Return an object which identifies this logger. + * Return an object which identifies this logger. + * @return the logger's name */ public String getName() { return name; } - - /** - * Append a message to the log. - */ - public void log(String msg) { - lastMessage = System.currentTimeMillis(); - - // it's enough to render the date every second - if ((lastMessage - 1000) > dateLastRendered) { - renderDate(); - } - - entries.add(dateCache + msg); - } - - /** - * - * - * @return the timestamp for last midnight in millis - */ - private static long lastMidnight() { - return Logging.nextMidnight() - 86400000; - } - /** * a Thread class that zips up a file, filename will stay the same. */ diff --git a/src/helma/util/Logger.java b/src/helma/util/Logger.java index 07f3b39b..aa6ae823 100644 --- a/src/helma/util/Logger.java +++ b/src/helma/util/Logger.java @@ -27,8 +27,9 @@ import java.util.*; */ public class Logger implements Log { - // buffer for log items - List entries; + // buffer for log items; create a synchronized list for log entries since + // different threads may attempt to modify the list at the same time + List entries = Collections.synchronizedList(new LinkedList()); // Writer for log output PrintWriter writer; @@ -49,7 +50,11 @@ public class Logger implements Log { public final static int FATAL = 6; int logLevel = INFO; - + + // timestamp of last log message, used to close file loggers after longer + // periods of inactivity + long lastMessage = System.currentTimeMillis(); + /** * zero argument constructor, only here for FileLogger subclass */ @@ -59,15 +64,12 @@ public class Logger implements Log { /** * Create a logger for a PrintStream, such as System.out. + * @param out the output stream */ protected Logger(PrintStream out) { init(); writer = new PrintWriter(out); canonicalName = out.toString(); - - // create a synchronized list for log entries since different threads may - // attempt to modify the list at the same time - entries = Collections.synchronizedList(new LinkedList()); } /** @@ -115,7 +117,8 @@ public class Logger implements Log { } /** - * Return an object which identifies this logger. + * Return an object which identifies this logger. + * @return the canonical name of this logger */ public String getCanonicalName() { return canonicalName; @@ -123,35 +126,45 @@ public class Logger implements Log { /** * Append a message to the log. + * @param level a string representing the log level + * @param msg the log message + * @param exception an exception, or null */ - public void log(String msg) { + protected void log(String level, Object msg, Throwable exception) { + lastMessage = System.currentTimeMillis(); // it's enough to render the date every second - if ((System.currentTimeMillis() - 1000) > dateLastRendered) { + if ((lastMessage - 1000) > dateLastRendered) { renderDate(); } // add a safety net so we don't grow indefinitely even if writer thread // has gone. the 2000 entries threshold is somewhat arbitrary. if (entries.size() < 2000) { - entries.add(dateCache + msg); + String message = msg == null ? "null" : msg.toString(); + entries.add(new Entry(dateCache, level, message, exception)); } } /** * This is called by the runner thread to perform actual output. */ - void write() { + protected synchronized void write() { if (entries.isEmpty()) { return; } try { + // make sure we have a valid writer + ensureOpen(); + int l = entries.size(); - for (int i = 0; i < l; i++) { - String entry = (String) entries.remove(0); - writer.println(entry); + Entry entry = (Entry) entries.remove(0); + writer.print(entry.date); + writer.print(entry.level); + writer.println(entry.message); + if (entry.exception != null) + entry.exception.printStackTrace(writer); } - writer.flush(); } catch (Exception x) { @@ -168,8 +181,15 @@ public class Logger implements Log { } } + /** + * This is called by the runner thread to to make sure we have an open writer. + */ + protected void ensureOpen() { + // nothing to do for console logger + } + // Pre-render the date to use for log messages. Called about once a second. - static synchronized void renderDate() { + protected static synchronized void renderDate() { Date date = new Date(); dateCache = dformat.format(date); dateLastRendered = date.getTime(); @@ -203,68 +223,62 @@ public class Logger implements Log { public void trace(Object parm1) { if (logLevel <= TRACE) - log(parm1.toString()); + log("[TRACE] ", parm1, null); } public void trace(Object parm1, Throwable parm2) { if (logLevel <= TRACE) - log(parm1.toString() + "\n" + - getStackTrace(parm2)); + log("[TRACE] ", parm1, parm2); } public void debug(Object parm1) { if (logLevel <= DEBUG) - log(parm1.toString()); + log("[DEBUG] ", parm1, null); } public void debug(Object parm1, Throwable parm2) { if (logLevel <= DEBUG) - log(parm1.toString() + "\n" + - getStackTrace(parm2)); + log("[DEBUG] ", parm1, parm2); } public void info(Object parm1) { if (logLevel <= INFO) - log(parm1.toString()); + log("[INFO] ", parm1, null); } public void info(Object parm1, Throwable parm2) { if (logLevel <= INFO) - log(parm1.toString() + "\n" + - getStackTrace(parm2)); + log("[INFO] ", parm1, parm2); } public void warn(Object parm1) { if (logLevel <= WARN) - log(parm1.toString()); + log("[WARN] ", parm1, null); } public void warn(Object parm1, Throwable parm2) { if (logLevel <= WARN) - log(parm1.toString() + "\n" + - getStackTrace(parm2)); + log("[WARN] ", parm1, parm2); } public void error(Object parm1) { if (logLevel <= ERROR) - log(parm1.toString()); + log("[ERROR] ", parm1, null); } public void error(Object parm1, Throwable parm2) { if (logLevel <= ERROR) - log(parm1.toString() + "\n" + - getStackTrace(parm2)); + log("[ERROR] ", parm1, parm2); } public void fatal(Object parm1) { if (logLevel <= FATAL) - log(parm1.toString()); + log("[FATAL] ", parm1, null); } public void fatal(Object parm1, Throwable parm2) { if (logLevel <= FATAL) - log(parm1.toString() + "\n" + - getStackTrace(parm2)); + log("[FATAL] ", parm1, parm2); } // utility method to get the stack trace from a Throwable as string @@ -276,4 +290,16 @@ public class Logger implements Log { return stringWriter.toString(); } + class Entry { + final String date, level, message; + final Throwable exception; + + Entry(String date, String level, String message, Throwable exception) { + this.date = date; + this.level = level; + this.message = message; + this.exception = exception; + } + } + } diff --git a/src/helma/util/Logging.java b/src/helma/util/Logging.java index 31a66c7b..3e2e8c9c 100644 --- a/src/helma/util/Logging.java +++ b/src/helma/util/Logging.java @@ -73,6 +73,7 @@ public class Logging extends LogFactory { /** * Get a logger to System.out. + * @return a logger that writes to System.out */ public static Log getConsoleLog() { ensureRunning(); @@ -81,7 +82,9 @@ public class Logging extends LogFactory { /** - * Get a file logger, creating it if it doesn't exist yet. + * Get a file logger, creating it if it doesn't exist yet. + * @param logname the base name for the file logger + * @return a file logger */ public synchronized Logger getFileLog(String logname) { Logger log = (Logger) loggerMap.get(logname); @@ -101,9 +104,7 @@ public class Logging extends LogFactory { } public void setAttribute(String name, Object value) { - if ("logdir".equals(name)) { - // FIXME: make log dir changable at runtime - } + // FIXME: make log dir changeable at runtime } public Object getAttribute(String name) { @@ -216,6 +217,15 @@ public class Logging extends LogFactory { return cal.getTime().getTime(); } + /** + * Returns the timestamp for the last Midnight + * + * @return last midnight timestamp in milliseconds + */ + static long lastMidnight() { + return nextMidnight() - 86400000; + } + /** * The static runner class that loops through all loggers. */ @@ -255,7 +265,7 @@ public class Logging extends LogFactory { } try { - wait(250); + wait(333); } catch (InterruptedException ix) { break; }