From 7a538c560e729c9a0cea97e53a97159e96e9b926 Mon Sep 17 00:00:00 2001 From: Aron Roberts Date: Mon, 27 Sep 2010 19:26:58 +0000 Subject: [PATCH] CSPACE-2950: More ad-hoc changes to performance logging with the goal of mere adequacy for 1.0 beta work. Generates CSV entries more readily comparable across layers, interleaved with services-specific log entries. --- .../src/main/config/log/jboss-log4j.xml | 20 +--------- .../services/common/profile/CSpaceFilter.java | 37 +++++++++++++------ .../services/common/profile/Profiler.java | 30 ++++++++++++--- 3 files changed, 51 insertions(+), 36 deletions(-) diff --git a/services/common/src/main/config/log/jboss-log4j.xml b/services/common/src/main/config/log/jboss-log4j.xml index d5f0a0daa..8c3a4640b 100644 --- a/services/common/src/main/config/log/jboss-log4j.xml +++ b/services/common/src/main/config/log/jboss-log4j.xml @@ -159,7 +159,7 @@ - + @@ -169,19 +169,6 @@ - - - - - - - - - - - - - @@ -393,11 +380,6 @@ - - - - - diff --git a/services/common/src/main/java/org/collectionspace/services/common/profile/CSpaceFilter.java b/services/common/src/main/java/org/collectionspace/services/common/profile/CSpaceFilter.java index 72aa93411..a3d9449a4 100644 --- a/services/common/src/main/java/org/collectionspace/services/common/profile/CSpaceFilter.java +++ b/services/common/src/main/java/org/collectionspace/services/common/profile/CSpaceFilter.java @@ -50,7 +50,6 @@ public class CSpaceFilter implements Filter { FilterConfig filterConfig = null; private final String CLASS_NAME = this.getClass().getSimpleName(); - private Logger csvPerfLogger = LoggerFactory.getLogger("perf.collectionspace.csv"); /* (non-Javadoc) * @see javax.servlet.Filter#destroy() @@ -74,32 +73,46 @@ public class CSpaceFilter implements Filter { uri.append(':'); uri.append(httpRequest.getMethod()); Profiler profiler = new Profiler(uri.toString(), 0); + Profiler csvProfiler = new Profiler("org.collectionspace.perf.csv"); // Start timing. profiler.start(); + // Write a CSV-delimited message to the performance log, + // in a format intended to be interoperable with those + // generated by other system layers. + String csvMsg = + profiler.getStartTime() + + "," + profiler.getElapsedTime() + + "," + "request" + + "," + "app" + + "," + "svc" + + "," + httpRequest.getMethod() + + "," + ServletTools.getURL(httpRequest) + + "," + CLASS_NAME + + "," + Thread.currentThread().getName(); + final boolean FORMAT_LOG_MESSAGE = false; + profiler.log(csvMsg, FORMAT_LOG_MESSAGE); + // Process the request. chain.doFilter(request, response); // Stop timing and log performance-related metrics. profiler.stop(); - String csvMsg = - "," + System.currentTimeMillis() - + "," + Thread.currentThread().getName() - + "," + "app" + csvMsg = + profiler.getStopTime() + + "," + profiler.getElapsedTime() + + "," + "response" + "," + "svc" - + "," + CLASS_NAME + + "," + "app" + "," + httpRequest.getMethod() + "," + ServletTools.getURL(httpRequest) - + "," + profiler.getElapsedTime(); + + "," + CLASS_NAME + + "," + Thread.currentThread().getName(); + profiler.log(csvMsg, FORMAT_LOG_MESSAGE); - // FIXME: Expedient change interleaves CSV-style log entries with entries - // in the original perf log. These should be written to their own log file, - // with their own patternLayout. - profiler.log(csvMsg); profiler.reset(); - // csvPerfLogger.debug(csvMsg); } } diff --git a/services/common/src/main/java/org/collectionspace/services/common/profile/Profiler.java b/services/common/src/main/java/org/collectionspace/services/common/profile/Profiler.java index d63c5300f..b31ecd8b2 100644 --- a/services/common/src/main/java/org/collectionspace/services/common/profile/Profiler.java +++ b/services/common/src/main/java/org/collectionspace/services/common/profile/Profiler.java @@ -179,9 +179,11 @@ public class Profiler { } /** - * Writes a log entry. + * Writes a message to a log entry. The message will + * be formatted, using current settings for indentation, + * prefix, etc. before being written. * - * @param msg the message to log. + * @param msg the message to be written to a log entry. */ public void log(String msg) { if (getLogger().isDebugEnabled()) { @@ -189,6 +191,23 @@ public class Profiler { } } + /** + * Writes a message to a log entry, + * + * @param msg the message to write to a log entry. + * @param formatMsg true if the message is to be formatted; + * false if it is not to be formatted. + */ + public void log(String msg, boolean formatMsg) { + if (getLogger().isDebugEnabled()) { + if (formatMsg) { + getLogger().debug(formatLogMessage(msg)); + } else { + getLogger().debug(msg); + } + } + } + /** * Gets the logger. * @@ -197,7 +216,7 @@ public class Profiler { protected Logger getLogger() { return this.profileLogger; } - + private void setMessagePrefix(String prefix) { this.messagePrefix = prefix; } @@ -251,10 +270,10 @@ public class Profiler { } /** - * Returns a formatted log message, including indentation and prefix. + * Returns a formatted log message, after adding indentation and prefix, if any. * * @param msg the message to log. - * @return a constructed log message, including indentation and prefix, if any. + * @return a formatted log message, including indentation and prefix, if any. */ private String formatLogMessage(String msg) { StringBuffer logMsg = new StringBuffer(); @@ -287,4 +306,5 @@ public class Profiler { } return defaultStopMessage.toString(); } + } -- 2.47.3