diff --git a/logback-access/pom.xml b/logback-access/pom.xml index db92f932e2..4ce03e7d6e 100755 --- a/logback-access/pom.xml +++ b/logback-access/pom.xml @@ -50,6 +50,13 @@ true + + org.apache.tomcat + tomcat-coyote + compile + true + + org.eclipse.jetty jetty-server @@ -58,7 +65,7 @@ - org.codehaus.janino + org.codehaus.janino janino compile true @@ -141,13 +148,13 @@ Bnd's analysis of java code. --> - ch.qos.logback.core.rolling, - ch.qos.logback.core.rolling.helper, - javax.servlet.*;version="2.5", - javax.*;resolution:=optional, - org.apache.catalina.*;version="${tomcat.version}";resolution:=optional, - org.eclipse.jetty.*;version="${jetty.version}";resolution:=optional, - * + ch.qos.logback.core.rolling, + ch.qos.logback.core.rolling.helper, + javax.servlet.*;version="2.5", + javax.*;resolution:=optional, + org.apache.catalina.*;version="${tomcat.version}";resolution:=optional, + org.eclipse.jetty.*;version="${jetty.version}";resolution:=optional, + * J2SE-1.5 diff --git a/logback-access/src/main/java/ch/qos/logback/access/PatternLayout.java b/logback-access/src/main/java/ch/qos/logback/access/PatternLayout.java index 601aa75fd1..703842d4d8 100644 --- a/logback-access/src/main/java/ch/qos/logback/access/PatternLayout.java +++ b/logback-access/src/main/java/ch/qos/logback/access/PatternLayout.java @@ -13,11 +13,9 @@ */ package ch.qos.logback.access; -import java.util.HashMap; -import java.util.Map; - import ch.qos.logback.access.pattern.ContentLengthConverter; import ch.qos.logback.access.pattern.DateConverter; +import ch.qos.logback.access.pattern.ElapsedTimeConverter; import ch.qos.logback.access.pattern.EnsureLineSeparation; import ch.qos.logback.access.pattern.FullRequestConverter; import ch.qos.logback.access.pattern.FullResponseConverter; @@ -46,6 +44,9 @@ import ch.qos.logback.core.pattern.color.*; import ch.qos.logback.core.pattern.parser.Parser; +import java.util.HashMap; +import java.util.Map; + /** *

* This class is a module-specific implementation of @@ -54,10 +55,10 @@ * way to format the logging output that is just as easy and flexible as the * usual PatternLayout. *

- *

+ *

* For more information about this layout, please refer to the online manual at * http://logback.qos.ch/manual/layouts.html#AccessPatternLayout - * + * * @author Ceki Gülcü * @author Sébastien Pennec */ @@ -122,22 +123,22 @@ public class PatternLayout extends PatternLayoutBase { defaultConverterMap.put("server", ServerNameConverter.class.getName()); defaultConverterMap.put("localPort", LocalPortConverter.class.getName()); - + defaultConverterMap.put("requestAttribute", RequestAttributeConverter.class .getName()); defaultConverterMap.put("reqAttribute", RequestAttributeConverter.class .getName()); - + defaultConverterMap .put("reqCookie", RequestCookieConverter.class.getName()); defaultConverterMap - .put("requestCookie", RequestCookieConverter.class.getName()); + .put("requestCookie", RequestCookieConverter.class.getName()); + - defaultConverterMap.put("responseHeader", ResponseHeaderConverter.class .getName()); - - + + defaultConverterMap.put("requestParameter", RequestParameterConverter.class .getName()); defaultConverterMap.put("reqParameter", RequestParameterConverter.class @@ -150,7 +151,9 @@ public class PatternLayout extends PatternLayoutBase { defaultConverterMap.put("fullRequest", FullRequestConverter.class.getName()); defaultConverterMap.put("fullResponse", FullResponseConverter.class.getName()); - + defaultConverterMap.put("elapsedTime", ElapsedTimeConverter.class.getName()); + defaultConverterMap.put("D", ElapsedTimeConverter.class.getName()); + defaultConverterMap.put("n", LineSeparatorConverter.class.getName()); defaultConverterMap.put("black", BlackCompositeConverter.class.getName()); @@ -171,7 +174,7 @@ public class PatternLayout extends PatternLayoutBase { defaultConverterMap.put("boldWhite", BoldWhiteCompositeConverter.class.getName()); } - + public PatternLayout() { // set a default value for pattern setPattern(CLF_PATTERN); diff --git a/logback-access/src/main/java/ch/qos/logback/access/jetty/JettyServerAdapter.java b/logback-access/src/main/java/ch/qos/logback/access/jetty/JettyServerAdapter.java index 44ca2bc7fe..14ab6c4924 100644 --- a/logback-access/src/main/java/ch/qos/logback/access/jetty/JettyServerAdapter.java +++ b/logback-access/src/main/java/ch/qos/logback/access/jetty/JettyServerAdapter.java @@ -13,19 +13,18 @@ */ package ch.qos.logback.access.jetty; -import java.util.Enumeration; -import java.util.HashMap; -import java.util.Map; - +import ch.qos.logback.access.spi.ServerAdapter; import org.eclipse.jetty.http.HttpFields; import org.eclipse.jetty.server.Request; import org.eclipse.jetty.server.Response; -import ch.qos.logback.access.spi.ServerAdapter; +import java.util.Enumeration; +import java.util.HashMap; +import java.util.Map; /** * A jetty specific implementation of the {@link ServerAdapter} interface. - * + * * @author Sébastien Pennec * @author Ceki Gulcu */ @@ -33,7 +32,7 @@ public class JettyServerAdapter implements ServerAdapter { Request request; Response response; - + public JettyServerAdapter(Request jettyRequest, Response jettyResponse) { this.request = jettyRequest; this.response = jettyResponse; @@ -47,6 +46,10 @@ public int getStatusCode() { return response.getStatus(); } + public long getRequestTimestamp() { + return request.getTimeStamp(); + } + public Map buildResponseHeaderMap() { Map responseHeaderMap = new HashMap(); HttpFields httpFields = response.getHttpFields(); @@ -58,5 +61,5 @@ public Map buildResponseHeaderMap() { } return responseHeaderMap; } - + } diff --git a/logback-access/src/main/java/ch/qos/logback/access/pattern/ElapsedTimeConverter.java b/logback-access/src/main/java/ch/qos/logback/access/pattern/ElapsedTimeConverter.java new file mode 100644 index 0000000000..a2c1221196 --- /dev/null +++ b/logback-access/src/main/java/ch/qos/logback/access/pattern/ElapsedTimeConverter.java @@ -0,0 +1,24 @@ +/** + * Logback: the reliable, generic, fast and flexible logging framework. + * Copyright (C) 1999-2013, QOS.ch. All rights reserved. + * + * This program and the accompanying materials are dual-licensed under + * either the terms of the Eclipse Public License v1.0 as published by + * the Eclipse Foundation + * + * or (per the licensee's choosing) + * + * under the terms of the GNU Lesser General Public License version 2.1 + * as published by the Free Software Foundation. + */ +package ch.qos.logback.access.pattern; + +import ch.qos.logback.access.spi.IAccessEvent; + +public class ElapsedTimeConverter extends AccessConverter { + + public String convert(IAccessEvent accessEvent) { + return Long.toString(accessEvent.getElapsedTime()); + } + +} diff --git a/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java b/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java index 3b53b516bf..83ce5d3303 100755 --- a/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java +++ b/logback-access/src/main/java/ch/qos/logback/access/spi/AccessEvent.java @@ -13,6 +13,13 @@ */ package ch.qos.logback.access.spi; +import ch.qos.logback.access.AccessConstants; +import ch.qos.logback.access.pattern.AccessConverter; +import ch.qos.logback.access.servlet.Util; + +import javax.servlet.http.Cookie; +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; import java.io.Serializable; import java.util.ArrayList; import java.util.Enumeration; @@ -22,14 +29,6 @@ import java.util.TreeMap; import java.util.Vector; -import javax.servlet.http.Cookie; -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.HttpServletResponse; - -import ch.qos.logback.access.AccessConstants; -import ch.qos.logback.access.pattern.AccessConverter; -import ch.qos.logback.access.servlet.Util; - // Contributors: Joern Huxhorn (see also bug #110) /** @@ -37,15 +36,15 @@ * logging component instance is called in the container to log then a * AccessEvent instance is created. This instance is passed * around to the different logback components. - * + * * @author Ceki Gülcü * @author Sébastien Pennec */ public class AccessEvent implements Serializable, IAccessEvent { - + private static final long serialVersionUID = 866718993618836343L; - + private static final String EMPTY = ""; private transient final HttpServletRequest httpRequest; @@ -61,6 +60,7 @@ public class AccessEvent implements Serializable, IAccessEvent { String serverName; String requestContent; String responseContent; + long elapsedTime; Map requestHeaderMap; Map requestParameterMap; @@ -79,17 +79,18 @@ public class AccessEvent implements Serializable, IAccessEvent { private long timeStamp = 0; public AccessEvent(HttpServletRequest httpRequest, - HttpServletResponse httpResponse, ServerAdapter adapter) { + HttpServletResponse httpResponse, ServerAdapter adapter) { this.httpRequest = httpRequest; this.httpResponse = httpResponse; this.timeStamp = System.currentTimeMillis(); this.serverAdapter = adapter; + this.elapsedTime = calculateElapsedTime(); } /** - * Returns the underlying HttpServletRequest. After serialization the returned - * value will be null. - * + * Returns the underlying HttpServletRequest. After serialization the returned + * value will be null. + * * @return */ public HttpServletRequest getRequest() { @@ -97,9 +98,9 @@ public HttpServletRequest getRequest() { } /** - * Returns the underlying HttpServletResponse. After serialization the returned - * value will be null. - * + * Returns the underlying HttpServletResponse. After serialization the returned + * value will be null. + * * @return */ public HttpServletResponse getResponse() { @@ -293,7 +294,7 @@ public Map getRequestParameterMap() { /** * Attributes are not serialized - * + * * @param key */ public String getAttribute(String key) { @@ -313,12 +314,12 @@ public String[] getRequestParameter(String key) { if (httpRequest != null) { String[] value = httpRequest.getParameterValues(key); if (value == null) { - return new String[] { NA }; + return new String[]{ NA }; } else { return value; } } else { - return new String[] { NA }; + return new String[]{ NA }; } } @@ -358,6 +359,17 @@ public int getStatusCode() { return statusCode; } + public long getElapsedTime() { + return elapsedTime; + } + + private long calculateElapsedTime() { + if (serverAdapter.getRequestTimestamp() < 0) { + return -1; + } + return getTimeStamp() - serverAdapter.getRequestTimestamp(); + } + public String getRequestContent() { if (requestContent != null) { return requestContent; @@ -482,6 +494,7 @@ public void prepareForDeferredProcessing() { getRequestURL(); getServerName(); getTimeStamp(); + getElapsedTime(); getStatusCode(); getContentLength(); diff --git a/logback-access/src/main/java/ch/qos/logback/access/spi/IAccessEvent.java b/logback-access/src/main/java/ch/qos/logback/access/spi/IAccessEvent.java index 7837d1b8d0..d4bdff2088 100644 --- a/logback-access/src/main/java/ch/qos/logback/access/spi/IAccessEvent.java +++ b/logback-access/src/main/java/ch/qos/logback/access/spi/IAccessEvent.java @@ -13,13 +13,13 @@ */ package ch.qos.logback.access.spi; +import ch.qos.logback.core.spi.DeferredProcessingAware; + +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; import java.util.Enumeration; import java.util.List; import java.util.Map; -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.HttpServletResponse; - -import ch.qos.logback.core.spi.DeferredProcessingAware; // Contributors: Joern Huxhorn (see also bug #110) @@ -60,6 +60,11 @@ public interface IAccessEvent extends DeferredProcessingAware { */ long getTimeStamp(); + /** + * The time elapsed between receiving the request and logging it. + */ + long getElapsedTime(); + String getRequestURI(); /** diff --git a/logback-access/src/main/java/ch/qos/logback/access/spi/ServerAdapter.java b/logback-access/src/main/java/ch/qos/logback/access/spi/ServerAdapter.java index b28a5796d4..06df70d518 100644 --- a/logback-access/src/main/java/ch/qos/logback/access/spi/ServerAdapter.java +++ b/logback-access/src/main/java/ch/qos/logback/access/spi/ServerAdapter.java @@ -24,6 +24,7 @@ */ public interface ServerAdapter { + long getRequestTimestamp(); long getContentLength(); int getStatusCode(); Map buildResponseHeaderMap(); diff --git a/logback-access/src/main/java/ch/qos/logback/access/tomcat/TomcatServerAdapter.java b/logback-access/src/main/java/ch/qos/logback/access/tomcat/TomcatServerAdapter.java index 5e8cc1f184..260651ba08 100644 --- a/logback-access/src/main/java/ch/qos/logback/access/tomcat/TomcatServerAdapter.java +++ b/logback-access/src/main/java/ch/qos/logback/access/tomcat/TomcatServerAdapter.java @@ -13,24 +13,23 @@ */ package ch.qos.logback.access.tomcat; -import java.util.HashMap; -import java.util.Map; - +import ch.qos.logback.access.spi.ServerAdapter; import org.apache.catalina.connector.Request; import org.apache.catalina.connector.Response; -import ch.qos.logback.access.spi.ServerAdapter; +import java.util.HashMap; +import java.util.Map; /** * A tomcat specific implementation of the {@link ServerAdapter} interface. - * + * * @author Sébastien Pennec */ public class TomcatServerAdapter implements ServerAdapter { Request request; Response response; - + public TomcatServerAdapter(Request tomcatRequest, Response tomcatResponse) { this.request = tomcatRequest; this.response = tomcatResponse; @@ -44,7 +43,10 @@ public int getStatusCode() { return response.getStatus(); } - + public long getRequestTimestamp() { + return request.getCoyoteRequest().getStartTime(); + } + public Map buildResponseHeaderMap() { Map responseHeaderMap = new HashMap(); for (String key : response.getHeaderNames()) { diff --git a/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyServerAdapter.java b/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyServerAdapter.java index 886cce6bb1..5058f0bbb0 100644 --- a/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyServerAdapter.java +++ b/logback-access/src/test/java/ch/qos/logback/access/dummy/DummyServerAdapter.java @@ -13,20 +13,20 @@ */ package ch.qos.logback.access.dummy; -import java.util.Map; - import ch.qos.logback.access.spi.ServerAdapter; +import java.util.Map; + public class DummyServerAdapter implements ServerAdapter { DummyRequest request; DummyResponse response; - + public DummyServerAdapter(DummyRequest dummyRequest, DummyResponse dummyResponse) { this.request = dummyRequest; this.response = dummyResponse; } - + public long getContentLength() { return response.getContentCount(); } @@ -34,7 +34,11 @@ public long getContentLength() { public int getStatusCode() { return response.getStatus(); } - + + public long getRequestTimestamp() { + return -1; + } + public Map buildResponseHeaderMap() { return response.headerMap; } diff --git a/logback-site/src/site/pages/manual/layouts.html b/logback-site/src/site/pages/manual/layouts.html index f602d9a641..cce6850405 100755 --- a/logback-site/src/site/pages/manual/layouts.html +++ b/logback-site/src/site/pages/manual/layouts.html @@ -2060,7 +2060,15 @@

PatternLayout

Status code of the request.

- + + + D / elapsedTime + +

+ The time taken to serve the request, in milliseconds. +

+ + t / date diff --git a/pom.xml b/pom.xml index eb4957c9a2..2c11c84889 100755 --- a/pom.xml +++ b/pom.xml @@ -33,10 +33,9 @@ https://github.com/ceki/logback - git@github.com:ceki/logback.git + git@github.com:ceki/logback.git - logback-core @@ -188,6 +187,12 @@ ${tomcat.version}
+ + org.apache.tomcat + tomcat-coyote + ${tomcat.version} + + org.eclipse.jetty jetty-server @@ -468,7 +473,7 @@ - +