有没有谁碰到Weblogic应用服务器集群将客户端的一个请求并发为两个请求来同时进行处理?绝对实践中的真实问题

[dctor]

本人现在公司用Java进行电子缴款系统模块的开发,
使用的是无状态SessionBean,
应用服务器为Weblogic配置的一个集群,
偶尔出现过1-2次并发操作(并发程度在1秒以内);
简单的说,我从前台发起一个扣款请求,从程序流程和EJB的架构来说,后台也应该发起一笔扣款请求;
问题就在于后台不只发起一起扣款请求,而是几乎同时发起两笔扣款请求,从而导致并发重复扣款;

暂时还没有找到具体产生原因,初步分析原因有两个
1)服务器集群算法出现Bug,导致同时有两个Bean在服务器中运作;
2)前台的事件处理存在Bug,同时发起了两个请求,只是界面上看不出来而已;

我的同事上次就这个问题发过问题,那是2个月前出现的一批并发重扣;
我今天再次发出此贴,就是因为前几天我又发现了一批并发重扣;

我们再上一次的教训上,这次多输出了一些调试信息,主要是Weblogic的事务信息如下:
连续两个我认为并发的Bean输出的日志如下(但是我不清楚这些日志代表什么意思):

2004-12-14 11:29:50,402 [system:124] [ExecuteThread: '8' for queue: 'weblogic.kernel.Default'] - ZScomm ZSetskkService.logTx jklsh = 3200412052036014
**********
txid1 = BEA1-72E10BBC0AA811840C29
**********
txid2 = BEA1-72E10BBC0AA811840C29
**********
TxStatus1 = Active
**********
TxStatus2 = Active
**********
timeSinceBegin1 = 645
**********
timeSinceBegin2 = 645
**********
tx1 = Name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)],Xid=BEA1-72E10BBC0AA811840C29(17975654),Status=Active,numRepliesOwedMe=0,numRepliesOwedOthers=0,seconds since begin=0,seconds left=599,activeThread=Thread[ExecuteThread: '8' for queue: 'weblogic.kernel.Default',5,Thread Group for Queue: 'weblogic.kernel.Default'],XAServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(ServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(state=ended,assigned=none),xar=weblogic.jdbc.wrapper.JTSXAResourceImpl@190cb2a),SCInfo[coredomain+coreapp4]=(state=active),SCInfo[eaidomain+eaiserver]=(state=active),properties=({weblogic.transaction.name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)], weblogic.jdbc=t3://150.18.30.31:7013}),OwnerTransactionManager=ServerTM[ServerCoordinatorDescriptor=(CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+, XAResources={},NonXAResources={})],CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+)
**********
tx2 = Name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)],Xid=BEA1-72E10BBC0AA811840C29(17975654),Status=Active,numRepliesOwedMe=0,numRepliesOwedOthers=0,seconds since begin=0,seconds left=599,activeThread=Thread[ExecuteThread: '8' for queue: 'weblogic.kernel.Default',5,Thread Group for Queue: 'weblogic.kernel.Default'],XAServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(ServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(state=ended,assigned=none),xar=weblogic.jdbc.wrapper.JTSXAResourceImpl@190cb2a),SCInfo[coredomain+coreapp4]=(state=active),SCInfo[eaidomain+eaiserver]=(state=active),properties=({weblogic.transaction.name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)], weblogic.jdbc=t3://150.18.30.31:7013}),OwnerTransactionManager=ServerTM[ServerCoordinatorDescriptor=(CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+, XAResources={},NonXAResources={})],CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+)

========================================================================================

2004-12-14 11:29:50,993 [system:124] [ExecuteThread: '20' for queue: 'weblogic.kernel.Default'] - ZScomm ZSetskkService.logTx jklsh = 3200412052036016
**********
txid1 = BEA1-72E50BBC0AA811840C29
**********
txid2 = BEA1-72E50BBC0AA811840C29
**********
TxStatus1 = Active
**********
TxStatus2 = Active
**********
timeSinceBegin1 = 763
**********
timeSinceBegin2 = 763
**********
tx1 = Name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)],Xid=BEA1-72E50BBC0AA811840C29(18172396),Status=Active,numRepliesOwedMe=0,numRepliesOwedOthers=0,seconds since begin=0,seconds left=600,activeThread=Thread[ExecuteThread: '20' for queue: 'weblogic.kernel.Default',5,Thread Group for Queue: 'weblogic.kernel.Default'],XAServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(ServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(state=ended,assigned=none),xar=weblogic.jdbc.wrapper.JTSXAResourceImpl@a82896),SCInfo[coredomain+coreapp4]=(state=active),SCInfo[eaidomain+eaiserver]=(state=active),properties=({weblogic.transaction.name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)], weblogic.jdbc=t3://150.18.30.31:7013}),OwnerTransactionManager=ServerTM[ServerCoordinatorDescriptor=(CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+, XAResources={},NonXAResources={})],CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+)
**********
tx2 = Name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)],Xid=BEA1-72E50BBC0AA811840C29(18172396),Status=Active,numRepliesOwedMe=0,numRepliesOwedOthers=0,seconds since begin=0,seconds left=600,activeThread=Thread[ExecuteThread: '20' for queue: 'weblogic.kernel.Default',5,Thread Group for Queue: 'weblogic.kernel.Default'],XAServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(ServerResourceInfo[weblogic.jdbc.wrapper.JTSXAResourceImpl]=(state=ended,assigned=none),xar=weblogic.jdbc.wrapper.JTSXAResourceImpl@a82896),SCInfo[coredomain+coreapp4]=(state=active),SCInfo[eaidomain+eaiserver]=(state=active),properties=({weblogic.transaction.name=[EJB gov.gdlt.taxcore.gateway.facade.TaxFacadeGateWayBean.invokeTask(gov.gdlt.taxcore.comm.event.RequestEvent)], weblogic.jdbc=t3://150.18.30.31:7013}),OwnerTransactionManager=ServerTM[ServerCoordinatorDescriptor=(CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+, XAResources={},NonXAResources={})],CoordinatorURL=coreapp4+150.18.30.31:7013+coredomain+t3+)

[dctor]

=======输出以上日志信息所用到的方法如下=================
weblogic.transaction.Transaction t1 = weblogic.transaction.TxHelper.
getTransaction();
String txid1 = "" + t1.getXid();
String txStatus1 = "" + t1.getStatusAsString();
long timeSinceBegin1 = t1.getMillisSinceBegin();

weblogic.transaction.Transaction t2 = ((weblogic.transaction.
Transaction) weblogic.transaction.TransactionHelper.
getTransactionHelper().getTransaction());
String txid2 = "" + t2.getXid();
String txStatus2 = "" + t2.getStatusAsString();
long timeSinceBegin2 = t2.getMillisSinceBegin();

LogWritter.sysError("ZScomm ZSetskkService.logTx jklsh = " + jklsh +
" \r\n**********\r\n txid1 = " + txid1 +
" \r\n**********\r\n txid2 = " + txid2 +
" \r\n**********\r\n TxStatus1 = " + txStatus1 +
" \r\n**********\r\n TxStatus2 = " + txStatus2 +
" \r\n**********\r\n timeSinceBegin1 = " +
timeSinceBegin1 +
" \r\n**********\r\n timeSinceBegin2 = " +
timeSinceBegin2 +
" \r\n**********\r\n tx1 = " + t1.toString() +
" \r\n**********\r\n tx2 = " + t2.toString());

[myy]

太高深了，太菜不懂ing.

想问一下，这样比较关键的动作，为什么不用数据库的并发锁定机制呢？

[披星戴月]

2)前台的事件处理存在Bug,同时发起了两个请求,只是界面上看不出来而已;

个人觉得这个可能性比较大，可以通过weblogic端来监控一下一次操作客户端发送至服务端的具体请求数！

[runer]

你说的这种情形是偶尔出现,还是一直如此?

估计程序的问题可能性大

1.检查一下前台到底发送了几个请求
2.检查Bean到底收到了几个请求

[GJA106]

这种问题比较麻烦。weblogic应该不会存在这种漏洞。
支持Lintops(披星戴月) 的看法，检查一下前台应用。存在不行，只能咨询weblogic专家了。

[dctor]

经过对前台日志的分析,
确定属于前台同时发起了两个请求,
只是适用了多线程技术,有个线程在后台运行看不出来而已
多谢各位的建议