2019獨角獸企業重金招聘Python工程師標準>>>

Spring MVC是美團點評很多團隊使用的Web框架。在基于Spring MVC的項目里，注解的使用幾乎遍布在項目中的各個模塊，有Java提供的注解，如：@Override、@Deprecated等；也有Spring提供的注解，如：@Controller、@Service、@Autowired等；同時還可能有自定義注解等。注解一方面可以作為標記說明使用；另一方面也能幫助我們省去一些配置工作，加快開發速度。注解就像語法糖一樣，我有時候會“隨心所欲”的把它帶入到代碼里，一直樂 (hú)此(lǐ)不(hú)疲(tú)。直到筆者遇到了一個由@Service注解引發的空指針問題時，才真正意識到亂用注解的危害，同時也有了下文的深入探討！

事件起因

接到業務方需求需要封裝上游的一個HTTP接口來提供系統內的服務支持，我封裝這個接口并通過本地單元測試后就部署到測試環境中開始測試了。沒想到一測試就報NullPointerException異常，異常棧信息如下：

ERROR [qtp384587033-86] 2015-12-21 16:29:00.905 com.meituan.trip.mobile.hermes.common.utils.HttpClientUtils.doRequest(HttpClientUtils.java:359) HttpClientUtils.doRequest invoke get error, url:nullmt/api/test/v1/query?id=123456org.apache.http.client.ClientProtocolExceptionat org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:186) ~[httpclient-4.3.5.jar:4.3.5]…Caused by: org.apache.http.ProtocolException: Target host is not specified...

從異常棧上可以清楚的看出錯誤原因，是由于請求地址不標準（以 http:// 開頭）導致的。這個錯誤其實很詭異，因為我已經在配置文件中通過XML的方式注入URL屬性值了，而且在本地寫單元測試都能通過，為什么還會屬性注入失敗呢？經過反復的檢查和嘗試，發現只要在class的定義上加@Service注解，問題就會重現，去掉則正常運行。

問題定位

在保留@Service注解的情況下，重新在本地部署并啟動工程，從啟動日志上發現此實現Bean被替換過：

INFO [main] 2015-12-21 16:28:47.078 org.springframework.beans.factory.support.DefaultListableBeanFactory.registerBeanDefinition(DefaultListableBeanFactory.java:665) Overriding bean definition for bean 'queryPartnerImpl': replacing [Generic bean: class [com.meituan.trip.mobile.hermes.sal.meilv.impl.QueryPartnerImpl]; scope=singleton; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in file [/Users/hanzhankang/hermes/hermes-sal/target/classes/com/meituan/trip/mobile/hermes/sal/meilv/impl/QueryPartnerImpl.class]] with [Generic bean: class [com.meituan.trip.mobile.hermes.sal.meilv.impl.QueryPartnerImpl]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [sal/service-outer.xml]]

Spring Bean發生替換是因為在同一個WebApplicationContext下，重復注入同一名稱的Bean實例。從上面的日志中我們可以看出，queryPartnerImpl對象最終保留的是通過[sal/service-outer.xml]配置文件注入的Bean，在這個配置文件里詳細的設置了相關屬性。從替換結果來看，即使發生過替換也不會影響程序到正確運行。那問題會出在哪里呢？

經過反復調試發現，只要在QueryPartnerImpl類的定義前面加上@Service注解，問題就會重現。

問題排查及解決

遇到如此詭異的問題，且又不能確定此問題是否是系統其他環境配置導致的時候，不妨可以從這個類在系統中的實例對象身上著手分析，最簡單的辦法是通過Jmap查詢系統中的對象實例個數。

使用Jmap查詢QueryPartnerImpl類在系統中的實例個數及結果：（Jmap是JDK自帶的堆分析工具Java Memory Map，可以通過此工具打印出某個Java進程內存內的所有對象大小和數量；建議在測試環境中使用jmap -histo:live命令查詢，執行此命令會觸發一次Full GC）

$ jmap -histo:live 20881 | grep QueryPartnerImpl1354: 2 80 com.meituan.trip.mobile.hermes.sal.meilv.impl.QueryPartnerImpl

查看發現系統中居然有2個實例！這和我們對“Spring創建Bean默認是單例的”認知不符，那就把進程Dump出來詳細解刨下這2個對象吧！通過Jmap的dump參數把進程鏡像dump出來：

$ jmap -dump:format=b,file=/tmp/heap.bin 20881Dumping heap to /private/tmp/dump.data ...Heap dump file created

此時可以使用MAT（內存分析工具，Memory Analysis Tool）并配合Jhat快速定位到此類的實例對象上，通過對象間的引用關系來查找定位原因。

首先通過Jhat工具來查看QueryPartnerImpl對象及對象間的引用關系：

$ jhat /tmp/heap.bin...........................................................................Snapshot resolved.Started HTTP server on port 7000Server is ready.

（Jhat是JDK自帶的堆分析工具Java Heap Analyse Tool，可以將堆中的對象以HTML的形式顯示出來，包括對象的數量、大小等，默認端口7000。）

通過Jhat加載dump文件成功后，訪問localhost:7000進入對象列表頁，此時通過關鍵字“QueryPartnerImpl”搜索定位到具體的類上，再點擊進去查看詳情：

Class 0x6c36938b0class com.meituan.trip.mobile.hermes.sal.meilv.impl.QueryPartnerImplInstances （類的實例）Exclude subclassesInclude subclassesReferences summary by Type（對象的引用關系）References summary by type

點擊鏈接Instances -> Exclude subclasses查看類的實例對象：

com.meituan.trip.mobile.hermes.sal.meilv.impl.QueryPartnerImpl@0x6c41b6f80 (64 bytes)
com.meituan.trip.mobile.hermes.sal.meilv.impl.QueryPartnerImpl@0x7aeafac20 (64 bytes)

這2個就是QueryPartnerImpl在系統中創建的2個實例對象，點擊查看每個對象屬性注入情況：

QueryPartnerImpl@0x6c41b6f80 (64 bytes) 屬性： clientId (L) : trip_trade (28 bytes) clientSecret (L) : 6ee952489a93b51b1ffcadd040ca562e (28 bytes) connectTimeout (I) : 15000 encode (L) : UTF-8 (28 bytes) log (L) : org.apache.logging.slf4j.Log4jLogger@0x6c3f26240 (41 bytes) readTimeout (I) : 15000 url (L) : http://test.url.meituan.com/ (28 bytes)引用關系： com.meituan.trip.mobile.hermes.biz.cs.GroupTravelCsOrderDetailBiz@0x6c41b6f60 (48 bytes) : field queryPartnerImpl java.util.concurrent.ConcurrentHashMap$Node@0x6c4420fe8 (44 bytes) : field val org.springframework.beans.factory.support.DisposableBeanAdapter@0x6c41b79f0 (66 bytes) : field bean com.meituan.trip.mobile.hermes.biz.driven.listener.snapshot.GroupTravelOrderSnapshotEventListener@0x7ae57c490 (96 bytes) : field queryPartnerImpl com.meituan.trip.mobile.hermes.web.controller.api.ApiAliveController@0x6c3619fe8 (24 bytes) : field queryPartnerImplQueryPartnerImpl@0x7aeafac20 (64 bytes) 屬性： clientId (L) : <null> clientSecret (L) : <null> connectTimeout (I) : 0 encode (L) : <null> log (L) : org.apache.logging.slf4j.Log4jLogger@0x6c3f26240 (41 bytes) readTimeout (I) : 0 url (L) : <null> 引用關系： org.springframework.beans.factory.support.DisposableBeanAdapter@0x7aeccfd40 (66 bytes) : field bean java.util.concurrent.ConcurrentHashMap$Node@0x7aeb05b18 (44 bytes) : field val com.meituan.trip.mobile.hermes.biz.cs.GroupTravelCsOrderDetailBiz@0x7aeafab88 (48 bytes) : field queryPartnerImpl com.meituan.trip.mobile.hermes.web.controller.api.ApiAliveController@0x7aeb80228 (24 bytes) : field queryPartnerImpl com.meituan.trip.mobile.hermes.biz.driven.listener.snapshot.GroupTravelOrderSnapshotEventListener@0x7aeb03908 (96 bytes) : field queryPartnerImpl

結果發現QueryPartnerImpl@0x6c41b6f80對象的屬性是注入成功的，而QueryPartnerImpl@0x7aeafac20對象的屬性卻注入失敗。從這里可以初步判斷：導致錯誤的原因是我們使用的對象是屬性注入失敗的QueryPartnerImpl@0x7aeafac20。

問題排除到這里，我們不禁有2個疑問：
1）為什么會出現2個對象？
從Spring啟動日志看到queryPartnerImpl有被替換的情況，其實替換的結果是把通過@Service注入的Bean替換成了用XML定義并注入的Bean，這也只能有1個對象，另一個對象怎么出現的？
2）誰在使用這2個對象？
既然錯誤已成事實，那是誰在使用這個屬性注入失敗的QueryPartnerImpl@0x7aeafac20呢？而且我們每次都是使用它，而不是屬性注入成功的QueryPartnerImpl@0x6c41b6f80。

通過Jhat展示的對象引用關系看，只有org.springframework.beans.factory.support.DisposableBeanAdapter和java.util.concurrent.ConcurrentHashMap$Node 比較可疑。但DisposableBeanAdapter是用來管理Spring Bean的銷毀，所以和本事故無關，重點就落在java.util.concurrent.ConcurrentHashMap$Node 上了。
通過MAT工具來分析java.util.concurrent.ConcurrentHashMap$Node@0x7aeb05b18的引用關系，通過對象查找工具并輸入對象的內存地址定位：

可直接查看此對象：

選中這個對象，右鍵打開菜單選項，選擇：Lists objects -> with incoming references查看都有哪些對象持有此對象（with outgoing references表示此對象擁有哪些對象）：

通過上面對象引用追蹤路徑可以看到，queryPartnerImpl@0x7aeafac20最終被DispatcherServlet@0x7ae577e00對象引用。
采用同樣的方式來分析queryPartnerImpl@0x6c41b6f80的對象引用關系：

queryPartnerImpl@0x6c41b6f80最終被ContextLoaderListener@0x6c358f7f8引用。
通過對比發現:

queryPartnerImpl@0x6c41b6f80 被 XmlWebApplicationContext@0x6c358f810 引用，而 XmlWebApplicationContext@0x6c358f810 又被 ContextLoaderListener@0x6c358f7f8 引用; queryPartnerImpl@0x7aeafac20 被 XmlWebApplicationContext@0x7ae9ca338 引用，而 XmlWebApplicationContext@0x7ae9ca338 又被 DispatcherServlet@0x7ae577e00 引用。

ContextLoaderListener和DispatcherServlet對我們來說非常熟悉，這是在Spring MVC項目中的web.xml中配置的，ContextLoaderListener用來初始化root WebApplicationContext；DispatcherServlet是請求分發控制器，啟動時也會初始化一個自己的WebApplicationContext，并設置parent為root WebApplicationContext，從而形成常說的“父子關系”。DispatcherServlet如果在自己的WebApplicationContext能找到需要用的對象就直接使用，只有在找不到對象的情況下才會去查找父容器里的。

到這里我們找到了引起事故發生的根本原因，但是我們還需要找出引發事故的罪魁禍首！通過前面的分析我們知道這和ContextLoaderListener、DispatcherServlet有關系，那就定位到web.xml的配置文件中來：

在spring/spring-servlet.xml配置文件中我們開啟了注解掃描功能，并且從項目路徑“com.meituan.trip.mobile.hermes”開始掃描：

我們知道Spring會通過@Service注解去實例化一個Bean，屬性如果沒有通過注解注入進來的話，就用默認值。在此配置文件后面就再沒有對queryPartnerImpl的定義，也就不會發生替換的情況。DispatcherServlet只能獲得由注解加載的半成品Bean。

再來看看ContextLoaderListener的配置文件applicationContext.xml：

我們在applicationContext.xml中也同樣開啟了注解掃描功能，也是從項目路徑“com.meituan.trip.mobile.hermes”開始掃描，但是在下文的sal/service-out.xml配置文件中，又重新對queryPartnerImpl通過XML定義，所以會發生替換現象。

到這里我們才最終搞清楚發生這次事故的最根本原因，解決辦法是要讓整個系統中只有一個屬性注入成功的queryPartnerImpl對象，途徑有如下幾種：
1）刪除@Service注解：這個方法治標不治本，因為配置、?注解掃描功能后會開啟包括@Service在內的超過6種注解，而這些注解部分在用；
2）掃描隔離：通過配置的屬性use-default-filters并配合include-filter/exclude-filter實現掃描過濾，只掃描指定注解。
修改后的spring-servlet.xml配置（applicationContext.xml配置也需要做調整）：

use-default-filters＝true，表示Spring將會創建那些被@Component, @Repository, @Service 或 @Controller等注解標注的Bean，默認值為true。如果use-default-filters＝true，同時使用并指定注解類，表示不掃描指定base-package路徑下的此注解；如果use-default-filters＝false，同時使用并指定注解類，表示掃描指定base-package路徑下面的此注解。

問題總結

使用注解并不一定會引起錯誤，但是注解要使用規范，不能亂用。如果通過注解注入，屬性值最好也要通過注解方式注入；

注解掃描功能雖然很強大、很方便，但是要注意區分掃描范圍及過濾特定注解；

單元測試能通過的原因：我們一般只指定加載一個配置文件作為測試環境，類實例只會出現一個，故能測試通過；

最好最重要的一點就是在使用任何框架時，最好按"Best Practice"規范，避免出現一些莫名其妙的問題。

進一步探討

通過閱讀Spring源碼中涉及ContextLoaderListener和DispatcherServlet的部分學習到，ContextLoaderListener在Context初始化的時候會創建一個root WebApplicationContext，并將此對象存儲在ServletContext中，Key為：WebApplicationContext.class.getName() + ".ROOT”；DispatcherServlet在初始化過程也實例化了一個自己的WebApplicationContext，設置在ServletContext中的key為：
FrameworkServlet.class.getName() + ".CONTEXT.”+ getServletName()，同時設置此對象的parent為 ContextLoaderListener定義的 root WebApplicationContext。DispatcherServlet所創建的WebApplicationContext被稱為子容器，子容器可以訪問父容器中的內容，但父容器不能訪問子容器中的內容。
Spring官方在介紹Spring MVC的同時，也給我們介紹了WebApplicationContext的繼承關系：

從圖中可以看出，每個DispatcherServlet都會去實例化一個自己的WebApplicationContext，而這個WebApplicationContext可以獲得root WebApplicationContext中已經實例化好的Bean。

參考文獻

Spring Web MVC框架文檔

轉載于:https://my.oschina.net/dolphinboy/blog/2248770

總結

以上是生活随笔為你收集整理的Spring MVC注解故障追踪记的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。