none
COM+ VB6 Application on 64 bit system: ABORT_DUE_TO_CONNECTION_DOWN_FROM_RM error RRS feed

  • Question

  • We are trying to migrate an Intranet Web Application, developed in VB6, from Windows Server 2003 to Windows Server 2008 R2 and we are facing a problem with two phase commit transactions between Microsoft SQL Server 2008 and DB2 on Z/OS Mainframe.

    On Windows Server 2008 R2 with DB2 v9.7.500.702 Fixpack 8 (64 bit) installed, the VB6 component registered in a COM+ application, when trying to update in transaction one table on SQL Server and another table on DB2,  returns this error:

    [IBM][CLI Driver] SQL0998N Error occurred during transaction or
    heuristic processing. Reason Code = "16". Subcode = "2-80004005".
    SQLSTATE=58005

    Running the VB6 application in Debug, the exception is raised when the `Open()` method is called on the `ADODB.Connection` object (Db2 connection).

    Db2Diag shows this:

    2013-06-26-09.14.15.822000+120 I41317H405         LEVEL: Severe  
    PID     : 5972                 TID  : 5588        PROC : dllhost.exe  
    INSTANCE: DB2                  NODE : 000  
    APPID   : LOCAL.DB2.1306260714140626071414  
    EDUID   : 5588  
    FUNCTION: DB2 UDB, XA DTP Support, MicrosoftXARMCreate, probe:364  
    DATA #1 : String, 69 bytes  
    HRESULT: 80004005   
    HRESULT Message: Unspecified error  

    System event viewer reports this:

    The XA Transaction Manager attempted to load the XA resource manager DLL. The call
    to LOADLIBRARY for the XA resource manager DLL
    failed: DLL=C:\PROGRAM FILES (X86)\IBM\SQLLIB\BIN\DB2APP.DLL,
    HR=0x800700c1, File=d:\w7rtm\com\complus\dtc\dtc\xatm\src\xarmconn.cpp
    Line=2446.

    Firewall is TURNED OFF.    
    I've already tried to reinstall MSDTC.    
    DTCPing.exe worked correctly.      
    This is my DTC configuration:  


    I found this blog http://bartwullems.blogspot.it/2011/03/problems-using-net-transactionscope.html that suggests to change the `HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\MSDTC\XADLL` registry referencing the `db2app64.dll` instead of the `db2app.dll` that DB2 client normally set.

    After changing the registry Key as suggested, the event viewer error report does not show anymore but the application still gives this error:

    [IBM][CLI Driver][DB2] SQL0998N Error occurred during transaction or
    heuristic   processing. Reason Code = "16". Subcode = "3-8004D00E".
    SQLSTATE=58005

    Db2Diag shows this:

    2013-06-25-12.22.37.192000+120 I39609H572         LEVEL: Severe  
    PID     : 4364                 TID  : 1804        PROC : dllhost.exe  
    INSTANCE: DB2                  NODE : 000  
    APPID   : LOCAL.DB2.1306251022380625102238  
    EDUID   : 1804  
    FUNCTION: DB2 UDB, XA DTP Support, MicrosoftEnlistWithRM, probe:422  
    DATA #1 : String, 130 bytes  
    HRESULT: 8004D00E   
    HRESULT Message: The transaction has already been implicitly or explicitly committed or aborted  

    and inspecting the Db2 trace log reports this error:

        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.605   ;seq=94468      ;eventid=TRACING_STARTED                          ;;"TM Identifier='(null)                                            '" ;"MSDTC is resuming the tracing of long - lived transactions"
        pid=2664       ;tid=1764       ;time=06/25/2013-10:46:11.725   ;seq=94469      ;eventid=CHECKPOINTING_STARTED                    ;;"TM Identifier='(null)                                            '" ;"MSDTC is resuming the checkpointing of transactions "
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.624   ;seq=94470      ;eventid=TRANSACTION_BEGUN                        ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"transaction has begun, description :'Foo.bstx'"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.624   ;seq=94471      ;eventid=TRANSACTION_PROPOGATED_TO_CHILD_NODE     ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"transaction propagated to 'DVD1SSQ4' as transaction child node #1"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.764   ;seq=94472      ;eventid=RM_ENLISTED_IN_TRANSACTION               ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"resource manager #1002 enlisted as transaction enlistment #1. RM guid = '185bcf6e-85b5-402c-8d43-0368d4c5ee46'"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.858   ;seq=94473      ;eventid=ABORT_DUE_TO_CONNECTION_DOWN_FROM_RM     ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"connection to the resource manager #1002 for transaction enlistment #1 went down"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.858   ;seq=94474      ;eventid=TRANSACTION_ABORTING                     ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"transaction is aborting"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.858   ;seq=94475      ;eventid=CHILD_NODE_ISSUED_ABORT                  ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"abort request issued to transaction child node #1 'DVD1SSQ4'"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.858   ;seq=94476      ;eventid=CHILD_NODE_ACKNOWLEDGED_ABORT            ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"received acknowledgement of abort request from transaction child node #1 'DVD1SSQ4'"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.858   ;seq=94477      ;eventid=TRANSACTION_ABORTED                      ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"transaction has been aborted"
        pid=2664       ;tid=2020       ;time=06/25/2013-10:46:11.837   ;seq=94478      ;eventid=RM_ENLIST_FAILED_TRANSACTION_NOT_FOUND   ;tx_guid=4d2b1dc0-8679-44f2-a649-e440057f2423     ;"TM Identifier='(null)                                            '" ;"attempt to enlist the resource manager failed cause the transaction could not be found. Some possible reasons include, client might have already called commit or transaction might have got aborted due to timeout. RM guid = 'aa265ceb-27b0-4de0-999b-80b58dee4af8'"


    Enabling Diagnostic tracing on MS DTC, we only get this entry:

        06-25-2013 12:43:17:746 : [ a68.132c] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] LookUpXaDllPath (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xatmdll.cpp@175): Looking up XA DLL 'C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL'
        06-25-2013 12:43:17:746 : [ a68.132c] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] LookUpXaDllPath (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xatmdll.cpp@294): Xa DLL Lookup completed, HR=00000000, Path='C:\Program Files\IBM\SQLLIB\BIN\DB2APP64.DLL'
        06-25-2013 12:43:17:746 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1915): CValidateTask::TaskRoutine - calling xa_open - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL, OpenString="DB=FOO,UID=FOO,PWD=FOO,TPM=MSDTC"
        06-25-2013 12:43:17:777 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1919): CValidateTask::TaskRoutine - returned from xa_open with error=0 - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL, OpenString="DB=FOO,UID=FOO,PWD=FOO,TPM=MSDTC"
        06-25-2013 12:43:17:777 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1934): CValidateTask::TaskRoutine - calling xa_close - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL
        06-25-2013 12:43:17:777 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1943): CValidateTask::TaskRoutine - returned from xa_close with error=0 - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL
        06-25-2013 12:43:17:855 : [ a68.156c] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] LookUpXaDllPath (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xatmdll.cpp@175): Looking up XA DLL 'C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL'
        06-25-2013 12:43:17:855 : [ a68.156c] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] LookUpXaDllPath (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xatmdll.cpp@294): Xa DLL Lookup completed, HR=00000000, Path='C:\Program Files\IBM\SQLLIB\BIN\DB2APP64.DLL'
        06-25-2013 12:43:17:855 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1915): CValidateTask::TaskRoutine - calling xa_open - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL, OpenString="DB=FOO,UID=FOO,PWD=FOO,TPM=MSDTC"
        06-25-2013 12:43:17:886 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1919): CValidateTask::TaskRoutine - returned from xa_open with error=0 - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL, OpenString="DB=FOO,UID=FOO,PWD=FOO,TPM=MSDTC"
        06-25-2013 12:43:17:886 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1934): CValidateTask::TaskRoutine - calling xa_close - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL
        06-25-2013 12:43:17:886 : [ a68. 6e4] 0x00000000 [    TRACE_XA] [TRACE_VERBOSE] CValidateTask::TaskRoutine (d:\w7rtm\com\complus\dtc\dtc\xatm\src\xataskmgr.cpp@1943): CValidateTask::TaskRoutine - returned from xa_close with error=0 - DLL=C:\PROGRAM FILES\IBM\SQLLIB\BIN\DB2APP.DLL

    Running testconn20.exe or testconn32.exe using the `-dtc` flag, the XA connection test passes without errors.

    ...  
    Step 4: Selecting rows from SYSIBM.systables to validate existence of packages  
       SELECT  FROM SYSIBM.systables FETCH FIRST 5 rows only  
            Elapsed: 0.0468015  

    Step 5: Calling GetSchema for tables to validate existence of schema functions  
            Elapsed: 1.5132485  

    Step 6: Creating XA connection  
            DB2TransactionScope: Connection Closed.  
            Elapsed: 2.152869    
    Test passed.  


    On the old server with Windows Server 2003 and Db2 9.5.800.186 FixPack8 (32 bit) installed, everything works smoothly without any problem; the db2 trace log, running the same application, shows this:

        pid=5188       ;tid=4516       ;time=06/25/2013-11:52:12.382   ;seq=5          ;eventid=TRACING_STARTED                          ;;"TM Identifier='(null)                                            '" ;"MSDTC is resuming the tracing of long - lived transactions"
        pid=5188       ;tid=1536       ;time=06/25/2013-11:52:12.616   ;seq=6          ;eventid=CHECKPOINTING_STARTED                    ;;"TM Identifier='(null)                                            '" ;"MSDTC is resuming the checkpointing of transactions "
        pid=5188       ;tid=4516       ;time=06/25/2013-11:52:12.382   ;seq=7          ;eventid=TRANSACTION_BEGUN                        ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"transaction has begun, description :'Foo.bstx'"
        pid=5188       ;tid=4352       ;time=06/25/2013-11:52:12.382   ;seq=8          ;eventid=TRANSACTION_PROPOGATED_TO_CHILD_NODE     ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"transaction propagated to 'DVD1SSQ4' as transaction child node #1"
        pid=5188       ;tid=4516       ;time=06/25/2013-11:52:12.647   ;seq=9          ;eventid=RM_ENLISTED_IN_TRANSACTION               ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"resource manager #1001 enlisted as transaction enlistment #1. RM guid = '3a1e3c78-a7ac-40f4-9101-d0506d78c405'"
        pid=5188       ;tid=5360       ;time=06/25/2013-11:52:12.913   ;seq=10         ;eventid=RECEIVED_COMMIT_REQUEST_FROM_BEGINNER    ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"received request to commit the transaction from beginner"
        pid=5188       ;tid=5360       ;time=06/25/2013-11:52:12.913   ;seq=11         ;eventid=CHILD_NODE_ISSUED_PREPARE                ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"prepare request issued to transaction child node #1 'DVD1SSQ4'"
        pid=5188       ;tid=5360       ;time=06/25/2013-11:52:12.913   ;seq=12         ;eventid=RM_ISSUED_PREPARE                        ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"prepare request issued to resource manager #1001 for transaction enlistment #1"
        pid=5188       ;tid=4352       ;time=06/25/2013-11:52:12.928   ;seq=13         ;eventid=CHILD_NODE_VOTED_COMMIT                  ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"transaction child node #1 'DVD1SSQ4' voted commit"
        pid=5188       ;tid=4516       ;time=06/25/2013-11:52:12.928   ;seq=14         ;eventid=RM_VOTED_COMMIT                          ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"resource manager #1001 voted commit for transaction enlistment #1"
        pid=5188       ;tid=1932       ;time=06/25/2013-11:52:12.944   ;seq=15         ;eventid=TRANSACTION_COMMITTED                    ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"transaction has got committed"
        pid=5188       ;tid=1932       ;time=06/25/2013-11:52:12.944   ;seq=16         ;eventid=CHILD_NODE_ISSUED_COMMIT                 ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"commit request issued to transaction child node #1 'DVD1SSQ4'"
        pid=5188       ;tid=1932       ;time=06/25/2013-11:52:12.944   ;seq=17         ;eventid=RM_ISSUED_COMMIT                         ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"commit request issued to resource manager #1001 for transaction enlistment #1"
        pid=5188       ;tid=4352       ;time=06/25/2013-11:52:12.944   ;seq=18         ;eventid=CHILD_NODE_ACKNOWLEDGED_COMMIT           ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"received acknowledgement of commit request from transaction child node #1 'DVD1SSQ4'"
        pid=5188       ;tid=4736       ;time=06/25/2013-11:52:12.944   ;seq=19         ;eventid=RM_ACKNOWLEDGED_COMMIT                   ;tx_guid=16bfbb83-9b31-4c59-a06f-c5b59978f0ca     ;"TM Identifier='(null)                                            '" ;"received acknowledgement of commit request from the resource manager #1001 for transaction enlistment #1"
        pid=5188       ;tid=4056       ;time=06/25/2013-11:53:07.118   ;seq=20         ;eventid=TRACING_STOPPED                          ;;"TM Identifier='(null)                                            '" ;"MSDTC is suspending the tracing of long - lived transactions due to lack of activity"

    Do you know if MSDTC (64 bit) supports a 2phase commit Transaction called from a 32 bit application (Dllhost.exe 32 bit)?  
    TestConn_32.exe works without problem, so it should be supported..

    any hints?

    Monday, July 1, 2013 9:56 AM