这几天在做一些Transaction方面的研究,碰到一个诡异的问题。问题大概是这样的,之前我的测试一直在公司做,今天把工作带到家里了,结果因为如下问题,导致我没法工作了。
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)
初看到这个异常,家里做测试,Tx的subcoordinator怎么会用到公司的IP(10.182.216.189)呐?怎么着也应该是192.168.0.51吧?第一感觉是我的datasource配置有问题,仔细检查了一下,没什么问题。再检查检查server2的listen address,也没有问题。见鬼了,怎么会这样?还有什么地方能跟IP有关系呢?tlog? 没错,的确好像跟tlog有关系,当时想直接把tlog删掉,重起一下算了。毕竟自己最近在做JTA的调查,干脆自己彻底debug一下算了。
重新启动客户端测试程序,debug一下客户端transaction信息。顺便提一下,weblogic中transaction在client、server之间是通过PropagationContext来回传递的,一次RMI调用,会导致一次传递来回。PropagationConext中一般包括如下信息:
Xid: 事务ID
CoordinatorURL: 事务主coordinator的URL(最终事务提交在对应的server上完成)
scURLs: subcoordinator url列表,每个involve到该tx中的server url都在其中。coordinator通过这个url通知每个subcoordinator完成事务的提交、回滚。
resNames: involve到该tx中所以resource的名字列表
......
从异常上来看,这个问题跟subCoordinator有关,所以在客户端,我只debug了scURLs,如下,
从debug信息来看,server2的scURL应该是没有问题的。回头再看看这个异常,因为异常是在客户端发起提交请求的时候,server端抛出的,问题是,我传递过去的是个正确的scURL(192.168.0.51),server端怎么会解析出一个错误的url(10.182.216.189)呢?
继续debug server端,server端收到coordinatorImpl_stub的commit()时,它需要先从PropagationContext中restore transaction信息,包括根据scURLs还原scInfoList, 根据resNames还原resourceInfoList。问题出在了还原scInfoList的时候。如下:
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还原事务的时候会遍历每个scURL,如果是个local的url,则忽略它,否则会要求tx检查该scURL对应的scInfo是否已经存在于tx自己的scInfoList中。再罗索一句,weblogic中,无论server端,还是client端,都会将tx保存在当前TransactionManager的txMap中,PropagationContext还原tx的时候,首先检查xid对应的tx是否存在于txMap中,没有的话,它会负责创建一个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,如果发现list中某个对象和传递进来的scURL匹配,则返回这个对象,否则它创建一个新的scInfo, 把它放入scInfoList并返回。那么它是怎么判断匹配与否的呢?
1 final boolean representsCoordinatorURL(String aCoURL)
2 {
3 return getServerID().equals(getServerID(aCoURL));
4 }
匹配的依据就是ServerID相等,serveId是什么?其实就是DomainName+ServerName,例如,driver_test_domain+server_2。它并不关心IP, Port,所以问题就出现了。出问题的时候,我debug出来tx中的scInfoList如下:
因为从传递进来的scURL解析出来的ServerID也是driver_test_domain+server_2,所以tx会认为这scURL对应的scInfo已经存在,它将直接使用这个scInfo作为subcoordinator提交事务。因为这个已有的scInfo根本就不可用,所以事务是无法提交的,就像我们开始看到的异常一样。
接下来的问题是,这个错误的scInfo是什么时候被创建的呢? SCInfo中并没有其他什么东西,核心的只有一个CoordinatorDescriptor。创建scInfo的时候也只是根据scURL,调用Coordinator的gerOrCreate方法给该scInfo分配一个coordinatorDescriptor。这个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标示其唯一性的,knownServers是个process-wide变量,tlog recover的时候,就会向其中加入对象。因为我的tlog如下:
如果我删掉tlog,客户端程序运行正常。因为tlog被我破坏了,没法重现这个问题,也无法作进一步的debug,所以不能证明那个错误的coordinatorDescriptor就是tlog recover时创建的。95%应该是这样的吧。
好了,问题解决了,虽然我的问题中只涉及了IP,但我认为,server端口变化也应该会引起类似的问题。这个问题算是weblogic的bug吗?应该算是吧!
补充点信息,这个是我在server端加的debug信息,可以看到,的确是在tlog中server checkpoint做recover的时候,创建了变更前IP对应的CoordinatorDescriptor信息。但因为weblogic内部比较coordinator的时候,只比较domain name + server name,而不关心address、port等信息,最终出现subcoordinator出错。
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
走走停停又三年 阅读(3344)
评论(7) 编辑 收藏 所属分类:
Weblogic