diff --git a/src/helma/framework/core/Application.java b/src/helma/framework/core/Application.java index 8450c3c7..361865e1 100644 --- a/src/helma/framework/core/Application.java +++ b/src/helma/framework/core/Application.java @@ -29,6 +29,9 @@ import java.lang.reflect.*; import java.net.MalformedURLException; import java.rmi.*; import java.util.*; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; + /** * The central class of a Helma application. This class keeps a pool of so-called @@ -46,13 +49,13 @@ public final class Application implements IPathElement, Runnable { // properties and db-properties SystemProperties dbProps; - // home, app and data directories + // Helma server home directory File home; - // home, app and data directories + // application directory File appDir; - // home, app and data directories + // embedded db directory File dbDir; // this application's node manager @@ -96,11 +99,13 @@ public final class Application implements IPathElement, Runnable { // Map of requesttrans -> active requestevaluators Hashtable activeRequests; - // Two logs for each application: events and accesses - Logger eventLog; + // Two logs for each application + Log eventLog; + Log accessLog; - // Two logs for each application: events and accesses - Logger accessLog; + // Symbolic names for each log + String eventLogName; + String accessLogName; // A transient node that is shared among all evaluators protected INode cachenode; @@ -229,6 +234,10 @@ public final class Application implements IPathElement, Runnable { props = new SystemProperties(propfile.getAbsolutePath(), sysProps); + // get log names + accessLogName = props.getProperty("accessLog", "helma."+name+".access"); + eventLogName = props.getProperty("eventLog", "helma."+name+".event"); + // create app-level db sources File dbpropfile = new File(appDir, "db.properties"); @@ -266,6 +275,16 @@ public final class Application implements IPathElement, Runnable { */ public void init() throws DatabaseException, ScriptingException, MalformedURLException { + + // create and init type mananger + typemgr = new TypeManager(this); + typemgr.createPrototypes(); + + // set the context classloader. Note that this must be done before + // using the logging framework so that a new LogFactory gets created + // for this app. + Thread.currentThread().setContextClassLoader(typemgr.loader); + if (Server.getServer() != null) { Vector extensions = Server.getServer().getExtensions(); @@ -286,10 +305,6 @@ public final class Application implements IPathElement, Runnable { loadSessionData(null); } - // create and init type mananger - typemgr = new TypeManager(this); - typemgr.createPrototypes(); - // create and init evaluator/thread lists freeThreads = new Stack(); allThreads = new Vector(); @@ -317,11 +332,14 @@ public final class Application implements IPathElement, Runnable { activeCronJobs = new WeakHashMap(); customCronJobs = new Hashtable(); + // create the skin manager skinmgr = new SkinManager(this); rootMapping = getDbMapping("root"); userMapping = getDbMapping("user"); + // The whole user/userroot handling is basically old + // ugly obsolete crap. Don't bother. SystemProperties p = new SystemProperties(); String usernameField = userMapping.getNameField(); @@ -334,7 +352,12 @@ public final class Application implements IPathElement, Runnable { userRootMapping = new DbMapping(this, "__userroot__", p); userRootMapping.update(); + // create the node manager nmgr = new NodeManager(this, dbDir.getAbsolutePath(), props); + + // reset the classloader to the parent/system/server classloader. + Thread.currentThread().setContextClassLoader(typemgr.loader.getParent()); + } /** @@ -399,14 +422,6 @@ public final class Application implements IPathElement, Runnable { storeSessionData(null); } - // stop logs if they exist - if (eventLog != null) { - eventLog.close(); - } - - if (accessLog != null) { - accessLog.close(); - } } /** @@ -1266,52 +1281,43 @@ public final class Application implements IPathElement, Runnable { //////////////////////////////////////////////////////////////////////// /** - * Get the logger object for logging generic events + * Log a generic application event */ public void logEvent(String msg) { - if ((eventLog == null) || eventLog.isClosed()) { - eventLog = getLogger("event"); + if (eventLog == null) { + eventLog = getLogger(eventLogName); } - eventLog.log(msg); + eventLog.info(msg); } /** - * Get the logger object for logging access events + * Log an application access */ public void logAccess(String msg) { - if ((accessLog == null) || accessLog.isClosed()) { - accessLog = getLogger("access"); + if (accessLog == null) { + accessLog = getLogger(accessLogName); } - accessLog.log(msg); + accessLog.info(msg); } /** * Get a logger object to log events for this application. */ - public Logger getLogger(String logname) { - Logger log = null; - String logDir = props.getProperty("logdir", "log"); + protected Log getLogger(String logname) { + String logdir = props.getProperty("logdir"); - // allow log to be redirected to System.out by setting logdir to "console" - if ("console".equalsIgnoreCase(logDir)) { - return new Logger(System.out); + if ("console".equals(logdir) || "console".equals(logname)) { + return Logging.getConsoleLog(); + } else { + + // set up helma.logdir system property in case we're using it + File dir = new File(logdir); + System.setProperty("helma.logdir", dir.getAbsolutePath()); + + return LogFactory.getLog(logname); } - - File helper = new File(logDir); - - // construct the fully qualified log name - String fullLogname = name + "_" + logname; - - if ((home != null) && !helper.isAbsolute()) { - helper = new File(home, logDir); - } - - logDir = helper.getAbsolutePath(); - log = Logger.getLogger(logDir, fullLogname); - - return log; } /** diff --git a/src/helma/framework/core/ApplicationBean.java b/src/helma/framework/core/ApplicationBean.java index b1ec2bcd..83d21f81 100644 --- a/src/helma/framework/core/ApplicationBean.java +++ b/src/helma/framework/core/ApplicationBean.java @@ -72,7 +72,7 @@ public class ApplicationBean implements Serializable { public void log(String logname, Object msg) { String str = (msg == null) ? "null" : msg.toString(); - app.getLogger(logname).log(str); + app.getLogger(logname).info(str); } /** @@ -98,7 +98,7 @@ public class ApplicationBean implements Serializable { if (app.debug()) { String str = (msg == null) ? "null" : msg.toString(); - app.getLogger(logname).log(str); + app.getLogger(logname).info(str); } } diff --git a/src/helma/main/ApplicationManager.java b/src/helma/main/ApplicationManager.java index b08481f0..17635b9a 100644 --- a/src/helma/main/ApplicationManager.java +++ b/src/helma/main/ApplicationManager.java @@ -19,6 +19,8 @@ package helma.main; import helma.framework.core.*; import helma.util.StringUtils; import helma.util.SystemProperties; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; import org.apache.xmlrpc.XmlRpcHandler; import org.mortbay.http.*; import org.mortbay.http.handler.*; @@ -97,7 +99,7 @@ public class ApplicationManager implements XmlRpcHandler { } } } catch (Exception mx) { - Server.getLogger().log("Error checking applications: " + mx); + Server.getLogger().error("Error checking applications: " + mx); } lastModified = System.currentTimeMillis(); @@ -161,7 +163,7 @@ public class ApplicationManager implements XmlRpcHandler { lastModified = System.currentTimeMillis(); } catch (Exception mx) { - Server.getLogger().log("Error starting applications: " + mx); + Server.getLogger().error("Error starting applications: " + mx); mx.printStackTrace(); } } @@ -322,7 +324,7 @@ public class ApplicationManager implements XmlRpcHandler { void start() { - Server.getLogger().log("Building application " + appName); + Server.getLogger().info("Building application " + appName); try { // create the application instance @@ -336,13 +338,13 @@ public class ApplicationManager implements XmlRpcHandler { app.init(); app.start(); } catch (Exception x) { - Server.getLogger().log("Error creating application " + appName + ": " + x); + Server.getLogger().error("Error creating application " + appName + ": " + x); x.printStackTrace(); } } void stop() { - Server.getLogger().log("Stopping application " + appName); + Server.getLogger().info("Stopping application " + appName); // unbind application unbind(); @@ -350,9 +352,9 @@ public class ApplicationManager implements XmlRpcHandler { // stop application try { app.stop(); - Server.getLogger().log("Stopped application " + appName); + Server.getLogger().info("Stopped application " + appName); } catch (Exception x) { - Server.getLogger().log("Couldn't stop app: " + x); + Server.getLogger().error("Couldn't stop app: " + x); } descriptors.remove(appName); @@ -361,7 +363,7 @@ public class ApplicationManager implements XmlRpcHandler { void bind() { try { - Server.getLogger().log("Binding application " + appName); + Server.getLogger().info("Binding application " + appName); // bind to RMI server if (port > 0) { @@ -380,7 +382,7 @@ public class ApplicationManager implements XmlRpcHandler { if (encode) { // FIXME: ContentEncodingHandler is broken/removed in Jetty 4.2 // context.addHandler(new ContentEncodingHandler()); - Server.getLogger().log("Warning: disabling response encoding for Jetty 4.2 compatibility"); + Server.getLogger().warn("Warning: disabling response encoding for Jetty 4.2 compatibility"); } ServletHandler handler = new ServletHandler(); @@ -413,7 +415,7 @@ public class ApplicationManager implements XmlRpcHandler { protectedContent = new File(server.getHopHome(), protectedStaticDir); } context.setResourceBase(protectedContent.getAbsolutePath()); - Server.getLogger().log("Serving protected static from " + + Server.getLogger().info("Serving protected static from " + protectedContent.getAbsolutePath()); context.addHandler(new ResourceHandler()); } @@ -428,9 +430,9 @@ public class ApplicationManager implements XmlRpcHandler { staticContent = new File(server.getHopHome(), staticDir); } - Server.getLogger().log("Serving static from " + + Server.getLogger().info("Serving static from " + staticContent.getAbsolutePath()); - Server.getLogger().log("Mounting static at " + + Server.getLogger().info("Mounting static at " + staticMountpoint); context = server.http.addContext(staticMountpoint); @@ -450,13 +452,13 @@ public class ApplicationManager implements XmlRpcHandler { xmlrpcHandlers.put(xmlrpcHandlerName, app); // app.start(); } catch (Exception x) { - Server.getLogger().log("Couldn't bind app: " + x); + Server.getLogger().error("Couldn't bind app: " + x); x.printStackTrace(); } } void unbind() { - Server.getLogger().log("Unbinding application " + appName); + Server.getLogger().info("Unbinding application " + appName); try { // unbind from RMI server @@ -486,10 +488,14 @@ public class ApplicationManager implements XmlRpcHandler { // unregister as XML-RPC handler xmlrpcHandlers.remove(xmlrpcHandlerName); } catch (Exception x) { - Server.getLogger().log("Couldn't unbind app: " + x); + Server.getLogger().error("Couldn't unbind app: " + x); } } + public String toString() { + return "[AppDescriptor "+app+"]"; + } + } } diff --git a/src/helma/main/HelmaShutdownHook.java b/src/helma/main/HelmaShutdownHook.java index 5a4c1576..cb15d0be 100644 --- a/src/helma/main/HelmaShutdownHook.java +++ b/src/helma/main/HelmaShutdownHook.java @@ -16,8 +16,9 @@ package helma.main; -import helma.util.Logger; +import helma.util.*; import java.util.List; +import org.apache.commons.logging.LogFactory; /** * ShutdownHook that shuts down all running Helma applications on exit. @@ -40,20 +41,12 @@ public class HelmaShutdownHook extends Thread { public void run() { System.err.println("Shutting down Helma - please stand by..."); - Logger logger = Server.getLogger(); - - if (logger != null) { - logger.log("Shutting down Helma"); - } + LogFactory.getLog("helma.server").info("Shutting down Helma"); appmgr.stopAll(); - List loggers = Logger.getLoggers(); - int l = loggers.size(); - - for (int i = 0; i < l; i++) - ((Logger) loggers.get(i)).close(); - - Logger.wakeup(); - } + if (LogFactory.getFactory() instanceof Logging) { + Logging.shutdown(); + } + } } diff --git a/src/helma/main/HelmaSocketFactory.java b/src/helma/main/HelmaSocketFactory.java index 7968d61a..dbc58b04 100644 --- a/src/helma/main/HelmaSocketFactory.java +++ b/src/helma/main/HelmaSocketFactory.java @@ -45,7 +45,7 @@ public class HelmaSocketFactory extends RMISocketFactory { try { filter.addAddress(address); } catch (IOException x) { - Server.getLogger().log("Could not add " + address + + Server.getLogger().error("Could not add " + address + " to Socket Filter: invalid address."); } } diff --git a/src/helma/main/Server.java b/src/helma/main/Server.java index ca1f2792..1ba1b995 100644 --- a/src/helma/main/Server.java +++ b/src/helma/main/Server.java @@ -21,10 +21,15 @@ import helma.framework.*; import helma.framework.core.*; import helma.objectmodel.db.DbSource; import helma.util.*; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; import org.apache.xmlrpc.*; import org.mortbay.http.*; import org.mortbay.http.ajp.*; -import org.mortbay.util.*; +import org.mortbay.util.InetAddrPort; +import org.mortbay.util.LogSink; +import org.mortbay.util.MultiException; +import org.mortbay.util.Frame; import java.io.*; import java.net.*; import java.rmi.registry.*; @@ -47,10 +52,14 @@ public class Server implements IPathElement, Runnable { protected static File hopHome = null; // our logger - private static Logger logger; + private static Log logger; + // are we using helma.util.Logging? + private static boolean helmaLogging; + + // server start time public final long starttime; - // if true we only accept RMI and XML-RPC connections from + // if true we only accept RMI and XML-RPC connections from // explicitly listed hosts. public boolean paranoid; private ApplicationManager appManager; @@ -143,6 +152,13 @@ public class Server implements IPathElement, Runnable { // create system properties sysProps = new SystemProperties(propfile); + // set the log factory property + String logFactory = sysProps.getProperty("loggerFactory", + "helma.util.Logging"); + + helmaLogging = "helma.util.Logging".equals(logFactory); + System.setProperty("org.apache.commons.logging.LogFactory", logFactory); + // check if there's a property setting for those ports not specified via command line if ((websrvPort == null) && (sysProps.getProperty("webPort") != null)) { try { @@ -243,7 +259,7 @@ public class Server implements IPathElement, Runnable { try { hopHome = hopHome.getCanonicalFile(); } catch (IOException iox) { - System.err.println("Error calling getCanonicalFile() on hopHome: " + iox); + hopHome = hopHome.getAbsoluteFile(); } // set the current working directory to the helma home dir. @@ -254,23 +270,23 @@ public class Server implements IPathElement, Runnable { System.setProperty("user.dir", hopHome.getPath()); // from now on it's safe to call getLogger() because hopHome is set up + getLogger(); + String startMessage = "Starting Helma " + version + " on Java " + System.getProperty("java.version"); - getLogger().log(startMessage); + logger.info(startMessage); // also print a msg to System.out System.out.println(startMessage); - getLogger().log("propfile = " + propfile); - getLogger().log("hopHome = " + hopHome); + logger.info("Setting Helma Home to " + hopHome); File helper = new File(hopHome, "db.properties"); dbPropfile = helper.getAbsolutePath(); dbProps = new SystemProperties(dbPropfile); DbSource.setDefaultProps(dbProps); - getLogger().log("dbPropfile = " + dbPropfile); appsPropfile = sysProps.getProperty("appsPropFile"); @@ -282,7 +298,6 @@ public class Server implements IPathElement, Runnable { appsPropfile = helper.getAbsolutePath(); appsProps = new SystemProperties(appsPropfile); - getLogger().log("appsPropfile = " + appsPropfile); paranoid = "true".equalsIgnoreCase(sysProps.getProperty("paranoid")); @@ -298,9 +313,9 @@ public class Server implements IPathElement, Runnable { TimeZone.setDefault(TimeZone.getTimeZone(timezone)); } - getLogger().log("Locale = " + Locale.getDefault()); - getLogger().log("TimeZone = " + - TimeZone.getDefault().getDisplayName(Locale.getDefault())); + // logger.debug("Locale = " + Locale.getDefault()); + // logger.debug("TimeZone = " + + // TimeZone.getDefault().getDisplayName(Locale.getDefault())); dbSources = new Hashtable(); @@ -320,9 +335,9 @@ public class Server implements IPathElement, Runnable { ext.init(this); extensions.add(ext); - getLogger().log("Loaded: " + extClassName); + logger.info("Loaded: " + extClassName); } catch (Throwable e) { - getLogger().log("Error loading extension " + extClassName + ": " + e.toString()); + logger.error("Error loading extension " + extClassName + ": " + e.toString()); } } } @@ -379,8 +394,8 @@ public class Server implements IPathElement, Runnable { // disable Jetty logging FIXME: seems to be a jetty bug; as soon // as the logging is disabled, the more is logged - Log.instance().disableLog(); - Log.instance().add(new LogSink() { + org.mortbay.util.Log.instance().disableLog(); + org.mortbay.util.Log.instance().add(new LogSink() { public String getOptions() { return null; } @@ -434,7 +449,7 @@ public class Server implements IPathElement, Runnable { } ajp13.setRemoteServers(jkallowarr); - getLogger().log("Starting AJP13-Listener on port " + (ajp13Port)); + logger.info("Starting AJP13-Listener on port " + (ajp13Port)); } if (xmlrpcPort != null) { @@ -463,7 +478,7 @@ public class Server implements IPathElement, Runnable { } } - getLogger().log("Starting XML-RPC server on port " + (xmlrpcPort)); + logger.info("Starting XML-RPC server on port " + (xmlrpcPort)); } if (rmiPort != null) { @@ -484,7 +499,7 @@ public class Server implements IPathElement, Runnable { RMISocketFactory.setSocketFactory(factory); } - getLogger().log("Starting RMI server on port " + rmiPort); + logger.info("Starting RMI server on port " + rmiPort); LocateRegistry.createRegistry(rmiPort.getPort()); // create application manager which binds to the given RMI port @@ -501,7 +516,7 @@ public class Server implements IPathElement, Runnable { // add shutdown hook to close running apps and servers on exit Runtime.getRuntime().addShutdownHook(new HelmaShutdownHook(appManager)); } catch (Exception gx) { - getLogger().log("Error initializing embedded database: " + gx); + logger.error("Error initializing embedded database: " + gx); gx.printStackTrace(); return; @@ -517,10 +532,10 @@ public class Server implements IPathElement, Runnable { .newInstance(); System.setSecurityManager(secMan); - getLogger().log("Setting security manager to " + secManClass); + logger.info("Setting security manager to " + secManClass); } } catch (Exception x) { - getLogger().log("Error setting security manager: " + x); + logger.error("Error setting security manager: " + x); } // start applications @@ -531,7 +546,7 @@ public class Server implements IPathElement, Runnable { try { http.start(); } catch (MultiException m) { - getLogger().log("Error starting embedded web server: " + m); + logger.error("Error starting embedded web server: " + m); } } @@ -539,7 +554,7 @@ public class Server implements IPathElement, Runnable { try { ajp13.start(); } catch (Exception m) { - getLogger().log("Error starting AJP13 listener: " + m); + logger.error("Error starting AJP13 listener: " + m); } } @@ -552,7 +567,7 @@ public class Server implements IPathElement, Runnable { try { appManager.checkForChanges(); } catch (Exception x) { - getLogger().log("Caught in app manager loop: " + x); + logger.warn("Caught in app manager loop: " + x); } } } @@ -574,24 +589,25 @@ public class Server implements IPathElement, Runnable { /** * Get a logger to use for output in this server. */ - public static Logger getLogger() { + public static Log getLogger() { if (logger == null) { + // get the logDir property String logDir = sysProps.getProperty("logdir", "log"); - if ("console".equalsIgnoreCase(logDir)) { - logger = new Logger(System.out); + if ("console".equals(logDir)) { + logger = Logging.getConsoleLog(); } else { - File helper = new File(logDir); - - if ((hopHome != null) && !helper.isAbsolute()) { - helper = new File(hopHome, logDir); + if (helmaLogging) { + // set up helma.logdir system property + File dir = new File(logDir); + if (!dir.isAbsolute()) { + dir = new File(hopHome, logDir); + } + System.setProperty("helma.logdir", dir.getAbsolutePath()); } - - logDir = helper.getAbsolutePath(); - logger = Logger.getLogger(logDir, "hop"); + logger = LogFactory.getLog("helma.server"); } } - return logger; } diff --git a/src/helma/util/FileLogger.java b/src/helma/util/FileLogger.java new file mode 100644 index 00000000..8b7731d1 --- /dev/null +++ b/src/helma/util/FileLogger.java @@ -0,0 +1,291 @@ +/* + * Helma License Notice + * + * The contents of this file are subject to the Helma License + * Version 2.0 (the "License"). You may not use this file except in + * compliance with the License. A copy of the License is available at + * http://adele.helma.org/download/helma/license.txt + * + * Copyright 1998-2003 Helma Software. All Rights Reserved. + * + * $RCSfile$ + * $Author$ + * $Revision$ + * $Date$ + */ + +package helma.util; + +import org.apache.commons.logging.Log; + +import java.io.*; +import java.text.*; +import java.util.*; +import java.util.zip.GZIPOutputStream; + +/** + * An extended Logger that writes to a file and rotates files each midnight. + * + * Note that the methods in this class that operate on the file writer + * (write(), openFile(), closeFile()) are expected to be called by just one + * thread (the static runner thread in helma.util.Logging) which is why they + * are not synchronized, although they're not threadsafe. + * + * @author Stefan Pollack + * @author Daniel Ruthardt + * @author Hannes Wallnoefer + */ +public class FileLogger extends Logger implements Log { + + // fields used for logging to files + private String name; + private File logdir; + private File logfile; + + // number format for log file rotation + 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. + */ + protected FileLogger(String directory, String name) { + this.name = name; + logdir = new File(directory); + logfile = new File(logdir, name + ".log"); + + if (!logdir.exists()) { + logdir.mkdirs(); + } + + openFile(); + + // 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. + */ + private void openFile() { + try { + if (logfile.exists() && (logfile.lastModified() < lastMidnight())) { + // rotate if a log file exists and is NOT from today + rotateLogFile(); + } else { + // create a new log file, appending to an existing file + writer = new PrintWriter(new FileWriter(logfile.getAbsolutePath(), true), + false); + } + } catch (IOException iox) { + System.err.println("Error creating log " + name + ": " + iox); + } + } + + /** + * Actually closes the file writer of a log. + */ + void closeFile() { + if (writer != null) { + try { + writer.close(); + } catch (Exception ignore) { + } finally { + writer = null; + } + } + } + + /** + * Return true if we have a file writer open + */ + boolean isOpen() { + return writer != null; + } + + /** + * This is called by the runner thread to perform actual output. + */ + 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(); + } + } + } + + + /** + * Rotate log files, closing, renaming and gzipping the old file and + * start a new one. + */ + protected void rotateLogFile() throws IOException { + // if the logger is not file based do nothing. + if (logfile == null) { + return; + } + + if (writer != null) { + try { + writer.close(); + } catch (Exception ignore) { + } + } + + // only backup/rotate if the log file is not empty, + if (logfile.exists() && (logfile.length() > 0)) { + String today = aformat.format(new Date()); + int ct = 0; + File archive = null; + + // first append just the date + String archname = name + "-" + today + ".log.gz"; + + while ((archive == null) || archive.exists()) { + archive = new File(logdir, archname); + + // for the next try we append a counter + String archidx = (ct > 999) ? Integer.toString(ct) : nformat.format(++ct); + + archname = name + "-" + today + "-" + archidx + ".log.gz"; + } + + if (logfile.renameTo(archive)) { + (new GZipper(archive)).start(); + } else { + System.err.println("Error rotating log file " + canonicalName + + ". Old file will possibly be overwritten!"); + } + } + + writer = new PrintWriter(new FileWriter(logfile), false); + } + + /** + * Return a string representation of this Logger + */ + public String toString() { + return "FileLogger[" + name + "]"; + } + + /** + * Return an object which identifies this logger. + */ + 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; + } + + public void error(Object parm1) { + System.err.println("Error: "+parm1); + info(parm1); + } + + public void error(Object parm1, Throwable parm2) { + System.err.println("Error: "+parm1); + System.err.println("See "+logfile+" for stack trace"); + info(parm1, parm2); + } + + public void fatal(Object parm1) { + System.err.println("Fatal error: "+parm1); + info(parm1); + } + + public void fatal(Object parm1, Throwable parm2) { + System.err.println("Fatal error: "+parm1); + System.err.println("See "+logfile+" for stack trace"); + info(parm1, parm2); + } + + /** + * a Thread class that zips up a file, filename will stay the same. + */ + class GZipper extends Thread { + File file; + File temp; + + public GZipper(File file) { + this.file = file; + this.temp = new File(file.getAbsolutePath() + ".tmp"); + } + + public void run() { + try { + GZIPOutputStream zip = new GZIPOutputStream(new FileOutputStream(temp)); + BufferedInputStream in = new BufferedInputStream(new FileInputStream(file)); + byte[] b = new byte[1024]; + int len = 0; + + while ((len = in.read(b, 0, 1024)) != -1) { + zip.write(b, 0, len); + } + + zip.close(); + in.close(); + file.delete(); + temp.renameTo(file); + } catch (Exception e) { + System.err.println(e.toString()); + } + } + } + +} diff --git a/src/helma/util/Logger.java b/src/helma/util/Logger.java index a4a7d0ca..b345ee4e 100644 --- a/src/helma/util/Logger.java +++ b/src/helma/util/Logger.java @@ -16,287 +16,46 @@ package helma.util; +import org.apache.commons.logging.Log; + import java.io.*; import java.text.*; import java.util.*; -import java.util.zip.GZIPOutputStream; /** - * Utility class for asynchronous logging. + * A simple logger that writes to a PrintStream such as System.out. */ -public final class Logger { - // we use one static thread for all Loggers - static Runner runner; - - // the list of active loggers - static ArrayList loggers; - - // hash map of loggers - static HashMap loggerMap; - - // fields for date rendering and caching - static DateFormat dformat = new SimpleDateFormat("[yyyy/MM/dd HH:mm] "); - static long dateLastRendered; - static String dateCache; +public class Logger implements Log { // buffer for log items - private List entries; + List entries; - // fields used for logging to files - private String filename; - private File logdir; - private File logfile; - private PrintWriter writer; + // Writer for log output + PrintWriter writer; // the canonical name for this logger String canonicalName; - // used when logging to a PrintStream such as System.out - private PrintStream out = null; + // fields for date rendering and caching + static DateFormat dformat = new SimpleDateFormat("[yyyy/MM/dd HH:mm:ss] "); + static long dateLastRendered; + static String dateCache; - // flag to tell runner thread if this log should be closed/discarded - boolean closed = false; - - // number format for log file rotation - DecimalFormat nformat = new DecimalFormat("000"); - DateFormat aformat = new SimpleDateFormat("yyyy-MM-dd"); + /** + * zero argument constructor, only here for FileLogger subclass + */ + Logger() {} /** * Create a logger for a PrintStream, such as System.out. */ - public Logger(PrintStream out) { - this.out = out; + protected Logger(PrintStream out) { + 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()); - - // register this instance with static logger list - start(this); - } - - /** - * Create a file logger. The actual file names do have numbers appended and are - * rotated every x bytes. - */ - private Logger(String dirname, String filename) { - this.filename = filename; - logdir = new File(dirname); - logfile = new File(logdir, filename + ".log"); - - try { - canonicalName = logfile.getCanonicalPath(); - } catch (IOException iox) { - canonicalName = logfile.getAbsolutePath(); - } - - if (!logdir.exists()) { - logdir.mkdirs(); - } - - try { - if (logfile.exists() && (logfile.lastModified() < lastMidnight())) { - // rotate if a log file exists and is NOT from today - rotateLogFile(); - } else { - // create a new log file, append to an existing file - writer = new PrintWriter(new FileWriter(logfile.getAbsolutePath(), true), - false); - } - } catch (IOException iox) { - System.err.println("Error creating log " + canonicalName + ": " + iox); - } - - // 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()); - - // register this instance with static logger list - start(this); - } - - /** - * Get a logger with a symbolic file name within a directory. - */ - public static synchronized Logger getLogger(String dirname, String filename) { - if ((filename == null) || (dirname == null)) { - throw new RuntimeException("Logger can't use null as file or directory name"); - } - - File file = new File(dirname, filename + ".log"); - Logger log = null; - - if (loggerMap != null) { - try { - log = (Logger) loggerMap.get(file.getCanonicalPath()); - } catch (IOException iox) { - log = (Logger) loggerMap.get(file.getAbsolutePath()); - } - } - - if ((log == null) || log.isClosed()) { - log = new Logger(dirname, filename); - } - - return log; - } - - /** - * Append a message to the log. - */ - public void log(String msg) { - // if we are closed, drop message without further notice - if (closed) { - return; - } - - // it's enough to render the date every 5 seconds - if ((System.currentTimeMillis() - 5000) > dateLastRendered) { - renderDate(); - } - - entries.add(dateCache + msg); - } - - private static synchronized void renderDate() { - dateLastRendered = System.currentTimeMillis(); - dateCache = dformat.format(new Date()); - } - - /** - * Return an object which identifies this logger. - */ - public String getCanonicalName() { - return canonicalName; - } - - /** - * Get the list of unwritten entries - */ - public List getEntries() { - return entries; - } - - /** - * This is called by the runner thread to perform actual output. - */ - public void write() { - if (entries.isEmpty()) { - return; - } - - try { - int l = entries.size(); - - // check if writing to printstream or file - if (out != null) { - for (int i = 0; i < l; i++) { - String entry = (String) entries.get(0); - - entries.remove(0); - out.println(entry); - } - } else { - if ((writer == null) || !logfile.exists() || !logfile.canWrite()) { - // rotate the log file if we can't write to it - rotateLogFile(); - } - - for (int i = 0; i < l; i++) { - String entry = (String) entries.get(0); - - entries.remove(0); - writer.println(entry); - } - - writer.flush(); - } - } catch (Exception x) { - int e = entries.size(); - - if (e > 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 " + e + " log entries."); - entries.clear(); - } - } - } - - /** - * Rotate log files, closing, renaming and gzipping the old file and - * start a new one. - */ - private void rotateLogFile() throws IOException { - // if the logger is not file based do nothing. - if (logfile == null) { - return; - } - - if (writer != null) { - try { - writer.close(); - } catch (Exception ignore) { - } - } - - // only backup/rotate if the log file is not empty, - if (logfile.exists() && (logfile.length() > 0)) { - String today = aformat.format(new Date()); - int ct = 0; - File archive = null; - - // first append just the date - String archname = filename + "-" + today + ".log.gz"; - - while ((archive == null) || archive.exists()) { - archive = new File(logdir, archname); - - // for the next try we append a counter - String archidx = (ct > 999) ? Integer.toString(ct) : nformat.format(++ct); - - archname = filename + "-" + today + "-" + archidx + ".log.gz"; - } - - if (logfile.renameTo(archive)) { - (new GZipper(archive)).start(); - } else { - System.err.println("Error rotating log file " + canonicalName + - ". Old file will possibly be overwritten!"); - } - } - - writer = new PrintWriter(new FileWriter(logfile), false); - } - - /** - * Tell whether this log is closed. - */ - public boolean isClosed() { - return closed; - } - - /** - * Tells a log to close down. Only the flag is set, the actual closing is - * done by the runner thread next time it comes around. - */ - public void close() { - this.closed = true; - } - - /** - * Actually closes the file writer of a log. - */ - void closeFiles() { - if (writer != null) { - try { - writer.close(); - } catch (Exception ignore) { - } - } } /** @@ -307,187 +66,134 @@ public final class Logger { } /** - * Add a log to the list of logs and - * create and start the runner thread if necessary. + * Return an object which identifies this logger. */ - static synchronized void start(Logger log) { - if (loggers == null) { - loggers = new ArrayList(); - } - - if (loggerMap == null) { - loggerMap = new HashMap(); - } - - loggers.add(log); - loggerMap.put(log.canonicalName, log); - - if ((runner == null) || !runner.isAlive()) { - runner = new Runner(); - runner.start(); - } + public String getCanonicalName() { + return canonicalName; } /** - * Return a list of all active Loggers + * Append a message to the log. */ - public static List getLoggers() { - if (loggers == null) { - return null; + public void log(String msg) { + // it's enough to render the date every second + if ((System.currentTimeMillis() - 1000) > dateLastRendered) { + renderDate(); } - return (List) loggers.clone(); + entries.add(dateCache + msg); } /** - * Notify the runner thread that it should wake up and run. + * This is called by the runner thread to perform actual output. */ - public static void wakeup() { - if (runner != null) { - runner.wakeup(); + void write() { + if (entries.isEmpty()) { + return; } - } - private static void rotateAllLogs() { - int nloggers = loggers.size(); + try { + int l = entries.size(); - for (int i = nloggers - 1; i >= 0; i--) { - Logger log = (Logger) loggers.get(i); + for (int i = 0; i < l; i++) { + String entry = (String) entries.remove(0); + writer.println(entry); + } - try { - log.rotateLogFile(); - } catch (IOException io) { - System.err.println("Error rotating log " + log.getCanonicalName() + ": " + - io.toString()); + 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(); } } } - /** - * - * - * @return ... - */ - public static long nextMidnight() { - Calendar cal = Calendar.getInstance(); - - cal.set(Calendar.DATE, 1 + cal.get(Calendar.DATE)); - cal.set(Calendar.HOUR_OF_DAY, 0); - cal.set(Calendar.MINUTE, 0); - cal.set(Calendar.SECOND, 1); - - // for testing, rotate the logs every minute: - // cal.set (Calendar.MINUTE, 1 + cal.get(Calendar.MINUTE)); - return cal.getTime().getTime(); + // Pre-render the date to use for log messages. Called every 2 seconds or so. + static synchronized void renderDate() { + dateLastRendered = System.currentTimeMillis(); + dateCache = dformat.format(new Date()); } - /** - * - * - * @return ... - */ - public static long lastMidnight() { - return nextMidnight() - 86400000; + // methods to implement org.apache.commons.logging.Log interface + + public boolean isDebugEnabled() { + return true; } - /** - * test main method - */ - public static void main(String[] args) { - Logger log = new Logger(".", "testlog"); - long start = System.currentTimeMillis(); - - for (int i = 0; i < 1000; i++) { - log.log("test log entry " + i); - - try { - Thread.sleep(100); - } catch (InterruptedException ie) { - } - } - - log.log("done: " + (System.currentTimeMillis() - start)); - System.err.println(System.currentTimeMillis() - start); - log.close(); + public boolean isErrorEnabled() { + return true; } - /** - * The static runner class that loops through all loggers. - */ - static class Runner extends Thread { - public synchronized void run() { - long nextMidnight = nextMidnight(); - - while ((runner == this) && !isInterrupted()) { - if (nextMidnight < System.currentTimeMillis()) { - rotateAllLogs(); - nextMidnight = nextMidnight(); - } - - int nloggers = loggers.size(); - - for (int i = nloggers - 1; i >= 0; i--) { - try { - Logger log = (Logger) loggers.get(i); - - log.write(); - - if (log.closed && log.entries.isEmpty()) { - loggers.remove(log); - log.closeFiles(); - } - } catch (Exception x) { - System.err.println("Error in Logger main loop: " + x); - } - } - - // if there are no active logs, exit logger thread - if (loggers.size() == 0) { - return; - } - - try { - wait(250); - } catch (InterruptedException ix) { - } - } - } - - public synchronized void wakeup() { - notifyAll(); - } + public boolean isFatalEnabled() { + return true; } - /** - * a Thread class that zips up a file, filename will stay the same. - */ - class GZipper extends Thread { - File file; - File temp; - - public GZipper(File file) { - this.file = file; - this.temp = new File(file.getAbsolutePath() + ".tmp"); - } - - public void run() { - try { - GZIPOutputStream zip = new GZIPOutputStream(new FileOutputStream(temp)); - BufferedInputStream in = new BufferedInputStream(new FileInputStream(file)); - byte[] b = new byte[1024]; - int len = 0; - - while ((len = in.read(b, 0, 1024)) != -1) { - zip.write(b, 0, len); - } - - zip.close(); - in.close(); - file.delete(); - temp.renameTo(file); - } catch (Exception e) { - System.err.println(e.toString()); - } - } + public boolean isInfoEnabled() { + return true; } + + public boolean isTraceEnabled() { + return true; + } + + public boolean isWarnEnabled() { + return true; + } + + public void trace(Object parm1) { + info(parm1); + } + + public void trace(Object parm1, Throwable parm2) { + info(parm1, parm2); + } + + public void debug(Object parm1) { + info(parm1); + } + + public void debug(Object parm1, Throwable parm2) { + info(parm1, parm2); + } + + public void info(Object parm1) { + log(parm1.toString()); + } + + public void info(Object parm1, Throwable parm2) { + log(parm1.toString() + "\n" + parm2.getStackTrace().toString()); + } + + public void warn(Object parm1) { + info(parm1); + } + + public void warn(Object parm1, Throwable parm2) { + info(parm1, parm2); + } + + public void error(Object parm1) { + info(parm1); + } + + public void error(Object parm1, Throwable parm2) { + info(parm1, parm2); + } + + public void fatal(Object parm1) { + info(parm1); + } + + public void fatal(Object parm1, Throwable parm2) { + info(parm1, parm2); + } + } diff --git a/src/helma/util/Logging.java b/src/helma/util/Logging.java new file mode 100644 index 00000000..0ebbc315 --- /dev/null +++ b/src/helma/util/Logging.java @@ -0,0 +1,272 @@ +/* + * Helma License Notice + * + * The contents of this file are subject to the Helma License + * Version 2.0 (the "License"). You may not use this file except in + * compliance with the License. A copy of the License is available at + * http://adele.helma.org/download/helma/license.txt + * + * Copyright 1998-2003 Helma Software. All Rights Reserved. + * + * $RCSfile$ + * $Author$ + * $Revision$ + * $Date$ + */ + +package helma.util; + +import org.apache.commons.logging.*; +import java.io.*; +import java.text.*; +import java.util.*; + +/** + * Implementation of Jakarta Commons LogFactory that supports both + * simple console logging and logging to files that are rotated and + * gzipped each night. + * + * @author Stefan Pollack + * @author Daniel Ruthardt + * @author Hannes Wallnoefer + */ +public class Logging extends LogFactory { + + // we use one static thread for all Loggers + public static Runner runner; + + // the list of active loggers + static ArrayList loggers = new ArrayList(); + + // hash map of loggers + static HashMap loggerMap = new HashMap(); + + // log directory + String logdir; + + // static console logger + static Logger consoleLog = new Logger(System.out); + + /** + * Constructs a log factory, getting the base logging directory from the + * helma.logdir system property. + */ + public Logging() { + logdir = System.getProperty("helma.logdir"); + } + + /** + * Get a logger for a file name. The log file is created in the + * directory specified by the "log.dir" System property. If the + * logname is "console" a log that writes to System.out is returned. + */ + public Log getInstance(String logname) { + if (logname == null) { + throw new LogConfigurationException("No logname specified!"); + } + if ("event".equals(logname)) + Thread.dumpStack(); + Logger log = null; + + if ("console".equals(logdir)) { + log = consoleLog; + } else { + log = (Logger) loggerMap.get(logname); + + if (log == null) { + log = newLog(logname); + } + } + + if ((runner == null) || !runner.isAlive()) { + runner = new Runner(); + runner.start(); + } + + return log; + } + + /** + * Get a logger to System.out. + */ + public static Log getConsoleLog() { + if ((runner == null) || !runner.isAlive()) { + runner = new Runner(); + runner.start(); + } + + return consoleLog; + } + + + /** + * Add a log to the list of logs and + * create and start the runner thread if necessary. + */ + private synchronized Logger newLog(String logname) { + // check loggerMap again because only now we are synchronized, + // so another thread may have created a log in the meantime. + Logger log = (Logger) loggerMap.get(logname); + + if (log != null) { + return log; + } + + log = new FileLogger(logdir, logname); + + loggerMap.put(logname, log); + loggers.add(log); + + return log; + } + + public synchronized Log getInstance (Class clazz) { + return getInstance(clazz.toString()); + } + + public void setAttribute(String name, Object value) { + if ("logdir".equals(name)) { + // FIXME: make log dir changable at runtime + } + } + + public Object getAttribute(String name) { + if ("logdir".equals(name)) { + return logdir; + } + return null; + } + + public String[] getAttributeNames() { + return new String[] {}; + } + + public void removeAttribute(String parm1) { + // nothing to do + } + + /** + * Flush all logs and shut down. + */ + public void release() { + shutdown(); + } + + public static void shutdown() { + if (runner != null && runner.isAlive()) { + runner.interrupt(); + Thread.yield(); + } + + closeAll(); + } + + static void closeAll() { + + consoleLog.write(); + + int nloggers = loggers.size(); + + for (int i = nloggers - 1; i >= 0; i--) { + FileLogger log = (FileLogger) loggers.get(i); + + log.write(); + log.closeFile(); + } + + loggers.clear(); + loggerMap.clear(); + } + + /** + * Rotate log files on all registered logs + */ + static void rotateLogs() { + int nloggers = loggers.size(); + + for (int i = nloggers - 1; i >= 0; i--) { + FileLogger log = (FileLogger) loggers.get(i); + + try { + log.rotateLogFile(); + } catch (IOException io) { + System.err.println("Error rotating log " + log.getName() + ": " + + io.toString()); + } + } + } + + + /** + * Returns the timestamp for the next Midnight + * + * @return next midnight timestamp in milliseconds + */ + static long nextMidnight() { + Calendar cal = Calendar.getInstance(); + + cal.set(Calendar.DATE, 1 + cal.get(Calendar.DATE)); + cal.set(Calendar.HOUR_OF_DAY, 0); + cal.set(Calendar.MINUTE, 0); + cal.set(Calendar.SECOND, 1); + + // for testing, rotate the logs every minute: + // cal.set (Calendar.MINUTE, 1 + cal.get(Calendar.MINUTE)); + return cal.getTime().getTime(); + } + + + + /** + * The static runner class that loops through all loggers. + */ + static class Runner extends Thread { + + public synchronized void run() { + long nextMidnight = nextMidnight(); + + while ((runner == this) && !isInterrupted()) { + + long now = System.currentTimeMillis(); + + if (nextMidnight < now) { + rotateLogs(); + nextMidnight = nextMidnight(); + } + + // write the stdout console log + consoleLog.write(); + + int nloggers = loggers.size(); + + for (int i = nloggers-1; i >= 0; i--) { + try { + FileLogger log = (FileLogger) loggers.get(i); + + // write out the log entries + log.write(); + + // if log hasn't been used in the last 30 minutes, close it + if (now - log.lastMessage > 1800000) { + log.closeFile(); + } + } catch (Exception x) { + System.err.println("Error in Logger main loop: " + x); + } + } + + try { + wait(250); + } catch (InterruptedException ix) { + return; + } + } + } + + public synchronized void wakeup() { + notifyAll(); + } + } + +} +