问题和背景:
遇到问题,一开始死活找不到原因,也找不到error 堆栈.
找不到原因的原因,
1. 这个堆栈是spring mvc本身打印的.
2.更关键的是这个堆栈竟然是用debug打印出来的
3. 但是代码里把非biz 打印的error,都统一打印到了 系统_other.log中
具体细节:
1. 失败后自动转成 400.html (500.html)的逻辑探究
1.1 先了解DispatcherServlet 框架代驾. 先pre 再调用,最后 post
1.2 一旦失败后,打印堆栈,然后转成500
2018-12-14 19:33:58,535 [DEBUG] Resolving exception from handler [public handler.method: java.lang.reflect.UndeclaredThrowableException DefaultHandlerExceptionResolver 0b0d7b1f15447872381858935e086e
含堆栈
2018-12-14 19:33:58,535 [DEBUG] Could not complete request DispatcherServlet 0b0d7b1f15447872381858935e086e
2018-12-14 19:33:58,536 [DEBUG] DispatcherServlet with name 'dispatcher' processing GET request for [/500.htm] DispatcherServlet 0b0d7b1f15447872381858935e086e
2018-12-14 18:05:31,864 [DEBUG] DispatcherServlet with name 'dispatcher' processing GET request for [/500.htm] DispatcherServlet 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,864 [DEBUG] Looking up handler method for path /500.htm RequestMappingHandlerMapping 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,864 [DEBUG] Did not find handler method for [/500.htm] RequestMappingHandlerMapping 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,864 [DEBUG] Matching patterns for request [/500.htm] are [/**] SimpleUrlHandlerMapping 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,864 [DEBUG] URI Template variables for request [/500.htm] are {} SimpleUrlHandlerMapping 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,864 [DEBUG] Mapping [/500.htm] to HandlerExecutionChain with handler [org.springframework.web.servlet.resource.DefaultServletHttpRequestHandler@6773adcf] and 1 interceptor SimpleUrlHandlerMapping 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,864 [DEBUG] Last-Modified value for [/500.htm] is: -1 DispatcherServlet 0b0d7b1f15447819316421804e0871
2018-12-14 18:05:31,865 [DEBUG] Null ModelAndView returned to DispatcherServlet with name 'dispatcher': assuming HandlerAdapter completed request handling DispatcherServlet 0b0aac0a15447819318651431d08dd
2018-12-14 18:05:31,865 [DEBUG] Successfully completed request DispatcherServlet 0b0aac0a15447819318651431d08dd
附录
logback.xml 的自动把error日志过滤出来. <!-- 系统日志 --> <root level="${lippi_meetingroom_log_level}"> <!-- 不要把业务日志记录在这里 --> <appender-ref ref="ROOT_APPENDE_OTHER"/> <!-- 要求配置报警,出现一个error就报 --> <appender-ref ref="ROOT_ERROR_APPENDER" /> </root>
<appender name="ROOT_ERROR_APPENDER_SYNC" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>${lippi_meetingroom_log_output}/lippi_meetingroom_error.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>${lippi_meetingroom_log_output}/lippi_meetingroom_error.log.%d{yyyy-MM-dd}</fileNamePattern> </rollingPolicy> <encoder> <pattern>%date [%level] [${lippi_meetingroom_current_environment}] %msg %X{EAGLE_TRACE_ID}%n</pattern> <charset>UTF-8</charset> </encoder> <filter class="ch.qos.logback.classic.filter.LevelFilter"> <level>ERROR</level> <onMatch>ACCEPT</onMatch> <onMismatch>DENY</onMismatch> </filter> </appender> <appender name ="ROOT_ERROR_APPENDER" class= "ch.qos.logback.classic.AsyncAppender"> <!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志 --> <discardingThreshold>0</discardingThreshold> <!-- 更改默认的队列的深度,该值会影响性能.默认值为256 --> <queueSize>1024</queueSize> <neverBlock>true</neverBlock> <!-- 添加附加的appender,最多只能添加一个 --> <appender-ref ref ="ROOT_ERROR_APPENDER_SYNC"/> </appender>
日志:
2018-12-14 19:33:58,203 [DEBUG] method 0b0d7b1f15447872381858935e086e
java.lang.Exception: null
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:219)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:745)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:686)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:936)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:827)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:621)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:812)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
======
2018-12-14 19:36:11,198 [DEBUG] Filter postHandle
java.lang.Exception: null
at org.springframework.web.servlet.HandlerExecutionChain.applyPostHandle(HandlerExecutionChain.java:149)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:934)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:936)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:827)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:621)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:812)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at com.taobao.eagleeye.EagleEyeFilter.doFilter(EagleEyeFilter.java:106)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:410)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1043)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:603)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1721)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1679)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1147)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:622)
at java.lang.Thread.run(Thread.java:834)
------