[LOG4J2-2420] switch the logging of request processing duration to TRACE level
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j-audit/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j-audit/commit/e333cda8 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j-audit/tree/e333cda8 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j-audit/diff/e333cda8 Branch: refs/heads/master Commit: e333cda808ffd3472477bdf48c119fcf256d3970 Parents: 390cbe9 Author: Andrei Ivanov <[email protected]> Authored: Mon Sep 17 11:41:42 2018 +0300 Committer: Andrei Ivanov <[email protected]> Committed: Mon Sep 17 11:41:42 2018 +0300 ---------------------------------------------------------------------- .../log4j/audit/rest/RequestContextFilter.java | 21 ++++++++++++------- .../rest/RequestContextHandlerInterceptor.java | 22 ++++++++++++-------- 2 files changed, 26 insertions(+), 17 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j-audit/blob/e333cda8/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextFilter.java ---------------------------------------------------------------------- diff --git a/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextFilter.java b/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextFilter.java index 02acf60..f60263b 100644 --- a/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextFilter.java +++ b/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextFilter.java @@ -79,11 +79,11 @@ public class RequestContextFilter implements Filter { if (servletRequest instanceof HttpServletRequest) { HttpServletRequest request = (HttpServletRequest) servletRequest; HttpServletResponse response = (HttpServletResponse) servletResponse; - logger.info("Starting request {}", request.getRequestURI()); + logger.trace("Starting request {}", request.getRequestURI()); try { - Enumeration headers = request.getHeaderNames(); + Enumeration<String> headers = request.getHeaderNames(); while (headers.hasMoreElements()) { - String name = (String) headers.nextElement(); + String name = headers.nextElement(); RequestContextMapping mapping = mappings.getMappingByHeader(name); logger.debug("Got Mapping:{} for Header:{}", mapping, name); if (mapping != null) { @@ -99,12 +99,17 @@ public class RequestContextFilter implements Filter { } } } - long start = System.nanoTime(); + long start = 0; + if (logger.isTraceEnabled()) { + start = System.nanoTime(); + } filterChain.doFilter(servletRequest, servletResponse); - long elapsed = System.nanoTime() - start; - StringBuilder sb = new StringBuilder("Request ").append(request.getRequestURI()).append(" completed in "); - ElapsedUtil.addElapsed(elapsed, sb); - logger.info(sb.toString()); + if (logger.isTraceEnabled()) { + long elapsed = System.nanoTime() - start; + StringBuilder sb = new StringBuilder("Request ").append(request.getRequestURI()).append(" completed in "); + ElapsedUtil.addElapsed(elapsed, sb); + logger.trace(sb.toString()); + } } catch (Throwable e) { logger.error("Application cascaded error", e); response.setStatus(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); http://git-wip-us.apache.org/repos/asf/logging-log4j-audit/blob/e333cda8/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextHandlerInterceptor.java ---------------------------------------------------------------------- diff --git a/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextHandlerInterceptor.java b/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextHandlerInterceptor.java index aed3124..114dbf5 100644 --- a/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextHandlerInterceptor.java +++ b/log4j-audit/log4j-audit-api/src/main/java/org/apache/logging/log4j/audit/rest/RequestContextHandlerInterceptor.java @@ -44,10 +44,10 @@ public class RequestContextHandlerInterceptor implements HandlerInterceptor { @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object o) throws Exception { - logger.info("Starting request {}", request.getRequestURI()); - Enumeration headers = request.getHeaderNames(); + logger.trace("Starting request {}", request.getRequestURI()); + Enumeration<String> headers = request.getHeaderNames(); while (headers.hasMoreElements()) { - String name = (String) headers.nextElement(); + String name = headers.nextElement(); RequestContextMapping mapping = mappings.getMappingByHeader(name); logger.debug("Got Mapping:{} for Header:{}", mapping, name); if (mapping != null) { @@ -63,17 +63,21 @@ public class RequestContextHandlerInterceptor implements HandlerInterceptor { } } } - startTime.set(System.nanoTime()); + if (logger.isTraceEnabled()) { + startTime.set(System.nanoTime()); + } return true; } @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object o, ModelAndView modelAndView) throws Exception { - long elapsed = System.nanoTime() - startTime.get(); - StringBuilder sb = new StringBuilder("Request ").append(request.getRequestURI()).append(" completed in "); - ElapsedUtil.addElapsed(elapsed, sb); - logger.info(sb.toString()); - startTime.remove(); + if (logger.isTraceEnabled()) { + long elapsed = System.nanoTime() - startTime.get(); + StringBuilder sb = new StringBuilder("Request ").append(request.getRequestURI()).append(" completed in "); + ElapsedUtil.addElapsed(elapsed, sb); + logger.trace(sb.toString()); + startTime.remove(); + } } @Override
