墨菲定律:當你覺得一個地方可能有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。
參考了: