tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From rj...@apache.org
Subject svn commit: r1137336 - in /tomcat/trunk: java/org/apache/catalina/valves/AccessLogValve.java webapps/docs/changelog.xml
Date Sun, 19 Jun 2011 10:58:02 GMT
Author: rjung
Date: Sun Jun 19 10:58:02 2011
New Revision: 1137336

URL: http://svn.apache.org/viewvc?rev=1137336&view=rev
Log:
BZ 49165 and more:
- Allow any time stamp formats supported
  by SimpleDateFormat in AccessLogValve.
- Support logging begin and/or end of request.

Docs to follow.

Modified:
    tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java
    tomcat/trunk/webapps/docs/changelog.xml

Modified: tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java
URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java?rev=1137336&r1=1137335&r2=1137336&view=diff
==============================================================================
--- tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java (original)
+++ tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java Sun Jun 19 10:58:02 2011
@@ -29,6 +29,7 @@ import java.text.SimpleDateFormat;
 import java.util.ArrayList;
 import java.util.Date;
 import java.util.Enumeration;
+import java.util.HashMap;
 import java.util.Iterator;
 import java.util.List;
 import java.util.TimeZone;
@@ -76,6 +77,7 @@ import org.apache.tomcat.util.ExceptionU
  * <li><b>%s</b> - HTTP status code of the response
  * <li><b>%S</b> - User session ID
  * <li><b>%t</b> - Date and time, in Common Log Format format
+ * <li><b>%t{format}</b> - Date and time, in any format supported by SimpleDateFormat
  * <li><b>%u</b> - Remote user that was authenticated
  * <li><b>%U</b> - Requested URL path
  * <li><b>%v</b> - Local server name
@@ -149,7 +151,7 @@ public class AccessLogValve extends Valv
      * The descriptive information about this implementation.
      */
     protected static final String info =
-        "org.apache.catalina.valves.AccessLogValve/2.1";
+        "org.apache.catalina.valves.AccessLogValve/2.2";
 
 
     /**
@@ -227,39 +229,239 @@ public class AccessLogValve extends Valv
      */
     private static final String timeZoneDST;
     
+    /**
+     * The size of our global date format cache
+     */
+    private static final int globalCacheSize = 300;
+
+    /**
+     * The size of our thread local date format cache
+     */
+    private static final int localCacheSize = 60;
+
     
     /**
      * The current log file we are writing to. Helpful when checkExists
      * is true.
      */
     protected File currentLogFile = null;
-    private static class AccessDateStruct {
-        private Date currentDate = new Date();
-        private String currentDateString = null;
-        private SimpleDateFormat dayFormatter = new SimpleDateFormat("dd");
-        private SimpleDateFormat monthFormatter = new SimpleDateFormat("MM");
-        private SimpleDateFormat yearFormatter = new SimpleDateFormat("yyyy");
-        private SimpleDateFormat timeFormatter = new SimpleDateFormat("HH:mm:ss");
-        public AccessDateStruct() {
-            TimeZone tz = TimeZone.getDefault();
-            dayFormatter.setTimeZone(tz);
-            monthFormatter.setTimeZone(tz);
-            yearFormatter.setTimeZone(tz);
-            timeFormatter.setTimeZone(tz);
+
+    /**
+     * <p>Cache structure for formatted timestamps based on seconds.</p>
+     *
+     * <p>The cache consists of entries for a consecutive range of
+     * seconds. The length of the range is configurable. It is
+     * implemented based on a cyclic buffer. New entries shift the range.</p>
+     *
+     * <p>There is one cache for the CLF format (the access log standard
+     * format) and a HashMap of caches for additional formats used by
+     * SimpleDateFormat.</p>
+     *
+     * <p>The cache is not threadsafe. It can be used without synchronization
+     * via thread local instances, or with synchronization as a global cache.</p>
+     *
+     * <p>This class uses a small thread local first level cache and a bigger
+     * synchronized global second level cache.</p>
+     */
+    private static class DateFormatCache {
+
+        private class Cache {
+
+            /* CLF log format */
+            private static final String cLFFormat = "dd/MMM/yyy:HH:mm:ss";
+
+            /* Second used to retrieve CLF format in most recent invocation */
+            private long previousSeconds = 0L;
+            /* Value of CLF format retrieved in most recent invocation */
+            private String previousFormat = "";
+
+            /* First second contained in cache */
+            private long first = 0L;
+            /* Last second contained in cache */
+            private long last = 0L;
+            /* Index of "first" in the cyclic cache */
+            private int offset = 0;
+            /* Helper object to be able to call SimpleDateFormat.format(). */
+            private final Date currentDate = new Date();
+
+            private String cache[];
+            private SimpleDateFormat formatter;
+            private boolean isCLF = false;
+
+            private Cache parent = null;
+
+            private Cache(String format, Cache parent) {
+                cache = new String[cacheSize];
+                for (int i = 0; i < cacheSize; i++) {
+                    cache[i] = null;
+                }
+                if (format == null) {
+                    isCLF = true;
+                    format = cLFFormat;
+                }
+                formatter = new SimpleDateFormat(format);
+                formatter.setTimeZone(TimeZone.getDefault());
+                this.parent = parent;
+            }
+
+            private String getFormat(long time) {
+
+                long seconds = time / 1000;
+
+                /* First step: if we have seen this timestamp
+                   during the previous call, and we need CLF, return the previous value.
*/
+                if (seconds == previousSeconds) {
+                    return previousFormat;
+                }
+
+                /* Second step: Try to locate in cache */
+                previousSeconds = seconds;
+                int index = (offset + (int)(seconds - first)) % cacheSize;
+                if (index < 0) {
+                    index += cacheSize;
+                }
+                if (seconds >= first && seconds <= last) {
+                    if (cache[index] != null) {
+                        /* Found, so remember for next call and return.*/
+                        previousFormat = cache[index];
+                        return previousFormat;
+                    }
+
+                /* Third step: not found in cache, adjust cache and add item */
+                } else if (seconds >= last + cacheSize || seconds <= first - cacheSize)
{
+                    first = seconds;
+                    last = first + cacheSize - 1;
+                    index = 0;
+                    offset = 0;
+                    for (int i = 1; i < cacheSize; i++) {
+                        cache[i] = null;
+                    }
+                } else if (seconds > last) {
+                    for (int i = 1; i < seconds - last; i++) {
+                        cache[(index + cacheSize - i) % cacheSize] = null;
+                    }
+                    first = seconds - cacheSize;
+                    last = seconds;
+                } else if (seconds < first) {
+                    for (int i = 1; i < first - seconds; i++) {
+                        cache[(index + i) % cacheSize] = null;
+                    }
+                    first = seconds;
+                    last = seconds + cacheSize;
+                }
+
+                /* Last step: format new timestamp either using
+                 * parent cache or locally. */
+                if (parent != null) {
+                    synchronized(parent) {
+                        previousFormat = parent.getFormat(time);
+                    }
+                } else {
+                    currentDate.setTime(time);
+                    previousFormat = formatter.format(currentDate);
+                    if (isCLF) {
+                        StringBuilder current = new StringBuilder(32);
+                        current.append('[');
+                        current.append(previousFormat);
+                        current.append(' ');
+                        current.append(getTimeZone(currentDate));
+                        current.append(']');
+                        previousFormat = current.toString();
+                    }
+                }
+                cache[index] = previousFormat;
+                return previousFormat;
+            }
+        }
+
+        private String type;
+
+        /* Number of cached entries */
+        private int cacheSize = 0;
+
+        private DateFormatCache parent;
+        private Cache cLFCache;
+        private HashMap<String, Cache> formatCache = new HashMap<String, Cache>();
+
+        private DateFormatCache(int size, DateFormatCache parent) {
+            if (parent == null) {
+                type = "main";
+            } else {
+                type = "child";
+            }
+            cacheSize = size;
+            this.parent = parent;
+            Cache parentCache = null;
+            if (parent != null) {
+                synchronized(parent) {
+                    parentCache = parent.getCache(null);
+                }
+            }
+            cLFCache = new Cache(null, parentCache);
+        }
+
+        private Cache getCache(String format) {
+            Cache cache;
+            if (format == null) {
+                cache = cLFCache;
+            } else {
+                cache = formatCache.get(format);
+                if (cache == null) {
+                    Cache parentCache = null;
+                    if (parent != null) {
+                        synchronized(parent) {
+                            parentCache = parent.getCache(format);
+                        }
+                    }
+                    cache = new Cache(format, parentCache);
+                    formatCache.put(format, cache);
+                }
+            }
+            return cache;
+        }
+
+        public String getFormat(String format, long time) {
+
+            return getCache(format).getFormat(time);
         }
     }
-    
+
+    /**
+     * Global date format cache.
+     */
+    private static final DateFormatCache globalDateCache =
+            new DateFormatCache(globalCacheSize, null);
+
+    /**
+     * Thread local date format cache.
+     */
+    private static final ThreadLocal<DateFormatCache> localDateCache =
+            new ThreadLocal<DateFormatCache>() {
+        protected DateFormatCache initialValue() {
+            return new DateFormatCache(localCacheSize, globalDateCache);
+        }
+    };
+
+
     /**
      * The system time when we last updated the Date that this valve
      * uses for log lines.
      */
-    private static final ThreadLocal<AccessDateStruct> currentDateStruct =
-            new ThreadLocal<AccessDateStruct>() {
+    private static final ThreadLocal<Date> localDate =
+            new ThreadLocal<Date>() {
         @Override
-        protected AccessDateStruct initialValue() {
-            return new AccessDateStruct();
+        protected Date initialValue() {
+            return new Date();
         }
     };
+
+    /**
+     * The list of our format types.
+     */
+    private static enum formatType {
+        CLF, SEC, MSEC, MSEC_FRAC, SDF
+    }
+
     /**
      * Resolve hosts.
      */
@@ -572,7 +774,15 @@ public class AccessLogValve extends Valv
             return;
         }
 
-        Date date = getDate();
+        /**
+         * XXX This is a bit silly, but we want to have start and stop time and
+         * duration consistent. It would be better to keep start and stop
+         * simply in the request and/or response object and remove time
+         * (duration) from the interface.
+         */
+        long start = request.getCoyoteRequest().getStartTime();
+        Date date = getDate(start + time);
+
         StringBuilder result = new StringBuilder(128);
 
         for (int i = 0; i < logElements.length; i++) {
@@ -759,15 +969,10 @@ public class AccessLogValve extends Valv
      * 
      * @return Date
      */
-    private Date getDate() {
-        // Only create a new Date once per second, max.
-        long systime = System.currentTimeMillis();
-        AccessDateStruct struct = currentDateStruct.get(); 
-        if ((systime - struct.currentDate.getTime()) > 1000) {
-            struct.currentDate.setTime(systime);
-            struct.currentDateString = null;
-        }
-        return struct.currentDate;
+    private static Date getDate(long systime) {
+        Date date = localDate.get();
+        date.setTime(systime);
+        return date;
     }
 
 
@@ -830,7 +1035,7 @@ public class AccessLogValve extends Valv
         }
         fileDateFormatter = new SimpleDateFormat(format);
         fileDateFormatter.setTimeZone(timezone);
-        dateStamp = fileDateFormatter.format(currentDateStruct.get().currentDate);
+        dateStamp = fileDateFormatter.format(new Date(System.currentTimeMillis()));
         open();
         
         setState(LifecycleState.STARTING);
@@ -997,31 +1202,154 @@ public class AccessLogValve extends Valv
     }
 
     /**
-     * write date and time, in Common Log Format - %t
+     * write date and time, in configurable format (default CLF) - %t or %t{format}
      */
     protected class DateAndTimeElement implements AccessLogElement {
 
+        /**
+         * Format prefix specifying request start time
+         */
+        private static final String requestStartPrefix = "begin";
+
+        /**
+         * Format prefix specifying response end time
+         */
+        private static final String responseEndPrefix = "end";
+
+        /**
+         * Separator between optional prefix and rest of format
+         */
+        private static final String prefixSeparator = ":";
+
+        /**
+         * Special format for seconds since epoch
+         */
+        private static final String secFormat = "sec";
+
+        /**
+         * Special format for milliseconds since epoch
+         */
+        private static final String msecFormat = "msec";
+
+        /**
+         * Special format for millisecond part of timestamp
+         */
+        private static final String msecFractionFormat = "msec_frac";
+
+        /**
+         * The pattern we use to replace "S" millisecond formatting
+         * of SimpleDateFormat by our own handling
+         */
+        private static final String msecPattern = "####";
+
+        /* Our format description string, null if CLF */
+        private String format = null;
+        /* Whether to use begin of request or end of response as the timestamp */
+        private boolean usesBegin = false;
+        /* The format type */
+        private formatType type = formatType.CLF;
+        /* Whether we need to postprocess by adding milliseconds */
+        private boolean usesMsecs = false;
+
+        protected DateAndTimeElement() {
+            this(null);
+        }
+
+        /**
+         * Replace the millisecond formatting character 'S' by
+         * some dummy characters in order to make the resulting
+         * formatted time stamps cacheable. We replace the dummy
+         * chars later with the actual milliseconds because that's
+         * relatively cheap.
+         */
+        private void tidyFormat() {
+            boolean escape = false;
+            StringBuilder result = new StringBuilder();
+            int len = format.length();
+            char x;
+            for (int i = 0; i < len; i++) {
+                x = format.charAt(i);
+                if (escape || x != 'S') {
+                    result.append(x);
+                } else {
+                    result.append(msecPattern);
+                    usesMsecs = true;
+                }
+                if (x == '\'') {
+                    escape = !escape;
+                }
+            }
+            format = result.toString();
+        }
+
+        protected DateAndTimeElement(String header) {
+            format = header;
+            if (format != null) {
+                if (format.equals(requestStartPrefix)) {
+                    usesBegin = true;
+                    format = "";
+                } else if (format.startsWith(requestStartPrefix + prefixSeparator)) {
+                    usesBegin = true;
+                    format = format.substring(6);
+                } else if (format.equals(responseEndPrefix)) {
+                    usesBegin = false;
+                    format = "";
+                } else if (format.startsWith(responseEndPrefix + prefixSeparator)) {
+                    usesBegin = false;
+                    format = format.substring(4);
+                }
+                if (format.length() == 0) {
+                    type = formatType.CLF;
+                } else if (format.equals(secFormat)) {
+                    type = formatType.SEC;
+                } else if (format.equals(msecFormat)) {
+                    type = formatType.MSEC;
+                } else if (format.equals(msecFractionFormat)) {
+                    type = formatType.MSEC_FRAC;
+                } else {
+                    type = formatType.SDF;
+                    tidyFormat();
+                }
+            }
+        }
 
         @Override
         public void addElement(StringBuilder buf, Date date, Request request,
                 Response response, long time) {
-            AccessDateStruct struct = currentDateStruct.get();
-            if (struct.currentDateString == null) {
-                StringBuilder current = new StringBuilder(32);
-                current.append('[');
-                current.append(struct.dayFormatter.format(date));
-                current.append('/');
-                current.append(lookup(struct.monthFormatter.format(date)));
-                current.append('/');
-                current.append(struct.yearFormatter.format(date));
-                current.append(':');
-                current.append(struct.timeFormatter.format(date));
-                current.append(' ');
-                current.append(getTimeZone(date));
-                current.append(']');
-                struct.currentDateString = current.toString();
+            long timestamp = date.getTime();
+            if (usesBegin) {
+                timestamp -= time;
+            }
+            switch (type) {
+            case CLF:
+                buf.append(localDateCache.get().getFormat(null, timestamp));
+                break;
+            case SEC:
+                buf.append(timestamp / 1000);
+                break;
+            case MSEC:
+                buf.append(timestamp);
+                break;
+            case MSEC_FRAC:
+                long frac = timestamp % 1000;
+                if (frac < 100) {
+                    if (frac < 10) {
+                        buf.append("00");
+                    } else {
+                        buf.append("0");
+                    }
+                }
+                buf.append(frac);
+                break;
+            case SDF:
+                String temp = localDateCache.get().getFormat(format, timestamp);
+                if (usesMsecs) {
+                    String msec = Long.toString(timestamp % 1000);
+                    temp = temp.replace(msecPattern, msec);
+                }
+                buf.append(temp);
+                break;
             }
-            buf.append(struct.currentDateString);
         }
     }
 
@@ -1449,6 +1777,8 @@ public class AccessLogValve extends Valv
             return new RequestAttributeElement(header);
         case 's':
             return new SessionAttributeElement(header);            
+        case 't':
+            return new DateAndTimeElement(header);
         default:
             return new StringElement("???");
         }

Modified: tomcat/trunk/webapps/docs/changelog.xml
URL: http://svn.apache.org/viewvc/tomcat/trunk/webapps/docs/changelog.xml?rev=1137336&r1=1137335&r2=1137336&view=diff
==============================================================================
--- tomcat/trunk/webapps/docs/changelog.xml (original)
+++ tomcat/trunk/webapps/docs/changelog.xml Sun Jun 19 10:58:02 2011
@@ -64,6 +64,10 @@
         so only types of interest are reported to a ServletContainerInitializer.
         (markt)
       </fix>
+      <fix>
+        <bug>49165</bug>: Allow any time stamp formats supported by SimpleDateFormat
+        in AccessLogValve. Support logging begin and/or end of request. (rjung)
+      </fix>
     </changelog>
   </subsection>
   <subsection name="Coyote">



---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


Mime
View raw message