@Ignore @Test public void testPostHandle_NormalLogOutput_ViewNotNull() { long startTime = System.nanoTime(); request.setAttribute(TraceLoggingInterceptor.class.getName() + ".startTime", startTime); HandlerMethod paramHandler = new HandlerMethod(controller, method[3]); View view = mock(View.class); when(model.getView()).thenReturn(view); try { interceptor.postHandle(request, response, paramHandler, model); } catch (Exception e) { fail("illegal case"); } String expectedLogStr = "TraceLoggingInterceptorController.second(SampleForm,Model)->"; verifyLogging(expectedLogStr, ImmutableList.of(Level.TRACE), 2); }
@Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) { if (!(handler instanceof HandlerMethod)) { return; } long startTime = 0; if (request.getAttribute(START_ATTR) != null) { startTime = ((Long) request.getAttribute(START_ATTR)).longValue(); } long handlingTime = System.nanoTime() - startTime; request.removeAttribute(START_ATTR); request.setAttribute(HANDLING_ATTR, handlingTime); String formattedHandlingTime = String.format("%1$,3d", handlingTime); boolean isWarnHandling = handlingTime > warnHandlingNanos; if (!isEnabledLogLevel(isWarnHandling)) { return; } HandlerMethod handlerMethod = (HandlerMethod) handler; Method m = handlerMethod.getMethod(); Object view = null; Map<String, Object> model = null; if (modelAndView != null) { view = modelAndView.getView(); model = modelAndView.getModel(); if (view == null) { view = modelAndView.getViewName(); } } logger.trace("[END CONTROLLER ] {}.{}({})-> view={}, model={}", new Object[] { m.getDeclaringClass().getSimpleName(), m .getName(), buildMethodParams(handlerMethod), view, model }); String handlingTimeMessage = "[HANDLING TIME ] {}.{}({})-> {} ns"; if (isWarnHandling) { logger.warn(handlingTimeMessage + " > {}", new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime, warnHandlingNanos }); } else { logger.trace(handlingTimeMessage, new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime }); } }
TraceLoggingInterceptor implements HandlerInterceptor { @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) { if (!(handler instanceof HandlerMethod)) { return; } long startTime = 0; if (request.getAttribute(START_ATTR) != null) { startTime = ((Long) request.getAttribute(START_ATTR)).longValue(); } long handlingTime = System.nanoTime() - startTime; request.removeAttribute(START_ATTR); request.setAttribute(HANDLING_ATTR, handlingTime); String formattedHandlingTime = String.format("%1$,3d", handlingTime); boolean isWarnHandling = handlingTime > warnHandlingNanos; if (!isEnabledLogLevel(isWarnHandling)) { return; } HandlerMethod handlerMethod = (HandlerMethod) handler; Method m = handlerMethod.getMethod(); Object view = null; Map<String, Object> model = null; if (modelAndView != null) { view = modelAndView.getView(); model = modelAndView.getModel(); if (view == null) { view = modelAndView.getViewName(); } } logger.trace("[END CONTROLLER ] {}.{}({})-> view={}, model={}", new Object[] { m.getDeclaringClass().getSimpleName(), m .getName(), buildMethodParams(handlerMethod), view, model }); String handlingTimeMessage = "[HANDLING TIME ] {}.{}({})-> {} ns"; if (isWarnHandling) { logger.warn(handlingTimeMessage + " > {}", new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime, warnHandlingNanos }); } else { logger.trace(handlingTimeMessage, new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime }); } } }
TraceLoggingInterceptor implements HandlerInterceptor { @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) { if (!(handler instanceof HandlerMethod)) { return; } long startTime = 0; if (request.getAttribute(START_ATTR) != null) { startTime = ((Long) request.getAttribute(START_ATTR)).longValue(); } long handlingTime = System.nanoTime() - startTime; request.removeAttribute(START_ATTR); request.setAttribute(HANDLING_ATTR, handlingTime); String formattedHandlingTime = String.format("%1$,3d", handlingTime); boolean isWarnHandling = handlingTime > warnHandlingNanos; if (!isEnabledLogLevel(isWarnHandling)) { return; } HandlerMethod handlerMethod = (HandlerMethod) handler; Method m = handlerMethod.getMethod(); Object view = null; Map<String, Object> model = null; if (modelAndView != null) { view = modelAndView.getView(); model = modelAndView.getModel(); if (view == null) { view = modelAndView.getViewName(); } } logger.trace("[END CONTROLLER ] {}.{}({})-> view={}, model={}", new Object[] { m.getDeclaringClass().getSimpleName(), m .getName(), buildMethodParams(handlerMethod), view, model }); String handlingTimeMessage = "[HANDLING TIME ] {}.{}({})-> {} ns"; if (isWarnHandling) { logger.warn(handlingTimeMessage + " > {}", new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime, warnHandlingNanos }); } else { logger.trace(handlingTimeMessage, new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime }); } }  }
TraceLoggingInterceptor implements HandlerInterceptor { @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) { if (!(handler instanceof HandlerMethod)) { return; } long startTime = 0; if (request.getAttribute(START_ATTR) != null) { startTime = ((Long) request.getAttribute(START_ATTR)).longValue(); } long handlingTime = System.nanoTime() - startTime; request.removeAttribute(START_ATTR); request.setAttribute(HANDLING_ATTR, handlingTime); String formattedHandlingTime = String.format("%1$,3d", handlingTime); boolean isWarnHandling = handlingTime > warnHandlingNanos; if (!isEnabledLogLevel(isWarnHandling)) { return; } HandlerMethod handlerMethod = (HandlerMethod) handler; Method m = handlerMethod.getMethod(); Object view = null; Map<String, Object> model = null; if (modelAndView != null) { view = modelAndView.getView(); model = modelAndView.getModel(); if (view == null) { view = modelAndView.getViewName(); } } logger.trace("[END CONTROLLER ] {}.{}({})-> view={}, model={}", new Object[] { m.getDeclaringClass().getSimpleName(), m .getName(), buildMethodParams(handlerMethod), view, model }); String handlingTimeMessage = "[HANDLING TIME ] {}.{}({})-> {} ns"; if (isWarnHandling) { logger.warn(handlingTimeMessage + " > {}", new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime, warnHandlingNanos }); } else { logger.trace(handlingTimeMessage, new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime }); } }  @Override boolean preHandle(HttpServletRequest request,
            HttpServletResponse response, Object handler); @Override void postHandle(HttpServletRequest request,
            HttpServletResponse response, Object handler,
            ModelAndView modelAndView); void setWarnHandlingNanos(long warnHandlingNanos); }
TraceLoggingInterceptor implements HandlerInterceptor { @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) { if (!(handler instanceof HandlerMethod)) { return; } long startTime = 0; if (request.getAttribute(START_ATTR) != null) { startTime = ((Long) request.getAttribute(START_ATTR)).longValue(); } long handlingTime = System.nanoTime() - startTime; request.removeAttribute(START_ATTR); request.setAttribute(HANDLING_ATTR, handlingTime); String formattedHandlingTime = String.format("%1$,3d", handlingTime); boolean isWarnHandling = handlingTime > warnHandlingNanos; if (!isEnabledLogLevel(isWarnHandling)) { return; } HandlerMethod handlerMethod = (HandlerMethod) handler; Method m = handlerMethod.getMethod(); Object view = null; Map<String, Object> model = null; if (modelAndView != null) { view = modelAndView.getView(); model = modelAndView.getModel(); if (view == null) { view = modelAndView.getViewName(); } } logger.trace("[END CONTROLLER ] {}.{}({})-> view={}, model={}", new Object[] { m.getDeclaringClass().getSimpleName(), m .getName(), buildMethodParams(handlerMethod), view, model }); String handlingTimeMessage = "[HANDLING TIME ] {}.{}({})-> {} ns"; if (isWarnHandling) { logger.warn(handlingTimeMessage + " > {}", new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime, warnHandlingNanos }); } else { logger.trace(handlingTimeMessage, new Object[] { m .getDeclaringClass().getSimpleName(), m.getName(), buildMethodParams(handlerMethod), formattedHandlingTime }); } }  @Override boolean preHandle(HttpServletRequest request,
            HttpServletResponse response, Object handler); @Override void postHandle(HttpServletRequest request,
            HttpServletResponse response, Object handler,
            ModelAndView modelAndView); void setWarnHandlingNanos(long warnHandlingNanos);  }