Highlighted

Failed to get the MSDTC Security configuration for VCS from registry

Hi,

I created campus cluster with 2 servers (Operating system: Windows server 2012 R2. SQL server 2012. Symantec Storage Foundation 6.1.)

Service group became online through time. In first time - Faulted. I clear fault on this server and try up service group. Service online. I made it offline then try up and got faulted. Then online, faulted and so on...

Faulted SQL agent.

In SQL server logs I didn't find any errors.

In C:\Program Files\Veritas\cluster server\log\SQLserver_A.txt I got errors

2015/05/16 20:41:33 VCS NOTICE V-16-20093-75 SQLServerSmiley FrustratedQLServer-SQL1Smiley Surprisednline:Failed to get the MSDTC Security configuration for VCS from registry.Error : [2, 2]
2015/05/16 20:47:50 VCS ERROR V-16-20093-11 SQLServerSmiley FrustratedQLServer-SQL1Smiley Surprisednline:Failed to wait for the service 'MSSQL$SQL1' to start. Error = [2 ,258]
2015/05/16 20:47:50 VCS DBG_21 V-16-50-0 SQLServerSmiley FrustratedQLServer-SQL1Smiley Surprisednline:*** Start of debug information dump for troubleshooting ***
    LibLogger.cpp:VLibThreadLogQueue:Smiley Very Happyump[206]
2015/05/16 20:47:50 VCS DBG_21 V-16-50-0 SQLServerSmiley FrustratedQLServer-SQL1Smiley SurprisednlineSmiley Sad2) CRegKey:Smiley Surprisedpen failed for Software\Veritas\VCS\EnterpriseAgents\SQLServer\SQLServer-SQL1.
    LibVcsHive.cpp:VLibVcsHive::_GetDWORDValue[435]
2015/05/16 20:47:50 VCS DBG_21 V-16-50-0 SQLServerSmiley FrustratedQLServer-SQL1Smiley SurprisednlineSmiley Sad2) CRegKey:Smiley Surprisedpen failed for Software\Veritas\VCS\EnterpriseAgents\SQLServer\__Global__.
    LibVcsHive.cpp:VLibVcsHive::_GetDWORDValue[435]
2015/05/16 20:47:50 VCS DBG_21 V-16-50-0 SQLServerSmiley FrustratedQLServer-SQL1Smiley SurprisednlineSmiley Sad2) _GetDWORDValue failed. Subkey = Software\Veritas\VCS\EnterpriseAgents\SQLServer\__Global__, Name = IgnoreMSDTCSecurity
    LibVcsHive.cpp:VLibVcsHive::GetValue[401]
2015/05/16 20:47:50 VCS DBG_21 V-16-50-0 SQLServerSmiley FrustratedQLServer-SQL1Smiley Surprisednline:Wait timed out for service MSSQL$SQL1
    LibService.cpp:VLibService::WaitForServiceStatus[275]
2015/05/16 20:47:50 VCS DBG_21 V-16-50-0 SQLServerSmiley FrustratedQLServer-SQL1Smiley Surprisednline:*** End of debug information dump for troubleshooting ***
    LibLogger.cpp:VLibThreadLogQueue:Smiley Very Happyump[217]
2015/05/16 20:47:50 VCS WARNING V-16-2-13140 Thread(10516) Could not find timer entry with id 274
2015/05/16 20:47:50 VCS INFO V-16-20093-29 SQLServerSmiley FrustratedQLServer-SQL1:monitor:The 'MSSQL$SQL1' service is not in stopped or running state. State = 2.
2015/05/16 20:48:50 VCS INFO V-16-20093-29 SQLServerSmiley FrustratedQLServer-SQL1:monitor:The 'MSSQL$SQL1' service is not in stopped or running state. State = 2.
2015/05/16 20:49:50 VCS INFO V-16-20093-29 SQLServerSmiley FrustratedQLServer-SQL1:monitor:The 'MSSQL$SQL1' service is not in stopped or running state. State = 2.
2015/05/16 20:49:50 VCS ERROR V-16-2-13066 Thread(9380) Agent is calling clean for resource(SQLServer-SQL1) because the resource is not up even after online completed.
2015/05/16 20:49:50 VCS WARNING V-16-20093-55 SQLServerSmiley FrustratedQLServer-SQL1:clean:The service 'MSSQL$SQL1' is not in running state. Attempt to stop it might be unsuccessful.
2015/05/16 20:53:32 VCS WARNING V-16-2-13140 Thread(9380) Could not find timer entry with id 279
2015/05/16 20:53:32 VCS ERROR V-16-2-13068 Thread(9380) Resource(SQLServer-SQL1) - clean completed successfully.
2015/05/16 20:53:32 VCS ERROR V-16-2-13071 Thread(9380) Resource(SQLServer-SQL1): reached OnlineRetryLimit(0).
2015/05/16 20:56:41 VCS NOTICE V-16-20093-75 SQLServerSmiley FrustratedQLServer-SQL1Smiley Surprisednline:Failed to get the MSDTC Security configuration for VCS from registry.Error : [2, 2]

There are two massages when service group became online

2015/05/16 20:58:58 VCS INFO V-16-20093-30002 SQLServerSmiley FrustratedQLServer-SQL1:imf_register:Registering with IMF for online monitoring
2015/05/16 21:08:28 VCS INFO V-16-20093-30001 SQLServerSmiley FrustratedQLServer-SQL1:imf_register:Registering with IMF for offline monitoring

 

Can you heip me resolve this issue?

 

Thanks in advance.

4 Replies
Highlighted

Hi Kanstantsin, Error 2 is

Hi Kanstantsin,

Error 2 is "The system cannot find the file specified".  This is not really the root of your problem.  VCS Agents often check for override registry keys during startup/online of a resource and report this message if those keys do not exists.  In most cases, those override registry keys do not exist.

The reall error that you should be concerned with is the 258 error. Error 258 = "The wait operation timed out.".  This mean that VCS SQL agent is waiting for SQL to start but it is not starting within timeout set by the VCS SQL agent.

If I had to guess, this is related to MSDTC.  You have mentioned having multiple SQL instances clustered but you have not mentioned clustering MSDTC.  SQL without MSDTC available, will take around 10 minutes to start up.  However, the VCS SQL agent will timeout long before that 10 minute period.  You should cluster MSDTC so that it is availalble during the SQL startup (this allows SQL to start up in a normal/reasonable timeframe.)

Thank you,

Wally

Highlighted

This is some kind of magic)

This is some kind of magic) Today I made service group online and all work good, but I am worry about how it will work in future. Is cluster MSDTC necessary if to use two instances of SQL servers on same node?

Highlighted

Hi Kanstantsin, Clustering

Hi Kanstantsin,

Clustering MSDTC is needed if you are going to do distributed transactions between the 2 instances for SQL.  If you are not going to do distributed transactions then clustering MSDTC is not needed.

In either case, the MSDTC service should be running and set to Automatic startup (default).

Thank you,

Wally

Highlighted

I resolved this problem,

I resolved this problem, howaver this method is not very good.

I think that time that MSSQL service takes to start don't assosiated with MSDTC.

Because sql service take long time to start with MSDTC service group too.

I sql server logs:

2015-05-27 12:03:04.96 spid15s     Starting up database 'tempdb'.
2015-05-27 12:04:23.24 Server      Using 'dbghelp.dll' version '4.0.5'
2015-05-27 12:04:23.25 Server      ***Unable to get thread context for spid 0
2015-05-27 12:04:23.25 Server      * *******************************************************************************
2015-05-27 12:04:23.25 Server      *
2015-05-27 12:04:23.25 Server      * BEGIN STACK DUMP:
2015-05-27 12:04:23.25 Server      *   05/27/15 12:04:23 spid 18200
2015-05-27 12:04:23.25 Server      *
2015-05-27 12:04:23.25 Server      * Non-yielding Scheduler
2015-05-27 12:04:23.25 Server      *
2015-05-27 12:04:23.25 Server      * *******************************************************************************
2015-05-27 12:04:23.25 Server      Stack Signature for the dump is 0x000000000000028A
2015-05-27 12:04:25.03 Server      External dump process return code 0x20000001.
External dump process returned no errors.

2015-05-27 12:04:25.03 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 60765 ms, user 8468 ms. Process Utilization 4%. System Idle 99%. Interval: 70507 ms.
2015-05-27 12:05:25.42 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 113250 ms, user 15531 ms. Process Utilization 4%. System Idle 99%. Interval: 132687 ms.
2015-05-27 12:06:25.81 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 165828 ms, user 22250 ms. Process Utilization 4%. System Idle 99%. Interval: 193080 ms.
2015-05-27 12:07:26.18 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 218109 ms, user 29312 ms. Process Utilization 4%. System Idle 99%. Interval: 253452 ms.
2015-05-27 12:08:26.59 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 270578 ms, user 35843 ms. Process Utilization 4%. System Idle 99%. Interval: 313854 ms.
2015-05-27 12:09:26.96 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 322640 ms, user 42406 ms. Process Utilization 4%. System Idle 99%. Interval: 374241 ms.
2015-05-27 12:10:27.32 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 374234 ms, user 49250 ms. Process Utilization 4%. System Idle 99%. Interval: 434603 ms.
2015-05-27 12:11:27.70 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 425906 ms, user 55984 ms. Process Utilization 4%. System Idle 99%. Interval: 494981 ms.
2015-05-27 12:12:28.07 Server      Process 0:0:0 (0x31bc) Worker 0x000000886D802160 appears to be non-yielding on Scheduler 47. Thread creation time: 13077190981781. Approx Thread CPU Used: kernel 476703 ms, user 63359 ms. Process Utilization 4%. System Idle 99%. Interval: 555349 ms.

2015-05-27 12:12:38.26 spid25s     The Service Broker endpoint is in disabled or stopped state.

The SQL server start "BEGIN STACK DUMP, Non-yielding Scheduler", this process take 8 minuts. As a result SQL server take 10.30 minuts to start. I didn't resolve problem with sql yet, But I expant SQLonline timeout (SQLserver agent) and SQL can wait sql server now.

Maybe this will help somebody.