找bug

      哪里出的bug，问题就在哪里，这次遇到的问题也是这样，但是这次的bug找的有点曲折，首先项目上线已经一年多了，从来没有出现过一次提交，在审批表里边插入过两条除主键不同外完全相同的数据，通过询问使用方是不是进行过连续点击两次提交按钮的情况，对方肯定的说只提交了一次,那么问题就很棘手了，由于提交涉及到一个流程引擎的插件，我被误导的分析插件是不是出了问题，但是插件封装的很严实，分析插件代码不现实，然后我就寻求公司同事的帮助，但是都没有遇到过这样的问题，看着经理也帮不上什么忙，只能靠自己了，这个时候唯一能求助的只有日志了，刚开始没有找出原因，是因为我主要关注抛出的异常部分，没有做深入分析，异常信息如下：

2018-12-11 19:03:27 701 eChain ERROR 
运行时异常,详细信息如下：
======================================================================
类：com.ecc.echain.workflow.engine.WorkFlowClient；方法：wfCompleteJob()
异常堆栈信息如下：
java.lang.ArrayIndexOutOfBoundsException: 0 >= 0
    at java.util.Vector.elementAt(Vector.java:427)
    at com.ecc.echain.workflow.engine.WfEngine.initializeNextNode(WfEngine.java:933)
    at com.ecc.echain.workflow.engine.WfEngine.wfRouterDirect(WfEngine.java:841)
    at com.ecc.echain.workflow.engine.WfEngine.submitNextNode(WfEngine.java:447)
    at com.ecc.echain.workflow.engine.WfEngine.wfCompleteJob(WfEngine.java:4672)
    at com.ecc.echain.workflow.engine.WorkFlowClient.wfCompleteJob(WorkFlowClient.java:533)
    at com.yucheng.cmis.platform.workflow.msi.msiimple.WorkflowServiceImpl.wfCompleteJob(WorkflowServiceImpl.java:269)
    at com.yucheng.cmis.platform.workflow.op.SubmitWorkFlowOp.doExecute(SubmitWorkFlowOp.java:133)
    at com.yucheng.cmis.operation.CMISOperation.execute(CMISOperation.java:149)
    at com.yucheng.cmis.ad.mvc.ADRequestController.executeEMPLogic(ADRequestController.java:118)
    at com.ecc.emp.web.servlet.mvc.EMPRequestController.executeTheFlow(EMPRequestController.java:487)
    at com.ecc.emp.web.servlet.mvc.EMPRequestController.doRequest(EMPRequestController.java:325)
    at com.ecc.emp.web.servlet.EMPRequestServlet.service(EMPRequestServlet.java:427)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
    at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
    at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
    at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:301)
    at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:26)
    at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
    at com.ecc.emp.web.jsptags.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:44)
    at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
    at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3748)
    at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3714)
    at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
    at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
    at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2283)
    at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2182)
    at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1499)
    at weblogic.work.ExecuteThread.execute(ExecuteThread.java:263)
    at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)

上述异常是因为同一笔数据多次插入数据库造成的异常，刚开始我没有意识到这一点，导致没能及时的找出问题。

后来意识到只能看自己了，又重新的分析日志，这次发现了有问题的地方：

2018-12-12 09:34:07 860 eChain DEBUG getCacheWFObjByWFSign：WFI_ZXCX
2018-12-12 09:34:07 860 eChain DEBUG 实例化全局流程属性initializeWFWholeDocUNID(),wfid:null;WFSign:WFI_ZXCX;CurrentUserID:34310206;orgid:1634319000;InstanceID:nullsysid:ciis
2018-12-12 09:34:07 860 eChain INFO 由流程标识WFSign为:WFI_ZXCX找到相应的最新流程ID为:1
2018-12-12 09:34:07 860 eChain DEBUG getCacheWFObjByWFSign：WFI_ZXCX
2018-12-12 09:34:07 861 eChain DEBUG 实例化全局流程属性initializeWFWholeDocUNID(),wfid:null;WFSign:WFI_ZXCX;CurrentUserID:34310206;orgid:1634319000;InstanceID:nullsysid:ciis
2018-12-12 09:34:07 861 eChain INFO 由流程标识WFSign为:WFI_ZXCX找到相应的最新流程ID为:1
2018-12-12 09:34:07 876 eChain INFO 工作流全局初始化,调用方法initializeWFWholeDocUNID(),当前用户：34310206,工作流全局属性ID：1,所属应用：wf_cmis_app
2018-12-12 09:34:07 877 eChain DEBUG 执行操作：实例化全局流程属性initializeWFWholeDocUNID(),InstanceID:A00CB9F47D27FA79;NodeID:1_a3;用时:17毫秒
2018-12-12 09:34:07 877 eChain INFO 工作流全局初始化,调用方法initializeWFWholeDocUNID(),当前用户：34310206,工作流全局属性ID：1,所属应用：wf_cmis_app
2018-12-12 09:34:07 877 eChain DEBUG 执行操作：实例化全局流程属性initializeWFWholeDocUNID(),InstanceID:A00CB9F51217B9EA;NodeID:1_a3;用时:17毫秒
2018-12-12 09:34:07 878 eChain DEBUG getCacheWFObjByWFSign：WFI_ZXCX
2018-12-12 09:34:07 878 eChain DEBUG getCacheWFObjByWFSign：WFI_ZXCX
- Do release the connection from data source: com.ecc.emp.jdbc.JNDIDataSource@2147545b success!
- Execute the flow [null] end.  retValue=null use 1049ms
- commit current transaction...
- Do release the connection from data source: com.ecc.emp.jdbc.JNDIDataSource@2147545b success!
- Execute the flow [null] end.  retValue=null use 2654ms
- commit current transaction...
- Do release the connection from data source.
- Process request: /ciis/initiateWF.do finished!
- Do release the connection from data source.
- Process request: /ciis/initiateWF.do finished!

通过再次查看日志，我发现了同一笔数据入库两次的情况会出现两次- Process request: /ciis/initiateWF.do finished!，很明显这是连续请求了两次,但是页面点击提交按钮后有遮罩层限制点击，后台代码有防止两笔相同的数据入库的校验，居然都没有限制住，很奇怪。

后来快下班的时候有人反映这一周网络比较慢，出现多笔入库的原因是进行了连续提交，后来经过验证，提交的时候由于没有立即弹出遮罩层，在网络不好的情况下，会出现连续点击，连续提交的情况，由于两笔请求几乎同时发起，后台校验拦截不到，才导致这样的情况出现。

经过这件事情，我感觉,找bug（1）哪里的问题就去哪里找；（2）不能光听别人嘴上说没有这样操作，要从日志里边找证据，包括请求，（3）找对抛出异常的因果关系，这次我没有理清异常的因果关系也是我没能找出问题很重要的原因