CSPACE-2950: More ad-hoc changes to performance logging with the goal of mere adequac...

diff --git a/services/common/src/main/config/log/jboss-log4j.xml b/services/common/src/main/config/log/jboss-log4j.xml
index d5f0a0daa13672cab5a11f7488e86855a8626867..8c3a4640be251c582908c25d131b1c98e7cac3c4 100644 (file)
--- a/services/common/src/main/config/log/jboss-log4j.xml
+++ b/services/common/src/main/config/log/jboss-log4j.xml
@@ -159,7 +159,7 @@
       <param name="DatePattern" value="'.'yyyy-MM-dd"/>
       <param name="File" value="${jboss.server.log.dir}/collectionspace-perf.log"/>
       <layout class="org.apache.log4j.PatternLayout">
-         <!-- FIXME: Temporary change to accommodate interleaved CSV log entries -->
+         <!-- Change to accommodate interleaved CSV log entries -->
          <!-- param name="ConversionPattern" value="%d [%t] %m%n"/ -->
          <param name="ConversionPattern" value="&quot;%d&quot;,%m%n"/>
       </layout>
@@ -169,19 +169,6 @@
       </filter> 
       <filter class="org.apache.log4j.varia.DenyAllFilter"></filter-->
    </appender>
-
-   <!-- collectionspace performance appender, generating a comma-separated value (CSV) -->
-   <!-- format common to (at least) the services and app layers -->
-   <appender name="CSLOG_PERF_CSV" class="org.jboss.logging.appender.DailyRollingFileAppender">
-      <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
-      <param name="Append" value="false"/>
-      <param name="DatePattern" value="'.'yyyy-MM-dd"/> <!-- Roll over at midnight daily -->
-      <param name="File" value="${jboss.server.log.dir}/collectionspace-perf-csv.log"/>
-      <layout class="org.apache.log4j.PatternLayout">
-         <!-- param name="ConversionPattern" value="&quot;%d&quot;,%r,%t,app,svc,%C{2},%M,method_get_uri_placeholder,svc%n"/ -->
-         <param name="ConversionPattern" value="&quot;%d&quot;,%m%n"/>
-      </layout>
-   </appender>
    
    <!-- ================ -->
    <!-- Limit categories -->
@@ -393,11 +380,6 @@
      <priority value="DEBUG" />
      <appender-ref ref="CSLOG_PERF"/>
    </category>
-
-   <category name="perf.collectionspace.csv">
-     <priority value="DEBUG" />
-     <appender-ref ref="CSLOG_PERF_CSV"/>
-   </category>
    
    <!-- ======================= -->
    <!-- Setup the Root category -->

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 72aa93411675807a528cd6eb230b05b928908a03..a3d9449a422ae0d4c9a2f7816ba7c9b0d18d39df 100644 (file)
--- 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;\r
 \r
     private final String CLASS_NAME = this.getClass().getSimpleName();\r
-    private Logger csvPerfLogger = LoggerFactory.getLogger("perf.collectionspace.csv");\r
 \r
     /* (non-Javadoc)\r
      * @see javax.servlet.Filter#destroy()\r
@@ -74,32 +73,46 @@ public class CSpaceFilter implements Filter {
             uri.append(':');\r
             uri.append(httpRequest.getMethod());\r
             Profiler profiler = new Profiler(uri.toString(), 0);\r
+            Profiler csvProfiler = new Profiler("org.collectionspace.perf.csv");\r
 \r
             // Start timing.\r
             profiler.start();\r
 \r
+            // Write a CSV-delimited message to the performance log,\r
+            // in a format intended to be interoperable with those\r
+            // generated by other system layers.\r
+            String csvMsg =\r
+                    profiler.getStartTime()\r
+                    + "," + profiler.getElapsedTime()\r
+                    + "," + "request"\r
+                    + "," + "app"\r
+                    + "," + "svc"\r
+                    + "," + httpRequest.getMethod()\r
+                    + "," + ServletTools.getURL(httpRequest)\r
+                    + "," + CLASS_NAME\r
+                    + "," + Thread.currentThread().getName();\r
+           final boolean FORMAT_LOG_MESSAGE = false;\r
+           profiler.log(csvMsg, FORMAT_LOG_MESSAGE);\r
+\r
             // Process the request.\r
             chain.doFilter(request, response);\r
 \r
             // Stop timing and log performance-related metrics.\r
             profiler.stop();\r
 \r
-            String csvMsg =\r
-                    "," + System.currentTimeMillis()\r
-                    + "," + Thread.currentThread().getName()\r
-                    + "," + "app"\r
+            csvMsg =\r
+                    profiler.getStopTime()\r
+                    + "," + profiler.getElapsedTime()\r
+                    + "," + "response"\r
                     + "," + "svc"\r
-                    + "," + CLASS_NAME\r
+                    + "," + "app"\r
                     + "," + httpRequest.getMethod()\r
                     + "," + ServletTools.getURL(httpRequest)\r
-                    + "," + profiler.getElapsedTime();\r
+                    + "," + CLASS_NAME\r
+                    + "," + Thread.currentThread().getName();\r
+            profiler.log(csvMsg, FORMAT_LOG_MESSAGE);\r
 \r
-            // FIXME: Expedient change interleaves CSV-style log entries with entries\r
-            // in the original perf log.  These should be written to their own log file,\r
-            // with their own patternLayout.\r
-            profiler.log(csvMsg);\r
             profiler.reset();\r
-            // csvPerfLogger.debug(csvMsg);\r
         }\r
     }\r
 \r

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 d63c5300f31a21ed5778fbdeb880f630c196dfc4..b31ecd8b2b31609b91006ecdfefb1398ddc31439 100644 (file)
--- 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 {
     }\r
 \r
     /**\r
-     * Writes a log entry.\r
+     * Writes a message to a log entry.  The message will\r
+     * be formatted, using current settings for indentation,\r
+     * prefix, etc. before being written.\r
      *\r
-     * @param msg the message to log.\r
+     * @param msg the message to be written to a log entry.\r
      */\r
     public void log(String msg) {\r
         if (getLogger().isDebugEnabled()) {\r
@@ -189,6 +191,23 @@ public class Profiler {
         }\r
     }\r
 \r
+    /**\r
+     * Writes a message to a log entry,\r
+     *\r
+     * @param msg the message to write to a log entry.\r
+     * @param formatMsg true if the message is to be formatted;\r
+     *                  false if it is not to be formatted.\r
+     */\r
+    public void log(String msg, boolean formatMsg) {\r
+        if (getLogger().isDebugEnabled()) {\r
+            if (formatMsg) {\r
+                getLogger().debug(formatLogMessage(msg));\r
+            } else {\r
+                getLogger().debug(msg);\r
+            }\r
+        }\r
+    }\r
+\r
     /**\r
      * Gets the logger.\r
      *\r
@@ -197,7 +216,7 @@ public class Profiler {
     protected Logger getLogger() {\r
         return this.profileLogger;\r
     }\r
-\r
+    \r
     private void setMessagePrefix(String prefix) {\r
         this.messagePrefix = prefix;\r
     }\r
@@ -251,10 +270,10 @@ public class Profiler {
     }\r
 \r
     /**\r
-     * Returns a formatted log message, including indentation and prefix.\r
+     * Returns a formatted log message, after adding indentation and prefix, if any.\r
      *\r
      * @param msg the message to log.\r
-     * @return a constructed log message, including indentation and prefix, if any.\r
+     * @return a formatted log message, including indentation and prefix, if any.\r
      */\r
     private String formatLogMessage(String msg) {\r
         StringBuffer logMsg = new StringBuffer();\r
@@ -287,4 +306,5 @@ public class Profiler {
         }\r
         return defaultStopMessage.toString();\r
     }\r
+\r
 }\r