Author: markt Date: Sun Sep 23 09:43:43 2012 New Revision: 1388991 URL: http://svn.apache.org/viewvc?rev=1388991&view=rev Log: Use CharBuffer rather than StringBuilder to build the access log message to: - save a char[] to String conversion and the associated garbage - allow buffers to be recycled also saving garbage Reduces allocations due to the AccessLog from 43% to 27% of the overall allocations
Modified: tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java tomcat/trunk/java/org/apache/catalina/valves/ExtendedAccessLogValve.java tomcat/trunk/webapps/docs/config/valve.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=1388991&r1=1388990&r2=1388991&view=diff ============================================================================== --- tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java (original) +++ tomcat/trunk/java/org/apache/catalina/valves/AccessLogValve.java Sun Sep 23 09:43:43 2012 @@ -25,6 +25,7 @@ import java.io.OutputStreamWriter; import java.io.PrintWriter; import java.io.UnsupportedEncodingException; import java.net.InetAddress; +import java.nio.CharBuffer; import java.nio.charset.Charset; import java.text.SimpleDateFormat; import java.util.ArrayList; @@ -34,7 +35,9 @@ import java.util.HashMap; import java.util.Iterator; import java.util.List; import java.util.Locale; +import java.util.Queue; import java.util.TimeZone; +import java.util.concurrent.ConcurrentLinkedQueue; import javax.servlet.ServletException; import javax.servlet.http.Cookie; @@ -570,13 +573,28 @@ public class AccessLogValve extends Valv */ protected boolean requestAttributesEnabled = false; - // ------------------------------------------------------------- Properties + /** + * Buffer pool used for log message generation. Pool used to reduce garbage + * generation. + */ + private Queue<CharBuffer> charBuffers = new ConcurrentLinkedQueue<>(); /** - * @return Returns the enabled. + * Log message buffers are usually recycled and re-used. To prevent + * excessive memory usage, if a buffer grows beyond this size it will be + * discarded. The default is 256 characters. This should be set to larger + * than the typical access log message size. */ - public boolean getEnabled() { - return enabled; + private int maxLogMessageBufferSize = 256; + + // ------------------------------------------------------------- Properties + + public int getMaxLogMessageBufferSize() { + return maxLogMessageBufferSize; + } + + public void setMaxLogMessageBufferSize(int maxLogMessageBufferSize) { + this.maxLogMessageBufferSize = maxLogMessageBufferSize; } /** @@ -596,6 +614,13 @@ public class AccessLogValve extends Valv } /** + * @return Returns the enabled. + */ + public boolean getEnabled() { + return enabled; + } + + /** * @param enabled * The enabled to set. */ @@ -933,13 +958,23 @@ public class AccessLogValve extends Valv long start = request.getCoyoteRequest().getStartTime(); Date date = getDate(start + time); - StringBuilder result = new StringBuilder(128); + CharBuffer result = charBuffers.poll(); + if (result == null) { + result = CharBuffer.allocate(128); + } for (int i = 0; i < logElements.length; i++) { logElements[i].addElement(result, date, request, response, time); } - log(result.toString()); + result.flip(); + log(result); + + // TODO - Make this configurable + if (result.length() < 256) { + result.clear(); + charBuffers.add(result); + } } @@ -1000,7 +1035,7 @@ public class AccessLogValve extends Valv * * @param message Message to be logged */ - public void log(String message) { + public void log(CharBuffer message) { if (rotatable) { // Only do a logfile switch check once a second, max. long systime = System.currentTimeMillis(); @@ -1047,7 +1082,9 @@ public class AccessLogValve extends Valv // Log this message synchronized(this) { if (writer != null) { - writer.println(message); + writer.write(message.array(), message.arrayOffset(), + message.arrayOffset() + message.limit()); + writer.println(""); if (!buffered) { writer.flush(); } @@ -1229,7 +1266,7 @@ public class AccessLogValve extends Valv * AccessLogElement writes the partial message into the buffer. */ protected interface AccessLogElement { - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time); } @@ -1239,7 +1276,7 @@ public class AccessLogValve extends Valv */ protected static class ThreadNameElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { RequestInfo info = request.getCoyoteRequest().getRequestProcessor(); if(info != null) { @@ -1269,7 +1306,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(LOCAL_ADDR_VALUE); } @@ -1280,14 +1317,14 @@ public class AccessLogValve extends Valv */ protected class RemoteAddrElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (requestAttributesEnabled) { Object addr = request.getAttribute(REMOTE_ADDR_ATTRIBUTE); if (addr == null) { buf.append(request.getRemoteAddr()); } else { - buf.append(addr); + buf.append(addr.toString()); } } else { buf.append(request.getRemoteAddr()); @@ -1300,7 +1337,7 @@ public class AccessLogValve extends Valv */ protected class HostElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { String value = null; if (requestAttributesEnabled) { @@ -1324,7 +1361,7 @@ public class AccessLogValve extends Valv */ protected static class LogicalUserNameElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append('-'); } @@ -1335,14 +1372,14 @@ public class AccessLogValve extends Valv */ protected class ProtocolElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (requestAttributesEnabled) { Object proto = request.getAttribute(PROTOCOL_ATTRIBUTE); if (proto == null) { buf.append(request.getProtocol()); } else { - buf.append(proto); + buf.append(proto.toString()); } } else { buf.append(request.getProtocol()); @@ -1355,7 +1392,7 @@ public class AccessLogValve extends Valv */ protected static class UserElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (request != null) { String value = request.getRemoteUser(); @@ -1491,7 +1528,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { long timestamp = date.getTime(); long frac; @@ -1503,10 +1540,10 @@ public class AccessLogValve extends Valv buf.append(localDateCache.get().getFormat(timestamp)); break; case SEC: - buf.append(timestamp / 1000); + buf.append(Long.toString(timestamp / 1000)); break; case MSEC: - buf.append(timestamp); + buf.append(Long.toString(timestamp)); break; case MSEC_FRAC: frac = timestamp % 1000; @@ -1518,7 +1555,7 @@ public class AccessLogValve extends Valv buf.append('0'); } } - buf.append(frac); + buf.append(Long.toString(frac)); break; case SDF: String temp = localDateCache.get().getFormat(format, locale, timestamp); @@ -1548,7 +1585,7 @@ public class AccessLogValve extends Valv */ protected static class RequestElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (request != null) { String method = request.getMethod(); @@ -1577,10 +1614,10 @@ public class AccessLogValve extends Valv */ protected static class HttpStatusCodeElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (response != null) { - buf.append(response.getStatus()); + buf.append(Integer.toString(response.getStatus())); } else { buf.append('-'); } @@ -1592,17 +1629,17 @@ public class AccessLogValve extends Valv */ protected class LocalPortElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (requestAttributesEnabled) { Object port = request.getAttribute(SERVER_PORT_ATTRIBUTE); if (port == null) { - buf.append(request.getServerPort()); + buf.append(Integer.toString(request.getServerPort())); } else { - buf.append(port); + buf.append(port.toString()); } } else { - buf.append(request.getServerPort()); + buf.append(Integer.toString(request.getServerPort())); } } } @@ -1621,7 +1658,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { // Don't need to flush since trigger for log message is after the // response has been committed @@ -1643,7 +1680,7 @@ public class AccessLogValve extends Valv if (length <= 0 && conversion) { buf.append('-'); } else { - buf.append(length); + buf.append(Long.toString(length)); } } } @@ -1653,7 +1690,7 @@ public class AccessLogValve extends Valv */ protected static class MethodElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (request != null) { buf.append(request.getMethod()); @@ -1676,19 +1713,19 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (millis) { - buf.append(time); + buf.append(Long.toString(time)); } else { // second - buf.append(time / 1000); + buf.append(Long.toString(time / 1000)); buf.append('.'); int remains = (int) (time % 1000); - buf.append(remains / 100); + buf.append(Long.toString(remains / 100)); remains = remains % 100; - buf.append(remains / 10); - buf.append(remains % 10); + buf.append(Long.toString(remains / 10)); + buf.append(Long.toString(remains % 10)); } } } @@ -1698,7 +1735,7 @@ public class AccessLogValve extends Valv */ protected static class QueryElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { String query = null; if (request != null) { @@ -1716,7 +1753,7 @@ public class AccessLogValve extends Valv */ protected static class SessionIdElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (request != null) { if (request.getSession(false) != null) { @@ -1736,7 +1773,7 @@ public class AccessLogValve extends Valv */ protected static class RequestURIElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (request != null) { buf.append(request.getRequestURI()); @@ -1751,7 +1788,7 @@ public class AccessLogValve extends Valv */ protected static class LocalServerNameElement implements AccessLogElement { @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(request.getServerName()); } @@ -1768,7 +1805,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(str); } @@ -1785,7 +1822,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { Enumeration<String> iter = request.getHeaders(header); if (iter.hasMoreElements()) { @@ -1810,7 +1847,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { String value = "-"; Cookie[] c = request.getCookies(); @@ -1837,7 +1874,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (null != response) { Iterator<String> iter = response.getHeaders(header).iterator(); @@ -1864,7 +1901,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { Object value = null; if (request != null) { @@ -1895,7 +1932,7 @@ public class AccessLogValve extends Valv } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { Object value = null; if (null != request) { Modified: tomcat/trunk/java/org/apache/catalina/valves/ExtendedAccessLogValve.java URL: http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/catalina/valves/ExtendedAccessLogValve.java?rev=1388991&r1=1388990&r2=1388991&view=diff ============================================================================== --- tomcat/trunk/java/org/apache/catalina/valves/ExtendedAccessLogValve.java (original) +++ tomcat/trunk/java/org/apache/catalina/valves/ExtendedAccessLogValve.java Sun Sep 23 09:43:43 2012 @@ -22,6 +22,7 @@ import java.io.StringReader; import java.io.UnsupportedEncodingException; import java.net.InetAddress; import java.net.URLEncoder; +import java.nio.CharBuffer; import java.text.SimpleDateFormat; import java.util.ArrayList; import java.util.Date; @@ -225,7 +226,7 @@ public class ExtendedAccessLogValve exte }; @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { ElementTimestampStruct eds = currentDate.get(); long millis = eds.currentTimestamp.getTime(); @@ -253,7 +254,7 @@ public class ExtendedAccessLogValve exte }; @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { ElementTimestampStruct eds = currentTime.get(); long millis = eds.currentTimestamp.getTime(); @@ -275,7 +276,7 @@ public class ExtendedAccessLogValve exte this.header = header; } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getHeader(header))); } @@ -289,7 +290,7 @@ public class ExtendedAccessLogValve exte } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(response.getHeader(header))); } @@ -302,7 +303,7 @@ public class ExtendedAccessLogValve exte this.attribute = attribute; } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getContext().getServletContext() .getAttribute(attribute))); @@ -316,7 +317,7 @@ public class ExtendedAccessLogValve exte this.name = name; } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { Cookie[] c = request.getCookies(); for (int i = 0; c != null && i < c.length; i++) { @@ -338,7 +339,7 @@ public class ExtendedAccessLogValve exte } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { if (null != response) { Iterator<String> iter = response.getHeaders(header).iterator(); @@ -367,7 +368,7 @@ public class ExtendedAccessLogValve exte } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getAttribute(attribute))); } @@ -380,7 +381,7 @@ public class ExtendedAccessLogValve exte this.attribute = attribute; } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { HttpSession session = null; if (request != null) { @@ -414,7 +415,7 @@ public class ExtendedAccessLogValve exte } @Override - public void addElement(StringBuilder buf, Date date, Request request, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(urlEncode(request.getParameter(parameter)))); } @@ -616,7 +617,7 @@ public class ExtendedAccessLogValve exte } else if ("dns".equals(nextToken)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { String value; try { @@ -656,7 +657,7 @@ public class ExtendedAccessLogValve exte } else if ("query".equals(token)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { String query = request.getQueryString(); @@ -671,7 +672,7 @@ public class ExtendedAccessLogValve exte } else { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { String query = request.getQueryString(); if (query == null) { @@ -778,7 +779,7 @@ public class ExtendedAccessLogValve exte if ("authType".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getAuthType())); } @@ -786,7 +787,7 @@ public class ExtendedAccessLogValve exte } else if ("remoteUser".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getRemoteUser())); } @@ -794,7 +795,7 @@ public class ExtendedAccessLogValve exte } else if ("requestedSessionId".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getRequestedSessionId())); } @@ -802,7 +803,7 @@ public class ExtendedAccessLogValve exte } else if ("requestedSessionIdFromCookie".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap("" + request.isRequestedSessionIdFromCookie())); @@ -811,7 +812,7 @@ public class ExtendedAccessLogValve exte } else if ("requestedSessionIdValid".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap("" + request.isRequestedSessionIdValid())); } @@ -819,7 +820,7 @@ public class ExtendedAccessLogValve exte } else if ("contentLength".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap("" + request.getContentLength())); } @@ -827,7 +828,7 @@ public class ExtendedAccessLogValve exte } else if ("characterEncoding".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getCharacterEncoding())); } @@ -835,7 +836,7 @@ public class ExtendedAccessLogValve exte } else if ("locale".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getLocale())); } @@ -843,7 +844,7 @@ public class ExtendedAccessLogValve exte } else if ("protocol".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap(request.getProtocol())); } @@ -851,7 +852,7 @@ public class ExtendedAccessLogValve exte } else if ("scheme".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(request.getScheme()); } @@ -859,7 +860,7 @@ public class ExtendedAccessLogValve exte } else if ("secure".equals(parameter)) { return new AccessLogElement() { @Override - public void addElement(StringBuilder buf, Date date, + public void addElement(CharBuffer buf, Date date, Request request, Response response, long time) { buf.append(wrap("" + request.isSecure())); } Modified: tomcat/trunk/webapps/docs/config/valve.xml URL: http://svn.apache.org/viewvc/tomcat/trunk/webapps/docs/config/valve.xml?rev=1388991&r1=1388990&r2=1388991&view=diff ============================================================================== --- tomcat/trunk/webapps/docs/config/valve.xml (original) +++ tomcat/trunk/webapps/docs/config/valve.xml Sun Sep 23 09:43:43 2012 @@ -128,6 +128,13 @@ </p> </attribute> + <attribute name="maxLogMessageBufferSize" required="false"> + <p>Log message buffers are usually recycled and re-used. To prevent + excessive memory usage, if a buffer grows beyond this size it will be + discarded. The default is <code>256</code> characters. This should be + set to larger than the typical access log message size.</p> + </attribute> + <attribute name="pattern" required="false"> <p>A formatting layout identifying the various information fields from the request and response to be logged, or the word @@ -342,6 +349,26 @@ </p> </attribute> + <attribute name="locale" required="false"> + <p>The locale used to format timestamps in the access log + lines. Any timestamps configured using an + explicit SimpleDateFormat pattern (<code>%{xxx}t</code>) + are formatted in this locale. By default the + default locale of the Java process is used. Switching the + locale after the AccessLogValve is initialized is not supported. + Any timestamps using the common log format + (<code>CLF</code>) are always formatted in the locale + <code>en_US</code>. + </p> + </attribute> + + <attribute name="maxLogMessageBufferSize" required="false"> + <p>Log message buffers are usually recycled and re-used. To prevent + excessive memory usage, if a buffer grows beyond this size it will be + discarded. The default is <code>256</code> characters. This should be + set to larger than the typical access log message size.</p> + </attribute> + <attribute name="pattern" required="false"> <p>A formatting layout identifying the various information fields from the request and response to be logged. --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org