Topic
3 replies Latest Post - ‏2013-07-02T14:05:52Z by Systempuntoout
Systempuntoout
Systempuntoout
3 Posts
ACCEPTED ANSWER

Pinned topic COM+ application on 64 bit: Error occurred during transaction or heuristic processing. Reason Code = "16". Subcode = "3-8004D00E"

‏2013-06-25T14:53:47Z |

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 5 (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.


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)?  
I've already tried to change the DB2 driver from 32 to 64 bits but the problem remains.  
The offending part, at my eyes, seems the DllHost.exe at 32 bits, what do you think?

Any hints?

Posted also on StackOverflow:
http://stackoverflow.com/questions/17298740/com-application-on-64-bit-system-two-phase-commit-returns-a-transaction-error

Updated on 2013-06-28T09:57:22Z at 2013-06-28T09:57:22Z by Systempuntoout
  • Prashant Kulkarni
    Prashant Kulkarni
    7 Posts
    ACCEPTED ANSWER

    Re: COM+ application on 64 bit: Error occurred during transaction or heuristic processing. Reason Code = "16". Subcode = "3-8004D00E"

    ‏2013-06-27T12:04:27Z  in response to Systempuntoout

    you can try setting MSDTC security permission using these steps  to resolve the error 

    1)run dcomcnfg;
    2)Component Services > Computers > My Computer > Distributed Transaction Coordinator
    3)Select Local DTC
    4) Right click on Local DTC and select > Properties > Security Tab:
    5) check the boxes as shown in below screenshot
    6) reboot the machine and try agian

    Also make sure you are using latest client driver available.

    MS DTC Configuration for DB2 and Informix

    • Systempuntoout
      Systempuntoout
      3 Posts
      ACCEPTED ANSWER

      Re: COM+ application on 64 bit: Error occurred during transaction or heuristic processing. Reason Code = "16". Subcode = "3-8004D00E"

      ‏2013-06-28T08:50:08Z  in response to Prashant Kulkarni

      Hi Prashant, thanks for your answer.

      That's my exact configuration of DTC security settings.

      I've also upgraded to 9.7 client version with the latest fixpack 8 but the problem remains.

      Do you have any other recommendation?