posts - 42,comments - 83,trackbacks - 0
       这几天在做一些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 == nullreturn 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

FeedBack:
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-02-23 11:26 | 每日推荐网
不懂,顶一下。  回复  更多评论
  
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-06-25 20:32 | crx
你好!我也碰到这样的问题,能联系下你吗?
我的msn:abenqq@hotmail.com  回复  更多评论
  
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-06-26 09:44 | 走走停停又三年
你有什么疑问,这里说好了。  回复  更多评论
  
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-06-29 12:57 | crx
你好!我都是同个环境下测试的,IP地址没有更换过。抛出的异常是这样子:
weblogic.transaction.RollbackException: SubCoordinator 'AdminServer4Smejb+172.20.1.18:7005+smejb+t3+' not available 抛出异常捕获后进行事务回滚,又抛出异常:java.lang.IllegalStateException: Transaction does not exist
异常情况不能完整贴出来,被系统当成垃圾广告。
  回复  更多评论
  
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-06-29 13:03 | 走走停停又三年
172.20.1.18:7005这个url和你当前的AdminServer4Smejb地址、端口一致吗? 如果一致,172.20.1.18:7005目前通吗?  回复  更多评论
  
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-06-29 13:17 | crx
是通的,在事务提交之前也有根据172.20.1.18:7005这个进行创建连接操作。之前在同台服务器下创建不同端口的域部署ejb,可以事务提交。现在在三台服务器分别部署就出现这个异常。是不是weblogic还需要配置什么?  回复  更多评论
  
# re: Weblogic中因为IP变更导致SubCoordinator not available,Transaction RollbackException问题调查
2009-06-29 13:28 | 走走停停又三年
你把$DOMAIN_HOME\servers\$SERVER_NAME\data\store\default下的.dat文件备份到其他地方,然后删除他们,重启服务器看看。  回复  更多评论
  

只有注册用户登录后才能发表评论。


网站导航: