none
XA Transactions failing with SQLJDBC_XA DTC_ERROR Context: FInitializeTransactionManager

    السؤال

  • Hi,

    I'm seeing an inconsistent problem with the JDBC driver and XA transactions.

    I think the problem is derived from the fact I have multiple J2SE applications running on the same server and connecting to the same DB.

    I'm using the latest JDBC drivers and I followed the MS instrutions on configuring the MSSQL-Server, including applying the XP-hotfix as my server is windows XP-SP3. My Transaction manager is Atomikos Essential Transactions. My SQL-Server is 2008.

    This is part of the logs which atomikos generates:

    10-11-23 09:16:05,275 [main] a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@635d2874
    10-11-23 09:16:05,291 [main] Coordinator 192.168.0.198.tm0000100001 entering state: ACTIVE
    10-11-23 09:16:05,291 [main] Coordinator 192.168.0.198.tm0000100001 entered state: ACTIVE
    10-11-23 09:16:05,291 [main] addParticipant ( XAResourceTransaction: 3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31 ) for transaction 192.168.0.198.tm0000100001
    10-11-23 09:16:05,291 [main] XAResourceTransaction: 3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31: about to switch to XAResource XAResourceID:1
    10-11-23 09:16:05,291 [main] XAResourceTransaction 192.168.0.198.tm0000100001192.168.0.198.tm1: switched to XAResource XAResourceID:1
    10-11-23 09:16:05,291 [main] XAResource.start ( 3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31 , XAResource.TMNOFLAGS ) on resource java:comp/env/jdbc/dataSource represented by XAResource instance XAResourceID:1
    10-11-23 09:16:07,728 [main] XA resource 'java:comp/env/jdbc/dataSource': resume for XID '3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31' raised -3: the XA resource detected an internal error
    javax.transaction.xa.XAException: Function START: failed, status: -3. The error message is: *** SQLJDBC_XA DTC_ERROR Context: FInitializeTransactionManager, state=1, StatusCode:-3 (0xFFFFFFFD) ***.
    	at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:543)
    	at com.microsoft.sqlserver.jdbc.SQLServerXAResource.start(SQLServerXAResource.java:672)
    	at com.atomikos.datasource.xa.XAResourceTransaction.resume(XAResourceTransaction.java:476)
    	at com.atomikos.datasource.xa.session.BranchEnlistedStateHandler.<init>(BranchEnlistedStateHandler.java:57)
    	at com.atomikos.datasource.xa.session.NotInBranchStateHandler.checkEnlistBeforeUse(NotInBranchStateHandler.java:66)
    	at com.atomikos.datasource.xa.session.TransactionContext.checkEnlistBeforeUse(TransactionContext.java:85)
    	at com.atomikos.datasource.xa.session.SessionHandleState.notifyBeforeUse(SessionHandleState.java:176)
    	at com.atomikos.jdbc.AtomikosConnectionProxy.enlist(AtomikosConnectionProxy.java:197)
    	at com.atomikos.jdbc.AtomikosConnectionProxy.invoke(AtomikosConnectionProxy.java:131)
    	at $Proxy11.prepareStatement(Unknown Source)
    	at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:534)
    	at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:452)
    	at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:161)
    	at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1573)
    	at org.hibernate.loader.Loader.doQuery(Loader.java:696)
    	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
    	at org.hibernate.loader.Loader.doList(Loader.java:2228)
    	at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2125)
    	at org.hibernate.loader.Loader.list(Loader.java:2120)
    	at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
    	at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:361)
    	at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
    	at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1148)
    	at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
    	at com.myCompany.dal.hibernate.BaseHibernateDAO.findByProperty(BaseHibernateDAO.java:94)
    	at com.myCompany.dal.DAO.ConfigurationDAO.findByServer(ConfigurationDAO.java:33)
    	at com.myCompany.common.Config.LoadDBConfiuration(Config.java:70)
    	at com.myCompany.common.Config.init(Config.java:56)
    	at com.myCompany.myModule.myModule.main(myModule.java:52)
    10-11-23 09:16:07,744 [main] Error enlisting in transaction - connection might be broken? Please check the logs for more information...
    com.atomikos.datasource.ResourceException: XA resource 'java:comp/env/jdbc/dataSource': resume for XID '3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31' raised -3: the XA resource detected an internal error
    	at com.atomikos.datasource.xa.XAResourceTransaction.resume(XAResourceTransaction.java:483)
    	at com.atomikos.datasource.xa.session.BranchEnlistedStateHandler.<init>(BranchEnlistedStateHandler.java:57)
    	at com.atomikos.datasource.xa.session.NotInBranchStateHandler.checkEnlistBeforeUse(NotInBranchStateHandler.java:66)
    	at com.atomikos.datasource.xa.session.TransactionContext.checkEnlistBeforeUse(TransactionContext.java:85)
    	at com.atomikos.datasource.xa.session.SessionHandleState.notifyBeforeUse(SessionHandleState.java:176)
    	at com.atomikos.jdbc.AtomikosConnectionProxy.enlist(AtomikosConnectionProxy.java:197)
    	at com.atomikos.jdbc.AtomikosConnectionProxy.invoke(AtomikosConnectionProxy.java:131)
    	at $Proxy11.prepareStatement(Unknown Source)
    	at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:534)
    	at org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:452)
    	at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:161)
    	at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1573)
    	at org.hibernate.loader.Loader.doQuery(Loader.java:696)
    	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
    	at org.hibernate.loader.Loader.doList(Loader.java:2228)
    	at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2125)
    	at org.hibernate.loader.Loader.list(Loader.java:2120)
    	at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
    	at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:361)
    	at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
    	at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1148)
    	at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
    	at com.myCompany.dal.hibernate.BaseHibernateDAO.findByProperty(BaseHibernateDAO.java:94)
    	at com.myCompany.dal.DAO.ConfigurationDAO.findByServer(ConfigurationDAO.java:33)
    	at com.myCompany.common.Config.LoadDBConfiuration(Config.java:70)
    	at com.myCompany.common.Config.init(Config.java:56)
    	at com.myCompany.myModule.myModule.main(myModule.java:52)
    10-11-23 09:16:07,744 [main] getCompositeTransaction() returning instance with id 192.168.0.198.tm0000100001
    10-11-23 09:16:07,744 [main] getCompositeTransaction() returning instance with id 192.168.0.198.tm0000100001
    10-11-23 09:16:07,806 [main] getCompositeTransaction() returning instance with id 192.168.0.198.tm0000100001
    10-11-23 09:16:07,806 [main] getCompositeTransaction() returning instance with id 192.168.0.198.tm0000100001
    10-11-23 09:16:07,822 [main] commit() done (by application) of transaction 192.168.0.198.tm0000100001
    10-11-23 09:16:07,822 [main] Coordinator 192.168.0.198.tm0000100001 entering state: PREPARING
    10-11-23 09:16:07,822 [main] Coordinator 192.168.0.198.tm0000100001 entered state: PREPARING
    10-11-23 09:16:07,822 [main] (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@602b6b
    10-11-23 09:16:07,822 [main] ThreadFactory: creating new thread: Atomikos:2
    10-11-23 09:16:07,822 [main] (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@3e1bc8
    10-11-23 09:16:07,822 [main] ThreadFactory: creating new thread: Atomikos:3
    10-11-23 09:16:07,822 [Atomikos:3] XAResource.end ( 3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31 , XAResource.TMSUCCESS ) on resource java:comp/env/jdbc/dataSource represented by XAResource instance XAResourceID:1
    10-11-23 09:16:09,900 [Atomikos:3] XA resource 'java:comp/env/jdbc/dataSource': end for XID '3139322E3136382E302E3139382E746D30303030313030303031:3139322E3136382E302E3139382E746D31' raised -7: the XA resource has become unavailable
    javax.transaction.xa.XAException: Function END: failed, status: -7. The error message is: *** SQLJDBC_XA DTC_ERROR Context: xa_end, state=1, StatusCode:-7 (0xFFFFFFF9) ***.
    	at com.microsoft.sqlserver.jdbc.SQLServerXAResource.DTC_XA_Interface(SQLServerXAResource.java:543)
    	at com.microsoft.sqlserver.jdbc.SQLServerXAResource.end(SQLServerXAResource.java:685)
    	at com.atomikos.datasource.xa.XAResourceTransaction.suspend(XAResourceTransaction.java:440)
    	at com.atomikos.datasource.xa.XAResourceTransaction.prepare(XAResourceTransaction.java:591)
    	at com.atomikos.icatch.imp.PrepareMessage.send(PrepareMessage.java:61)
    	at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:111)
    	at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:87)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    	at java.lang.Thread.run(Unknown Source)
    10-11-23 09:16:09,900 [main] Coordinator 192.168.0.198.tm0000100001 entering state: ABORTING
    10-11-23 09:16:09,900 [main] Coordinator 192.168.0.198.tm0000100001 entered state: ABORTING
    10-11-23 09:16:09,900 [main] (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@13b9fae
    10-11-23 09:16:09,900 [main] Coordinator 192.168.0.198.tm0000100001 entering state: TERMINATED
    10-11-23 09:16:09,900 [main] Coordinator 192.168.0.198.tm0000100001 : stopping timer...
    10-11-23 09:16:09,900 [main] Coordinator 192.168.0.198.tm0000100001 : disposing statehandler TERMINATED...
    10-11-23 09:16:09,900 [main] Coordinator 192.168.0.198.tm0000100001 : disposed.
    
    

    If you have any questions please don't hesitate to ask.

    I'd appreciate any help granted,

    Ittai

    19/ذو الحجة/1431 04:02 م

جميع الردود

  • Hi,

    Could you please elaborate a bit? Which version of SQL Server JDBC driver are you using? Did you download the latest JDBC driver? We can download from here.

    According to your description, you are running Windows XP. Could you please verify whether the hotfix is installed? Please see:
    http://support.microsoft.com/kb/922668

    Thanks,
    Ai-Hua Qiu

    Constant dropping wears away a stone.
    23/ذو الحجة/1431 02:57 ص
  • Hi Ali-Hua,

    As I wrote in the begining of my original post I am using the latest JDBC drivers and I have the hotfix installed.

    Thanks,

    Ittai 

    23/ذو الحجة/1431 07:44 ص
  • Hi,

    According to my research, I think we need to enable XA Transaction on your machine. Please refer to the following steps:

    1. From Control Panel, open Administrative Tools, and then open Component Services. You can also click the Start button, click Run, type dcomcnfg in the Open box, and then press OK to open Component Services.
    2. Expand Component Services, Computers and right-click My Computer, and then select Properties.
    3. Click the MSDTC tab, and then click Security Configuration.
    4. Select the Enable XA Transactions check box, and then click OK. This will cause a MS DTC service restart.
    5. Click OK again to close the Properties dialog box, and then close Component Services.
    6. Stop and then restart SQL Server to ensure that it syncs up with the MS DTC changes.

    For more information, please see:
    Understanding XA Transactions

    Thanks,
    Ai-Hua Qiu


    Constant dropping wears away a stone.
    24/ذو الحجة/1431 03:09 ص
  • Hi Ali-Hua,

    Thanks for your comment but I've gone through this procedure before I posted.

    I did go through the whole article you linked to as a base to my debugging.

    I think the problem is strange since sometimes everything works perfectly great and sometimes it doesn't.

    24/ذو الحجة/1431 07:24 ص
  • Hi,

    Could you please check out and post the SQL Server error log? This can be helpful to detect any current or potential problem areas.

    By default, the error log is located at Program Files\Microsoft SQL Server\MSSQL.n\MSSQL\LOG\ERRORLOG and ERRORLOG.n files.

    For more information, please see:
    How to: View the SQL Server Error Log (SQL Server Management Studio)

    Thanks,
    Ai-Hua Qiu

    Constant dropping wears away a stone.
    25/ذو الحجة/1431 02:23 ص
  • Hi Ali-Hua,

    Here is the log from the same day of the above logs, from the transaction manager. 'MyDB' is the relevant DB.

    Thanks a lot for your attention so far.

    2010-11-22 08:54:55.95 Server      Microsoft SQL Server 2008 (RTM) - 10.0.1600.22 (Intel X86)
     Jul  9 2008 14:43:34
     Copyright (c) 1988-2008 Microsoft Corporation
     Developer Edition on Windows NT 5.1 <X86> (Build 2600: Service Pack 3)

    2010-11-22 08:54:55.95 Server      (c) 2005 Microsoft Corporation.
    2010-11-22 08:54:55.95 Server      All rights reserved.
    2010-11-22 08:54:55.95 Server      Server process ID is 4048.
    2010-11-22 08:54:55.96 Server      Authentication mode is MIXED.
    2010-11-22 08:54:55.96 Server      Logging SQL Server messages in file 'C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\Log\ERRORLOG'.
    2010-11-22 08:54:55.96 Server      This instance of SQL Server last reported using a process ID of 2584 at 21/11/2010 22:28:19 (local) 21/11/2010 20:28:19 (UTC). This is an informational message only; no user action is required.
    2010-11-22 08:54:55.96 Server      Registry startup parameters:
      -d C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\DATA\master.mdf
      -e C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\Log\ERRORLOG
      -l C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\DATA\mastlog.ldf
    2010-11-22 08:54:56.34 Server      SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
    2010-11-22 08:54:56.34 Server      Detected 2 CPUs. This is an informational message; no user action is required.
    2010-11-22 08:54:56.37 Server      SQL Server is not configured to use all of the available system memory. To enable SQL Server to use more memory, set the awe enabled option to 1 by using the sp_configure stored procedure.
    2010-11-22 08:54:57.96 Server      Using dynamic lock allocation.  Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node.  This is an informational message only.  No user action is required.
    2010-11-22 08:54:59.14 Server      Node configuration: node 0: CPU mask: 0x00000003 Active CPU mask: 0x00000003. This message provides a description of the NUMA configuration for this computer. This is an informational message only. No user action is required.
    2010-11-22 08:55:00.92 spid5s      Starting up database 'master'.
    2010-11-22 08:55:02.65 spid5s      103 transactions rolled forward in database 'master' (1). This is an informational message only. No user action is required.
    2010-11-22 08:55:03.01 spid5s      0 transactions rolled back in database 'master' (1). This is an informational message only. No user action is required.
    2010-11-22 08:55:03.01 spid5s      Recovery is writing a checkpoint in database 'master' (1). This is an informational message only. No user action is required.
    2010-11-22 08:55:03.78 spid5s      Recovery completed for database master (database ID 1) in 2 second(s) (analysis 375 ms, redo 636 ms, undo 293 ms.) This is an informational message only. No user action is required.
    2010-11-22 08:55:11.56 spid5s      Resource governor reconfiguration succeeded.
    2010-11-22 08:55:11.65 spid5s      SQL Server Audit is starting the audits. This is an informational message. No user action is required.
    2010-11-22 08:55:12.35 spid5s      SQL Server Audit has started the audits. This is an informational message. No user action is required.
    2010-11-22 08:55:12.87 spid5s      FILESTREAM: effective level = 0, configured level = 0, file system access share name = 'MSSQLSERVER'.
    2010-11-22 08:55:18.48 spid5s      SQL Trace ID 1 was started by login "sa".
    2010-11-22 08:55:19.09 spid5s      Starting up database 'mssqlsystemresource'.
    2010-11-22 08:55:19.40 spid5s      The resource database build version is 10.00.1600. This is an informational message only. No user action is required.
    2010-11-22 08:55:23.50 spid10s     Starting up database 'model'.
    2010-11-22 08:55:23.67 spid5s      Server name is 'ServerName'. This is an informational message only. No user action is required.
    2010-11-22 08:55:26.14 spid10s     Clearing tempdb database.
    2010-11-22 08:55:31.56 Server      A self-generated certificate was successfully loaded for encryption.
    2010-11-22 08:55:32.06 Server      Server is listening on [ 'any' <ipv4> 1433].
    2010-11-22 08:55:32.37 Server      Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ].
    2010-11-22 08:55:32.37 Server      Server local connection provider is ready to accept connection on [ \\.\pipe\sql\query ].
    2010-11-22 08:55:32.43 Server      Server is listening on [ 127.0.0.1 <ipv4> 1434].
    2010-11-22 08:55:32.43 Server      Dedicated admin connection support was established for listening locally on port 1434.
    2010-11-22 08:55:32.70 Server      The SQL Server Network Interface library could not register the Service Principal Name (SPN) for the SQL Server service. Error: 0x54b, state: 3. Failure to register an SPN may cause integrated authentication to fall back to NTLM instead of Kerberos. This is an informational message. Further action is only required if Kerberos authentication is required by authentication policies.
    2010-11-22 08:55:32.71 Server      SQL Server is now ready for client connections. This is an informational message; no user action is required.
    2010-11-22 08:55:34.78 spid14s     Error: 9954, Severity: 16, State: 1.
    2010-11-22 08:55:34.78 spid14s     SQL Server failed to communicate with filter daemon launch service  (Windows error: Windows Error: hr = 0x80070422(failed to retrieve text for this error)). Full-Text filter daemon process failed to start. Full-text search functionality will not be available.
    2010-11-22 08:55:36.12 spid12s     Starting up database 'msdb'.
    2010-11-22 08:55:36.15 spid15s     Starting up database 'ReportServer'.
    2010-11-22 08:55:36.15 spid14s     Starting up database 'ReportServerTempDB'.
    2010-11-22 08:55:39.03 spid10s     Starting up database 'tempdb'.
    2010-11-22 08:55:41.74 spid15s     18 transactions rolled forward in database 'ReportServer' (5). This is an informational message only. No user action is required.
    2010-11-22 08:55:41.78 spid12s     1 transactions rolled forward in database 'msdb' (4). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.03 spid5s      0 transactions rolled back in database 'msdb' (4). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.03 spid5s      Recovery is writing a checkpoint in database 'msdb' (4). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.09 spid14s     18 transactions rolled forward in database 'ReportServerTempDB' (6). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.43 spid5s      0 transactions rolled back in database 'ReportServer' (5). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.43 spid5s      Recovery is writing a checkpoint in database 'ReportServer' (5). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.43 spid5s      Recovery completed for database ReportServer (database ID 5) in 1 second(s) (analysis 308 ms, redo 74 ms, undo 664 ms.) This is an informational message only. No user action is required.
    2010-11-22 08:55:42.74 spid5s      0 transactions rolled back in database 'ReportServerTempDB' (6). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.74 spid5s      Recovery is writing a checkpoint in database 'ReportServerTempDB' (6). This is an informational message only. No user action is required.
    2010-11-22 08:55:42.74 spid5s      Recovery completed for database ReportServerTempDB (database ID 6) in 1 second(s) (analysis 197 ms, redo 122 ms, undo 270 ms.) This is an informational message only. No user action is required.
    2010-11-22 08:55:43.34 spid10s     Recovery completed for database tempdb (database ID 2) in 1 second(s) (analysis 579 ms, redo 0 ms, undo 146 ms.) This is an informational message only. No user action is required.
    2010-11-22 08:55:45.60 spid12s     The Service Broker protocol transport is disabled or not configured.
    2010-11-22 08:55:45.64 spid12s     The Database Mirroring protocol transport is disabled or not configured.
    2010-11-22 08:55:47.79 spid12s     Service Broker manager has started.
    2010-11-22 08:55:47.79 spid5s      Recovery is complete. This is an informational message only. No user action is required.
    2010-11-22 08:56:00.03 spid52      Setting database option COMPATIBILITY_LEVEL to 100 for database ReportServer.
    2010-11-22 08:56:00.21 spid52      Setting database option COMPATIBILITY_LEVEL to 100 for database ReportServerTempDB.
    2010-11-22 11:56:31.64 spid51      Setting database option COMPATIBILITY_LEVEL to 100 for database ReportServer.
    2010-11-22 11:56:32.20 spid51      Setting database option COMPATIBILITY_LEVEL to 100 for database ReportServerTempDB.
    2010-11-22 14:33:05.49 spid53      Attempting to load library 'xpstar.dll' into memory. This is an informational message only. No user action is required.
    2010-11-22 14:33:05.67 spid53      Using 'xpstar.dll' version '2007.100.1600' to execute extended stored procedure 'xp_instance_regread'. This is an informational message only; no user action is required.
    2010-11-22 15:04:18.28 spid52      Starting up database 'MyDB'.
    2010-11-22 15:04:26.23 spid55      Attempting to load library 'SQLJDBC_XA.dll' into memory. This is an informational message only. No user action is required.
    2010-11-22 15:04:26.51 spid55      Using 'SQLJDBC_XA.dll' version '0003.00.1301' to execute extended stored procedure 'xp_sqljdbc_xa_init'. This is an informational message only; no user action is required.
    2010-11-22 15:04:28.31 spid52      Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
    2010-11-22 15:04:28.35 spid52      Recovery of any in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC) has completed. This is an informational message only. No user action is required.
    2010-11-22 15:25:23.24 spid52      Starting up database 'MyDB'.
    2010-11-22 15:40:39.62 spid52      Starting up database 'MyDB'.
    2010-11-23 07:51:12.78 spid16s     This instance of SQL Server has been using a process ID of 4048 since 22/11/2010 08:55:48 (local) 22/11/2010 06:55:48 (UTC). This is an informational message only; no user action is required.
    2010-11-23 07:52:38.55 spid51      Setting database option COMPATIBILITY_LEVEL to 100 for database ReportServer.
    2010-11-23 07:52:39.63 spid51      Setting database option COMPATIBILITY_LEVEL to 100 for database ReportServerTempDB.
    2010-11-23 09:16:07.21 spid20s     The connection has been lost with Microsoft Distributed Transaction Coordinator (MS DTC). Recovery of any in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC) will begin once the connection is re-established. This is an informational message only. No user action is required.
    2010-11-23 09:16:07.83 spid54      Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
    2010-11-23 09:16:09.69 spid54      The Microsoft Distributed Transaction Coordinator (MS DTC) service could not be contacted.  If you would like distributed transaction functionality, please start this service.
    2010-11-23 09:25:04.86 spid53      Starting up database 'MyDB'.
    2010-11-23 09:25:26.08 spid53      Starting up database 'MyDB'.
    2010-11-23 09:26:55.35 spid53      Starting up database 'MyDB'.
    2010-11-23 09:27:11.54 spid51      Starting up database 'MyDB'.
    2010-11-23 09:27:46.93 spid53      Starting up database 'MyDB'.
    2010-11-23 09:34:42.33 spid54      Starting up database 'MyDB'.
    2010-11-23 09:34:45.63 spid54      Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
    2010-11-23 09:34:45.66 spid54      Recovery of any in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC) has completed. This is an informational message only. No user action is required.
    2010-11-23 09:35:01.55 spid54      Starting up database 'MyDB'.
    2010-11-23 09:35:06.54 Server      The connection has been lost with Microsoft Distributed Transaction Coordinator (MS DTC). Recovery of any in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC) will begin once the connection is re-established. This is an informational message only. No user action is required.
    2010-11-23 13:12:44.38 spid52      Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
    2010-11-23 13:12:44.42 spid52      The Microsoft Distributed Transaction Coordinator (MS DTC) service could not be contacted.  If you would like distributed transaction functionality, please start this service.
    2010-11-23 13:15:18.62 spid12s     Service Broker manager has shut down.
    2010-11-23 13:15:20.67 spid5s      SQL Server is terminating in response to a 'stop' request from Service Control Manager. This is an informational message only. No user action is required.
    2010-11-23 13:15:20.82 spid5s      SQL Trace was stopped due to server shutdown. Trace ID = '1'. This is an informational message only; no user action is required.

    25/ذو الحجة/1431 08:52 ص
  • Hi,

    The SQL Server Network Interface library could not register the Service Principal Name (SPN) for the SQL Server service. Error: 0x54b, state: 3. Failure to register an SPN may cause integrated authentication to fall back to NTLM instead of Kerberos. This is an informational message. Further action is only required if Kerberos authentication is required by authentication policies.

    According to these error messages, I think we must manually register the SPN for the instance under a domain administrator account to use Kerberos authentication.

    SQL Server failed to communicate with filter daemon launch service (Windows error: Windows Error: hr = 0x80070422(failed to retrieve text for this error)). Full-Text filter daemon process failed to start. Full-text search functionality will not be available.

    According to these error messages, we can refer to the following steps:
    1. Go into Services and set the "SQL Full-text Filter Daemon Launcher (Instance Name)" service to Manual startup.
    2. Restart SQL Server. Once SQL Server is started, you should see in Services that the "SQL Full-text Filter Daemon Launcher (Instance Name)" is now started.
    3. Then try enabling FTS on the database

    For more information, please see:
    http://support.microsoft.com/kb/909801
    http://social.msdn.microsoft.com/forums/en-us/sqlsetupandupgrade/thread/FDA77C94-9BF0-4A04-9853-75AEB0E6AD9D

    Thanks,
    Ai-Hua Qiu

    Constant dropping wears away a stone.
    26/ذو الحجة/1431 02:29 ص
  • Hi Ali-Hua,

    Do you think the above errors are related to my issue or are these additional issues you noticed from my logs?

    Because I think the main issue in the log which relates to what I'm seeing in my TM is in the following log lines:

    2010-11-23 09:16:07.21 spid20s     The connection has been lost with Microsoft Distributed Transaction Coordinator (MS DTC). Recovery of any in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC) will begin once the connection is re-established. This is an informational message only. No user action is required.
    2010-11-23 09:16:07.83 spid54      Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
    2010-11-23 09:16:09.69 spid54      The Microsoft Distributed Transaction Coordinator (MS DTC) service could not be contacted.  If you would like distributed transaction functionality, please start this service.

    You can also see that this is at the exact same time where my TM complains about the SQLServerException.

    What do you think I can do with this issue?

    Regarding your recommendations above, I was able to enable FTS (although I don't think I'm using it or need to use it) but I was unable to register the SPN.

    I'm using the following command:

    "setspn -A MSSQLSvc/myCompName:1433 Administrator"  where Administrator is the account which runs the MSSQL server service and 1433 is the port. But I get a "Unable to locate account Administrator" error message.

    The thing is I'm not sure I need this because I'm using "integratedSecurity=false" in my connection string.

    Thanks,

    Ittai

    26/ذو الحجة/1431 07:20 ص
  • Hi,

    According to your description above, the problem intermittently appears, I think it might be caused by other error messages.

    According to my research again, the issue occurs when SQL Server instance cannot connect to MSDTC using RPC calls because all of the RPC server ports are exhausted, which can happen if the range of available RPC server ports is restricted in the registry.

    For more information, please see:
    http://blogs.msdn.com/b/distributedservices/archive/2009/03/13/intermittent-error-msdtc-on-server-servername-is-unavailable.aspx

    Thanks,
    Ai-Hua Qiu


    Constant dropping wears away a stone.
    • تم الاقتراح كإجابة بواسطة Ai-hua Qiu 27/ذو الحجة/1431 05:21 ص
    27/ذو الحجة/1431 05:18 ص
  • Hi Ali-Hua,

    Thanks for your efforts.

    The issue seems a bit odd to me as the instance is not part of a cluster and so the MS-SQLServer and MSDTC reside on the same machine, so why is RPC needed?

    In any case I implemented the fix proposed in the link you supplied but the problem is that because the problem is inconsistent I don't know how to check if it has been resolved.

    Do you have any idea how I can reproduce the issue? And so to check if it's resolved.

    Thanks,

    Ittai

    29/ذو الحجة/1431 08:52 ص
  • Hi Ali-Hua,

    I kept on working and I received, just now, the same exception after implementing the changes in the registry.

    Have you got any idea why this is?

    Thanks,

    Ittai

    29/ذو الحجة/1431 01:51 م
  • Thanks its works for me thanks again !
    • تم التحرير بواسطة Muzaffar45 24/جمادى الأولى/1433 07:24 ص
    24/جمادى الأولى/1433 07:24 ص
  • did you get any solution for this.?
    25/جمادى الأولى/1433 11:29 ص