這幾天在做一些Transaction方面的研究，碰到一個(gè)詭異的問題。問題大概是這樣的，之前我的測(cè)試一直在公司做，今天把工作帶到家里了，結(jié)果因?yàn)槿缦聠栴}，導(dǎo)致我沒法工作了。
weblogic.transaction.RollbackException: SubCoordinator 'server_2+10.182.216.189:7021+driver_test_domain+t3+' not available
at weblogic.rjvm.ResponseImpl.unmarshalReturn(ResponseImpl.java:215)
at weblogic.rmi.internal.BasicRemoteRef.invoke(BasicRemoteRef.java:224)
at weblogic.transaction.internal.CoordinatorImpl_923_WLStub.commit(Unknown Source)
at weblogic.transaction.internal.TransactionImpl.commit(TransactionImpl.java:324)
at weblogic.transaction.internal.TransactionManagerImpl.commit(TransactionManagerImpl.java:283)
at weblogic.transaction.internal.TransactionManagerImpl.commit(TransactionManagerImpl.java:277)
at test.jdbc.DriverTest.xaTest(DriverTest.java:293)
at test.jdbc.DriverTest.main(DriverTest.java:49)
Caused by: weblogic.transaction.RollbackException: SubCoordinator 'server_2+10.182.216.189:7021+driver_test_domain+t3+' not available
at weblogic.transaction.internal.TransactionImpl.throwRollbackException(TransactionImpl.java:1809)
at weblogic.transaction.internal.ServerTransactionImpl.internalCommit(ServerTransactionImpl.java:331)
at weblogic.transaction.internal.ServerTransactionImpl.commit(ServerTransactionImpl.java:227)
at weblogic.transaction.internal.CoordinatorImpl.commit(CoordinatorImpl.java:101)
at weblogic.transaction.internal.CoordinatorImpl_WLSkel.invoke(Unknown Source)
at weblogic.rmi.internal.BasicServerRef.invoke(BasicServerRef.java:553)
at weblogic.rmi.internal.BasicServerRef$1.run(BasicServerRef.java:443)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:147)
at weblogic.rmi.internal.BasicServerRef.handleRequest(BasicServerRef.java:439)
at weblogic.rmi.internal.BasicServerRef.access$300(BasicServerRef.java:61)
at weblogic.rmi.internal.BasicServerRef$BasicExecuteRequest.run(BasicServerRef.java:983)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:181)
初看到這個(gè)異常，家里做測(cè)試，Tx的subcoordinator怎么會(huì)用到公司的IP（10.182.216.189）吶？怎么著也應(yīng)該是192.168.0.51吧？第一感覺是我的datasource配置有問題，仔細(xì)檢查了一下，沒什么問題。再檢查檢查server2的listen address，也沒有問題。見鬼了，怎么會(huì)這樣？還有什么地方能跟IP有關(guān)系呢？tlog? 沒錯(cuò)，的確好像跟tlog有關(guān)系，當(dāng)時(shí)想直接把tlog刪掉，重起一下算了。畢竟自己最近在做JTA的調(diào)查，干脆自己徹底debug一下算了。
重新啟動(dòng)客戶端測(cè)試程序，debug一下客戶端transaction信息。順便提一下，weblogic中transaction在client、server之間是通過PropagationContext來回傳遞的，一次RMI調(diào)用，會(huì)導(dǎo)致一次傳遞來回。PropagationConext中一般包括如下信息：
Xid: 事務(wù)ID
CoordinatorURL: 事務(wù)主coordinator的URL(最終事務(wù)提交在對(duì)應(yīng)的server上完成)
scURLs: subcoordinator url列表，每個(gè)involve到該tx中的server url都在其中。coordinator通過這個(gè)url通知每個(gè)subcoordinator完成事務(wù)的提交、回滾。
resNames: involve到該tx中所以resource的名字列表
......
從異常上來看，這個(gè)問題跟subCoordinator有關(guān)，所以在客戶端，我只debug了scURLs，如下，
從debug信息來看，server2的scURL應(yīng)該是沒有問題的。回頭再看看這個(gè)異常，因?yàn)楫惓Ｊ窃诳蛻舳税l(fā)起提交請(qǐng)求的時(shí)候，server端拋出的，問題是，我傳遞過去的是個(gè)正確的scURL(192.168.0.51)，server端怎么會(huì)解析出一個(gè)錯(cuò)誤的url（10.182.216.189）呢？
繼續(xù)debug server端，server端收到coordinatorImpl_stub的commit()時(shí)，它需要先從PropagationContext中restore transaction信息，包括根據(jù)scURLs還原scInfoList, 根據(jù)resNames還原resourceInfoList。問題出在了還原scInfoList的時(shí)候。如下：
1 if (scURLs != null) {
2 for (int i = 0; i < scURLs.length; i++) {
3 String scURL = scURLs[i];
4 if (tm.isLocalCoordinator(scURL)) continue;
5 SCInfo sci = tx.getOrCreateSCInfo(scURL);
6 sci.setState(scStates[i]);
7 if (scSyncRegs[i] == 1) sci.setSyncRegistered(true);
8 }
9 }
也就是說，PropagationContext還原事務(wù)的時(shí)候會(huì)遍歷每個(gè)scURL，如果是個(gè)local的url，則忽略它，否則會(huì)要求tx檢查該scURL對(duì)應(yīng)的scInfo是否已經(jīng)存在于tx自己的scInfoList中。再羅索一句，weblogic中，無論server端，還是client端，都會(huì)將tx保存在當(dāng)前TransactionManager的txMap中，PropagationContext還原tx的時(shí)候，首先檢查xid對(duì)應(yīng)的tx是否存在于txMap中，沒有的話，它會(huì)負(fù)責(zé)創(chuàng)建一個(gè)tx。再看看tx.getOrCreateSCInfo(scURL)是怎么工作的，
1 SCInfo getOrCreateSCInfo(String scURL) {
2 if (scInfoList != null) {
3 for (int i = 0; i < scInfoList.size(); i++) {
4 SCInfo sci = (SCInfo) scInfoList.get(i);
5 if (sci.getCoordinatorDescriptor().representsCoordinatorURL(scURL)) {
6 return sci;
7 }
8 }
9 }
10 SCInfo sci = createSCInfo(scURL);
11 addSC(sci);
12 return sci;
13 }
它也是遍歷自己手里的scInfoList，如果發(fā)現(xiàn)list中某個(gè)對(duì)象和傳遞進(jìn)來的scURL匹配，則返回這個(gè)對(duì)象，否則它創(chuàng)建一個(gè)新的scInfo, 把它放入scInfoList并返回。那么它是怎么判斷匹配與否的呢？
1 final boolean representsCoordinatorURL(String aCoURL)
2 {
3 return getServerID().equals(getServerID(aCoURL));
4 }
匹配的依據(jù)就是ServerID相等，serveId是什么？其實(shí)就是DomainName+ServerName，例如，driver_test_domain+server_2。它并不關(guān)心IP, Port，所以問題就出現(xiàn)了。出問題的時(shí)候，我debug出來tx中的scInfoList如下：
因?yàn)閺膫鬟f進(jìn)來的scURL解析出來的ServerID也是driver_test_domain+server_2，所以tx會(huì)認(rèn)為這scURL對(duì)應(yīng)的scInfo已經(jīng)存在，它將直接使用這個(gè)scInfo作為subcoordinator提交事務(wù)。因?yàn)檫@個(gè)已有的scInfo根本就不可用，所以事務(wù)是無法提交的，就像我們開始看到的異常一樣。
接下來的問題是，這個(gè)錯(cuò)誤的scInfo是什么時(shí)候被創(chuàng)建的呢？ SCInfo中并沒有其他什么東西，核心的只有一個(gè)CoordinatorDescriptor。創(chuàng)建scInfo的時(shí)候也只是根據(jù)scURL，調(diào)用Coordinator的gerOrCreate方法給該scInfo分配一個(gè)coordinatorDescriptor。這個(gè)getOrCreate如下,
1 static CoordinatorDescriptor getOrCreate(String aCoURL)
2 {
3 if (aCoURL == null) return null;
4 CoordinatorDescriptor cd =
5 (CoordinatorDescriptor) knownServers.get(getServerID(aCoURL));
6 if (cd == null) cd = new CoordinatorDescriptor(aCoURL);
7 return cd;
8 }
從這我們可以看到，CoordinatorDescriptor也是通過ServerID標(biāo)示其唯一性的，knownServers是個(gè)process-wide變量，tlog recover的時(shí)候，就會(huì)向其中加入對(duì)象。因?yàn)槲业膖log如下：
如果我刪掉tlog，客戶端程序運(yùn)行正常。因?yàn)閠log被我破壞了，沒法重現(xiàn)這個(gè)問題，也無法作進(jìn)一步的debug,所以不能證明那個(gè)錯(cuò)誤的coordinatorDescriptor就是tlog recover時(shí)創(chuàng)建的。95%應(yīng)該是這樣的吧。
好了，問題解決了，雖然我的問題中只涉及了IP，但我認(rèn)為，server端口變化也應(yīng)該會(huì)引起類似的問題。這個(gè)問題算是weblogic的bug嗎？應(yīng)該算是吧！
補(bǔ)充點(diǎn)信息，這個(gè)是我在server端加的debug信息，可以看到，的確是在tlog中server checkpoint做recover的時(shí)候，創(chuàng)建了變更前IP對(duì)應(yīng)的CoordinatorDescriptor信息。但因?yàn)閣eblogic內(nèi)部比較coordinator的時(shí)候，只比較domain name + server name，而不關(guān)心address、port等信息，最終出現(xiàn)subcoordinator出錯(cuò)。
to put follow coordinator to knownServers of CoordinatorDescriptor:
serverID: driver_test_domain+server_2
coordinatorURLserver_2+10.182.216.189:7021+driver_test_domain+t3+
java.lang.Exception
at weblogic.transaction.internal.CoordinatorDescriptor.init(CoordinatorDescriptor.java:176)
at weblogic.transaction.internal.CoordinatorDescriptor.<init>(CoordinatorDescriptor.java:128)
at weblogic.transaction.internal.ServerCoordinatorDescriptor.<init>(ServerCoordinatorDescriptor.java:258)
at weblogic.transaction.internal.ServerCoordinatorDescriptor.getOrCreate(ServerCoordinatorDescriptor.java:953)
at weblogic.transaction.internal.ServerCoordinatorDescriptor.getOrCreate(ServerCoordinatorDescriptor.java:371)
at weblogic.transaction.internal.ServerCheckpoint.onRecovery(ServerCheckpoint.java:175)
at weblogic.transaction.internal.StoreTransactionLoggerImpl.recover(StoreTransactionLoggerImpl.java:441)
at weblogic.transaction.internal.StoreTransactionLoggerImpl.init(StoreTransactionLoggerImpl.java:230)
at weblogic.transaction.internal.StoreTransactionLoggerImpl.init(StoreTransactionLoggerImpl.java:212)
at weblogic.transaction.internal.StoreTransactionLoggerImpl.<init>(StoreTransactionLoggerImpl.java:121)
at weblogic.transaction.internal.ServerTransactionManagerImpl.recover(ServerTransactionManagerImpl.java:933)
at weblogic.transaction.internal.TransactionRecoveryService.startOwnRecoveryIfNeeded(TransactionRecoveryService.java:214)
at weblogic.transaction.internal.TransactionRecoveryService.resume(TransactionRecoveryService.java:165)
at weblogic.transaction.internal.TransactionRecoveryService.start(TransactionRecoveryService.java:181)
at weblogic.t3.srvr.SubsystemRequest.run(SubsystemRequest.java:64)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:181)
posted on 2009-02-23 08:07
走走停停又三年 閱讀(3364)
評(píng)論(7) 編輯 收藏 所屬分類:
Weblogic