1. 程式人生 > >墨菲定律:當你覺得一個地方可能有bug,那麼這個地方就會有bug----順帶了解下Tomcat那少有人注意的localhost.log

墨菲定律:當你覺得一個地方可能有bug,那麼這個地方就會有bug----順帶了解下Tomcat那少有人注意的localhost.log

一、問題概述

題目有點長,但應該值得後端java們瞭解下有點小坑的localhost.log,讓我長話短說。

博主是搞java後端的。後臺是很簡單的spring mvc + spring框架。

今天測試一個Controller層的介面,但是斷點一直進不來。

我做的改動也不大,新增了mqMsgFactoryUtils這個spring 託管的bean,(程式碼是接手別人的,所以看著原來的部分有點臃腫,就提煉了mqMsgFactoryUtils公共類

,mqMsgFactoryUtils需要依賴bean,就把自己也搞成bean了)。

如下:

 斷點進不來怎麼辦,作為一個工作了幾年的老司機,思路還是清晰的,直接在filter打斷點,發現可以進來。

然後在aop層打斷點,aop層有個切controller層方法的@before方法,主要是一些額外的引數校驗。

在aop層的斷點裡,程式碼走到如下位置,return了:

因為這個類也是剛被我重構的,我一想,難道是用了return後,像spring的攔截器一樣,直接把request返回了嗎?

於是我把針對這個aop類的修改回退了,結果發現問題還是存在。

這就神了,filter正常,對aop的修改也回退了,然而controller還是進不去。

二、問題原因

經過上面一番折騰了,午睡是沒了,很困,暫時沒什麼思路。然後又發起了一次request,發現問題還是那樣。

但是,這次,我點開了下面的日誌:(圖片小的話,可以在新的tab開啟就清晰了)

哈?這裡還有個日誌?一看還真就和該問題有關係。

至此,真相大白。

之前剛接手這份程式碼時,我就很奇怪為什麼很多controller頭上要搞個這:

當時感覺新接手程式碼,覺得“一切都是有因有果”,可能是之前的哥們覺得這個controller類有可能有併發問題,執行緒同步問題啥的。

加就加吧,我又不動它。雖然感覺有點和以前不一樣,但應該沒啥大問題。無非是controller不是單例罷了。

多建立幾個沒什麼大不了。

以上就是我之前的心態。直到這次遇到這個問題。

有些同學估計沒懂,我這裡解釋下,當controller加了prototype後,就不會在應用啟動時就將該controller 單例bean建立好,而是等到需要的時候再去建立。

什麼時候是需要的時候呢,就是請求進來,經spring mvc的handlerMappingAdapter分析,需要路由到該controller時,發現該bean的bean definition的scope為prototype,

就會去建立該controller。

建立的時候,就該注入各service了。但是恰好,這個service的包沒在掃描範圍內(我單獨加了個包,然後我們的配置檔案不是配置成只掃描base package的,是掃描一系列的具體package)。

那麼,沒掃描到這個bean,依賴不滿足,當然,這個controller就建立失敗了。

於是拋異常。

三、異常日誌為啥打這兒呢

接著說問題。原因清楚了之後,我又試了一遍:去掉prototype,重啟應用,果然,這次啟動失敗了。

然後,大家估計有疑問了,你有異常,日誌打這個localhost.log是什麼意思,一般人(比如我),主要關注的是應用的console輸出面板。

我就想,這個異常資訊,打到這個檔案?為什麼?這個檔案幹嘛的?

查了點資料,發現google比百度資料還少點。。。將就看吧。

localhost.{yyyy-MM-dd}.log主要是應用初始化(listener, filter, servlet)未處理的異常最後被tomcat捕獲而輸出的日誌 

這麼說,這是spring 建立bean失敗,直接向tomcat丟擲了異常。這下面是堆疊。

02-Nov-2018 16:36:17.882 嚴重 [http-nio-8080-exec-4] org.apache.catalina.core.ApplicationDispatcher.invoke Servlet.service() for servlet [DispatcherServlet] threw exception
 org.springframework.beans.factory.NoSuchBeanDefinitionException: No qualifying bean of type 'com.ceiec.service.mqmsg.MqMsgFactoryUtils' available: expected at least 1 bean which qualifies as autowire candidate. Dependency annotations: {@org.springframework.beans.factory.annotation.Autowired(required=true)}
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.raiseNoMatchingBeanFound(DefaultListableBeanFactory.java:1486)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1104)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1264)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:325)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.web.method.HandlerMethod.createWithResolvedBean(HandlerMethod.java:259)
    at org.springframework.web.servlet.handler.AbstractHandlerMethodMapping.getHandlerInternal(AbstractHandlerMethodMapping.java:323)
    at org.springframework.web.servlet.handler.AbstractHandlerMethodMapping.getHandlerInternal(AbstractHandlerMethodMapping.java:61)
    at org.springframework.web.servlet.handler.AbstractHandlerMapping.getHandler(AbstractHandlerMapping.java:352)
    at org.springframework.web.servlet.DispatcherServlet.getHandler(DispatcherServlet.java:1156)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:936)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:728)
    at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:467)
    at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:392)
    at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:311)
    at com.ceiec.webservice.filter.WebRequestFilter.doFilterInternal(WebRequestFilter.java:116)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.orm.hibernate4.support.OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:151)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

剛開始,我感覺是不是spring這麼處理有點不對,直接將異常拋給tomcat。但是轉念一想,啟動時,建立bean失敗的話,也是會直接拋給tomcat,tomcat拋給使用者來處理。

這麼一想,可以理解。但是還是感覺:為啥不能在應用裡打個日誌呢?打個日誌,起碼一下就找到問題了。

四、關於tomcat的日誌

這裡只簡單介紹下幾種日誌吧。

catalina.out,這個大家都知道,stdout和stderr都會打到這。(也就是應用的System.out.println,以及tomcat自己的stdout和stderr)

然後是logs目錄下的另外幾種日誌,其中,紅色箭頭指向的,很重要(當然,以前只覺得localhost_access.log重要,經過今天這一課嘛。。。):

這幾個日誌在哪配置的呢?

一般在tomcat安裝目錄下的conf下的logging.properties.

但是,tomcat這麼完備的伺服器,不可能這麼easy。

實際是這樣的,(來自於官方文件,連結會在最後給出來):

1、全域性模式:

那就是catalina.base下的conf下的logging.properties了,也可以通過啟動時通過java.util.logging.config.file來指定。如果該檔案不可讀或沒配置,會使用javahome下的lib下的該檔案。

2、在應用中,預設位於WEB-INF/classes/logging.properties.

Tomcat預設的日誌框架為juli。基於java.util.logging改的。也可以換成log4j,操作不繁瑣,連結如下:

 五、心得體會

這裡,讓我們再次記得:如果出了bug,記得看看localhost.log。

參考了: