1. 程式人生 > >springboot filter and interceptor實戰之mdc日誌列印

springboot filter and interceptor實戰之mdc日誌列印

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配置

@WebFilter(filterName="logFilter", urlPatterns="/*")

public class LogFilter implements Filter {

    private static final Logger log = LoggerFactory.getLogger(LogInterceptor.class);

   

    @Override

    public void init(FilterConfig filterConfig) throws ServletException {

        log

.info("---------log filter init");

    }

 

    @Override

    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)

            throws IOException, ServletException {

        log.info("log filter doFilter");

        ServletRequest requestWrapper = null;

        requestWrapper = new MyRequestWrapper((HttpServletRequest) request);

        chain.doFilter(requestWrapper, response);

    }

 

    @Override

    public void destroy() {

        log.info("-------------log filter destroy");

       

    }

}

同時需要在啟動類加上掃描配置

@SpringBootApplication()

@ServletComponentScan       //掃描過濾器

public class LogApplication {

 

   public static void main(String[] args) {

       Tools.setMdc(Tools.getUuid());

      SpringApplication.run(LogApplication.class, args);

   }

}

1.1.3    自定義httpServletRequest

public class MyRequestWrapper extends HttpServletRequestWrapper {

 

    private String body;

    private String requestMethod;

   

    public MyRequestWrapper(HttpServletRequest request) throws IOException {

        super(request);

        StringBuilder sb = new StringBuilder();

        String line = null;

        BufferedReader reader = request.getReader();

        requestMethod = request.getMethod();

       

        while((line = reader.readLine()) != null) {

            sb.append(line);

        }

        body = sb.toString();

    }

    private boolean isPostOrPut() {

        return "POST".equalsIgnoreCase(requestMethod) || "PUT".equalsIgnoreCase(requestMethod);

    }

    @Override

    public String getQueryString() {

        if(isPostOrPut()) {

            return body;

        } else {

            return super.getQueryString();

        }

    }

    @Override

    public ServletInputStream getInputStream() throws IOException {

        ByteArrayInputStream bais = new ByteArrayInputStream(body.getBytes(CommonVar.DEFAULT_CHARSET));

        return new ServletInputStream() {

           

            @Override

            public int read() throws IOException {

                return bais.read();

            }

 

            @Override

            public boolean isFinished() {

                return bais.available()==0;

            }

 

            @Override

            public boolean isReady() {

                return true;

            }

 

            @Override

            public void setReadListener(ReadListener listener) {

               

            }

        };

    }

}

1.1.4    interceptor配置

public class LogInterceptor implements HandlerInterceptor{

    private static final Logger log = LoggerFactory.getLogger(LogInterceptor.class);

   

    private static final String REQUEST_START_TIME = "request_start_time";

   

    @Override

    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)

            throws Exception {

        setMdc(request);

        logRequestMsg(request);

        request.setAttribute(REQUEST_START_TIME, System.currentTimeMillis());

        System.out.println("preHandle");

        return true;

    }

 

    @Override

    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler,

            ModelAndView modelAndView) throws Exception {

        HandlerInterceptor.super.postHandle(request, response, handler, modelAndView);

        System.out.println("postHandle");

    }

 

    @Override

    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)

            throws Exception {

        logRequestEnd(request);

        Tools.removeMdc();

        System.out.println("afterCompletion");

    }

    private void setMdc(HttpServletRequest request) {

        MDC.put("operation_id", Tools.getUuid());

    }

    /**

     * log request url and request cost time

     * @param request

     */

    private void logRequestEnd(HttpServletRequest request) {

        long startTime = (long) request.getAttribute(REQUEST_START_TIME);

        long endTime = System.currentTimeMillis();

        long interval = endTime - startTime;

        log.debug("request_end: {}, cost time:{}ms",request.getRequestURL(), interval);

    }

    /**

     * log request url and param

     * @param request

     * @throws IOException

     */

    private void logRequestMsg(HttpServletRequest request) throws IOException {

        String url = request.getRequestURL().toString();

        String method = request.getMethod();

        String query = request.getQueryString();

        log.debug("request_receive: url:{},method:{},query:{}", url, method, query);

    }

}

新建config類將interceptor註冊到spring

@Configuration

public class LogWebAppConfig implements WebMvcConfigurer  {

 

    @Override

    public void addInterceptors(InterceptorRegistry registry) {

        registry.addInterceptor(new LogInterceptor()).addPathPatterns("/**");

        WebMvcConfigurer.super.addInterceptors(registry);

    }

   

}

 

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