1.1 mdc日志打印全局控制
1.1.1 logback配置
<property name="log.pattern" value="%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX}%level [%thread] [%logger{50}:%line] [uuid:%X{operation_id}] %msg%n"></property>
1.1.2 filter配置
1 @WebFilter(filterName="logFilter", urlPatterns="/*") 2 3 public class LogFilter implements Filter { 4 5 private static final Logger log = LoggerFactory.getLogger(LogInterceptor.class); 6 7 8 9 @Override 10 11 public void init(FilterConfig filterConfig) throws ServletException { 12 13 log.info("---------log filter init"); 14 15 } 16 17 18 19 @Override 20 21 public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) 22 23 throws IOException, ServletException { 24 25 log.info("log filter doFilter"); 26 27 ServletRequest requestWrapper = null; 28 29 requestWrapper = new MyRequestWrapper((HttpServletRequest) request); 30 31 chain.doFilter(requestWrapper, response); 32 33 } 34 35 36 37 @Override 38 39 public void destroy() { 40 41 log.info("-------------log filter destroy"); 42 43 44 45 } 46 47 }
同時需要在啟動類加上掃描配置
1 @SpringBootApplication() 2 3 @ServletComponentScan //掃描過濾器 4 5 public class LogApplication { 6 7 8 9 public static void main(String[] args) { 10 11 Tools.setMdc(Tools.getUuid()); 12 13 SpringApplication.run(LogApplication.class, args); 14 15 } 16 17 }
1.1.3 自定義httpServletRequest
1 public class MyRequestWrapper extends HttpServletRequestWrapper { 2 3 private String body; 4 private String requestMethod; 5 6 public MyRequestWrapper(HttpServletRequest request) throws IOException { 7 super(request); 8 StringBuilder sb = new StringBuilder(); 9 String line = null; 10 BufferedReader reader = request.getReader(); 11 requestMethod = request.getMethod(); 12 13 while((line = reader.readLine()) != null) { 14 sb.append(line); 15 } 16 body = sb.toString(); 17 } 18 private boolean isPostOrPut() { 19 return "POST".equalsIgnoreCase(requestMethod) || "PUT".equalsIgnoreCase(requestMethod); 20 } 21 @Override 22 public String getQueryString() { 23 if(isPostOrPut()) { 24 return body; 25 } else { 26 return super.getQueryString(); 27 } 28 } 29 @Override 30 public ServletInputStream getInputStream() throws IOException { 31 ByteArrayInputStream bais = new ByteArrayInputStream(body.getBytes(CommonVar.DEFAULT_CHARSET)); 32 return new ServletInputStream() { 33 34 @Override 35 public int read() throws IOException { 36 return bais.read(); 37 } 38 39 @Override 40 public boolean isFinished() { 41 return bais.available()==0; 42 } 43 44 @Override 45 public boolean isReady() { 46 return true; 47 } 48 49 @Override 50 public void setReadListener(ReadListener listener) { 51 52 } 53 }; 54 } 55 }
1.1.4 interceptor配置
1 public class LogInterceptor implements HandlerInterceptor{ 2 private static final Logger log = LoggerFactory.getLogger(LogInterceptor.class); 3 4 private static final String REQUEST_START_TIME = "request_start_time"; 5 6 @Override 7 public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) 8 throws Exception { 9 setMdc(request); 10 logRequestMsg(request); 11 request.setAttribute(REQUEST_START_TIME, System.currentTimeMillis()); 12 System.out.println("preHandle"); 13 return true; 14 } 15 16 @Override 17 public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, 18 ModelAndView modelAndView) throws Exception { 19 HandlerInterceptor.super.postHandle(request, response, handler, modelAndView); 20 System.out.println("postHandle"); 21 } 22 23 @Override 24 public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) 25 throws Exception { 26 logRequestEnd(request); 27 Tools.removeMdc(); 28 System.out.println("afterCompletion"); 29 } 30 private void setMdc(HttpServletRequest request) { 31 MDC.put("operation_id", Tools.getUuid()); 32 } 33 /** 34 * log request url and request cost time 35 * @param request 36 */ 37 private void logRequestEnd(HttpServletRequest request) { 38 long startTime = (long) request.getAttribute(REQUEST_START_TIME); 39 long endTime = System.currentTimeMillis(); 40 long interval = endTime - startTime; 41 log.debug("request_end: {}, cost time:{}ms",request.getRequestURL(), interval); 42 } 43 /** 44 * log request url and param 45 * @param request 46 * @throws IOException 47 */ 48 private void logRequestMsg(HttpServletRequest request) throws IOException { 49 String url = request.getRequestURL().toString(); 50 String method = request.getMethod(); 51 String query = request.getQueryString(); 52 log.debug("request_receive: url:{},method:{},query:{}", url, method, query); 53 } 54 }
新建config類將interceptor注冊到spring
1 @Configuration 2 public class LogWebAppConfig implements WebMvcConfigurer { 3 4 @Override 5 public void addInterceptors(InterceptorRegistry registry) { 6 registry.addInterceptor(new LogInterceptor()).addPathPatterns("/**"); 7 WebMvcConfigurer.super.addInterceptors(registry); 8 } 9 10 }
1.1.5 總體說明
1.1.5.1 功能說明
打印請求url,請求類型,請求參數
打印所有的請求耗時統計
使用logback的MDC機制打印日志,不了解的自行百度
1.1.5.2 問題(功能1)
post,put請求的參數在流里面,只能讀取一次,如果在攔截器中讀取了流,流就空了,controller層讀取會報錯。報錯信息:
getReader() has already been called for this request preHandle
1.1.5.3 解決思想(功能1)
自定義一個httpServletRequest,提供post參數讀取的方法(讀完流之后將數據重新寫回流中),然后重寫getQueryString()方法。這個方法是get等請求獲取參數的方式,在這里同樣提供post請求的參數,減輕調用者的負擔
使用過濾器過濾所有的請求,替換httpServletRequest為自定義的request,傳遞給下一條鏈
由於過濾器已經替換httpServletRequest,那么這里拿到的就是自定義的httpServletRequest,所以可以不用區分請求類型,直接調用getQueryString() 獲取請求參數
1.1.5.4 其它功能實現
打印所有的請求耗時統計
實現方式是在攔截器中為request增加一個字段(本文是request_start_time),記錄當前時間,在方法調用完成后從request中拿到這個字段(起始時間),根據當前時間算出調用時間間隔。
使用logback打印MDC日志
需要在logback中配置這么一個字段(本文是operation_id),然后在攔截器的入口為這個字段設置一個uuid即可。作用是每個請求對應的日志都有這個uuid。mdc實現原理是threadLocal,所以對於線程池需要額外處理方式。
1.1.6 結果
2018-12-08T11:46:23.916+08:00 INFO [localhost-startStop-1] [com.hikvision.log.common.filter.LogInterceptor:23] [uuid:] ---------log filter init
2018-12-08T11:46:33.307+08:00 INFO [http-nio-8080-exec-3] [com.hikvision.log.common.filter.LogInterceptor:29] [uuid:] log filter doFilter
2018-12-08T11:46:33.307+08:00 INFO [http-nio-8080-exec-2] [com.hikvision.log.common.filter.LogInterceptor:29] [uuid:] log filter doFilter
2018-12-08T11:46:33.307+08:00 INFO [http-nio-8080-exec-1] [com.hikvision.log.common.filter.LogInterceptor:29] [uuid:] log filter doFilter
2018-12-08T11:46:33.326+08:00 DEBUG [http-nio-8080-exec-1] [com.hikvision.log.common.filter.LogInterceptor:67] [uuid:0002] request_receive: url:http://127.0.0.1:8080/settings,method:GET,query:null
preHandle
2018-12-08T11:46:33.326+08:00 DEBUG [http-nio-8080-exec-2] [com.hikvision.log.common.filter.LogInterceptor:67] [uuid:0003] request_receive: url:http://127.0.0.1:8080/meta,method:GET,query:null
preHandle
2018-12-08T11:46:33.328+08:00 DEBUG [http-nio-8080-exec-3] [com.hikvision.log.common.filter.LogInterceptor:67] [uuid:0004] request_receive: url:http://127.0.0.1:8080/session,method:GET,query:null
preHandle
2018-12-08T11:46:33.368+08:00 INFO [http-nio-8080-exec-2] [com.hikvision.log.web.restful.CheckDiskController:45] [uuid:0003] Get availableSpace is:173138524
2018-12-08T11:46:33.369+08:00 INFO [http-nio-8080-exec-2] [com.hikvision.log.web.restful.CheckDiskController:49] [uuid:0003] Get omcVersion is:
postHandle
2018-12-08T11:46:33.453+08:00 DEBUG [http-nio-8080-exec-3] [com.hikvision.log.common.filter.LogInterceptor:56] [uuid:0004] request_end: http://127.0.0.1:8080/session, cost time:124ms
afterCompletion
postHandle
2018-12-08T11:46:33.455+08:00 DEBUG [http-nio-8080-exec-2] [com.hikvision.log.common.filter.LogInterceptor:56] [uuid:0003] request_end: http://127.0.0.1:8080/meta, cost time:129ms
afterCompletion
postHandle
2018-12-08T11:46:33.473+08:00 DEBUG [http-nio-8080-exec-1] [com.hikvision.log.common.filter.LogInterceptor:56] [uuid:0002] request_end: http://127.0.0.1:8080/settings, cost time:147ms
afterCompletion