title: SQL Server Agent Job Fails Due to MS DTC
body: <p>In SQL Server 2008R2 I have an Agent Job that runs very frequently. The job has a single step which calls a stored procedure. The stored procedure is very long and calls other stored procedures, some of which are long as well.</p>
  
  <p>The stored procedures need to work with multiple databases on different servers.</p>
  
  <p>The problem is that the agent job will fail sometimes. It will run several times without failing, then it will fail once, then the next time it runs it runs successfully. Everything is done within a transaction so if it fails the data will be reverted. This makes me believe it's not a syntax or data problem although I can't say for sure.</p>
  
  <p>When checking the Job Activity Manager and viewing the history for the failed job, all it says is </p>
  
  <pre><code>The job failed. The Job was invoked by Schedule 11 (Sch0). The last step to run was step 1 (Step00).
  </code></pre>
  
  <p>I enabled logging for Step 1 of the job. The error I get from the log is</p>
  
  <pre><code>The Microsoft Distributed Transaction Coordinator (MS DTC) has cancelled the distributed transaction. [SQLSTATE 42000]
  </code></pre>
  
  <p>I looked into the Trace logs for MS DTC on the main server (SERVER1) and when it fails, the following entries are present:</p>
  
  <pre><code> pid=3416;tid=3036;time=02/29/2016-12:13:11.493   ;seq=88;eventid=TRANSACTION_BEGUN                        ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction has begun, description :'user_transaction'"
   pid=3416;tid=3036;time=02/29/2016-12:13:11.493   ;seq=89;eventid=RM_ENLISTED_IN_TRANSACTION               ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"resource manager #1001 enlisted as transaction enlistment #1. RM guid = '&lt;guid&gt;'"
   pid=3416;tid=3036;time=02/29/2016-12:13:11.509   ;seq=90;eventid=TRANSACTION_PROPOGATED_TO_CHILD_NODE     ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction propagated to 'SERVER1' as transaction child node #1"
   pid=3416;tid=3036;time=02/29/2016-12:13:27.947   ;seq=91;eventid=TRANSACTION_ABORTING                     ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction is aborting"
   pid=3416;tid=3036;time=02/29/2016-12:13:27.947   ;seq=92;eventid=RM_ISSUED_ABORT                          ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"abort request issued to resource manager #1001 for transaction enlistment #1"
   pid=3416;tid=3036;time=02/29/2016-12:13:27.947   ;seq=93;eventid=CHILD_NODE_ISSUED_ABORT                  ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"abort request issued to transaction child node #1 'SERVER1'"
   pid=3416;tid=3036;time=02/29/2016-12:13:27.947   ;seq=94;eventid=CHILD_NODE_ACKNOWLEDGED_ABORT            ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"received acknowledgement of abort request from transaction child node #1 'SERVER1'"
   pid=3416;tid=3036;time=02/29/2016-12:13:36.993   ;seq=95;eventid=RM_ACKNOWLEDGED_ABORT                    ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"received acknowledgement of abort request from the resource manager #1001 for transaction enlistment #1"
   pid=3416;tid=3036;time=02/29/2016-12:13:36.993   ;seq=96;eventid=TRANSACTION_ABORTED                      ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction has been aborted"
  </code></pre>
  
  <p>So it goes from TRANSACTION_PROPOGATED_TO_CHILD_NODE to TRANSACTION_ABORTING with no indication why (as far as I can tell).</p>
  
  <p>I checked the MS DTC Trace logs on the second server (SERVER2) and see the following when it fails:</p>
  
  <pre><code> pid=4032;tid=3564;time=02/29/2016-13:26:46.117   ;seq=173977;eventid=TRANSACTION_PROPOGATED_FROM_PARENT       ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction propagated from parent node 'SERVER2', Description = 'a16ace8fa7f6'"
   pid=4032;tid=3564;time=02/29/2016-13:26:46.117   ;seq=173978;eventid=RM_ENLISTED_IN_TRANSACTION               ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"resource manager #1001 enlisted as transaction enlistment #1. RM guid = '&lt;guid&gt;'"
   pid=4032;tid=3564;time=02/29/2016-13:27:02.758   ;seq=173979;eventid=RECEIVED_ABORT_REQUEST_FROM_NON_BEGINNER ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"received request to abort the transaction from non beginner"
   pid=4032;tid=3564;time=02/29/2016-13:27:02.758   ;seq=173980;eventid=TRANSACTION_ABORTING                     ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction is aborting"
   pid=4032;tid=3564;time=02/29/2016-13:27:02.758   ;seq=173981;eventid=RM_ISSUED_ABORT                          ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"abort request issued to resource manager #1001 for transaction enlistment #1"
   pid=4032;tid=3564;time=02/29/2016-13:27:02.758   ;seq=173982;eventid=RECEIVED_ABORT_FROM_PARENT               ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"child node received abort request from parent node 'SERVER2'"
   pid=4032;tid=3564;time=02/29/2016-13:27:02.758   ;seq=173983;eventid=ACKNOWLEDGING_ABORT_TO_PARENT            ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"child node achnowledging the delivery of abort request from parent node 'SERVER2'"
   pid=4032;tid=3564;time=02/29/2016-13:27:05.773   ;seq=173984;eventid=RM_ACKNOWLEDGED_ABORT                    ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"received acknowledgement of abort request from the resource manager #1001 for transaction enlistment #1"
   pid=4032;tid=3564;time=02/29/2016-13:27:05.773   ;seq=173985;eventid=TRANSACTION_ABORTED                      ;tx_guid=&lt;guid&gt;;"TM Identifier='(null)'" ;"transaction has been aborted"
  </code></pre>
  
  <p>This one shows RECEIVED_ABORT_REQUEST_FROM_NON_BEGINNER after RM_ENLISTED_IN_TRANSACTION. But still no indication why it's being aborted. </p>
  
  <p>Is the RECEIVED_ABORT_REQUEST_FROM_NON_BEGINNER error indicating that the abort is coming from the main server (SERVER1)? Or is it saying the abort is coming from something other than SERVER1 because SERVER1 is the beginner?</p>
  
  <p>I also checked the SQL Server ERRORLOG files and it doesn't contain anything for this failure.</p>
  
  <p>The stored procedures use TRY/CATCH to handle errors and the Agent is setup to send email notifications on failures. In this case, I receive the email notification but the CATCH is not handling the error. I know this is probably because the severity of the error is high.</p>
  
  <p>Is there anything else I can do to find out exactly what is causing this to fail? </p>