December 11, 2008 at 7:51 am
We have a two node SQL Cluster whose primary database is named ‘FM’. That database was created at the same time as the cluster and the data files for that database are located in the ‘E:\MSSQL\MSSQL.1\MSSQL\Data’. We tested the failover several times before we put this into production last July.
In September, another database was added to the same SQL Instance. It is called ‘DMI’, and its data files are located in the same directory as FM’s data files.
When I failed over the cluster a few days ago, everything went fine except the DMI database wasn’t available from Server 2. I quickly failed back over to Server 1.
How can I resolve this? Do I have to add the DMI database as a separate resource?
December 11, 2008 at 8:03 am
In a cluster the whole instance does a failover and all databases inside the instance should be available after the failover.
Did you get any errors in the SQL Errorlog or Windows application log?
[font="Verdana"]Markus Bohse[/font]
December 11, 2008 at 1:38 pm
Mark,
Thanks for answering. In response to your question regarding error messages in the SQL or windows error logs, I can't find anything that would indicate why the DMI database wasn't available - but I'm new to both clustering & SQL server, so I may very well be missing something that would be obvious to someone else. Here is the SQL error log for that day:
2008-12-03 00:15:24.31 Backup Database backed up. Database: master, creation date(time): 2008/10/31(13:45:39), pages dumped: 363, first LSN: 275:328:50, last LSN: 275:360:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'E:\MSSQL\MSSQL.1\MSSQL\Backup\master_backup_200812030015.bak'}). This is an informational message only. No user action is required.
2008-12-03 13:56:21.13 spid51 Configuration option 'show advanced options' changed from 0 to 1. Run the RECONFIGURE statement to install.
2008-12-03 13:56:21.13 spid51 Configuration option 'Agent XPs' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 13:56:21.15 spid51 Configuration option 'show advanced options' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 13:56:22.27 Logon Error: 18456, Severity: 14, State: 23.
2008-12-03 13:56:22.27 Logon Login failed for user 'fvm'. [CLIENT: 180.1.217.171]
2008-12-03 13:56:22.27 spid83 Error: 18056, Severity: 20, State: 23.
2008-12-03 13:56:22.27 spid83 The client was unable to reuse a session with SPID 83, which had been reset for connection pooling. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.
2008-12-03 13:56:22.29 Logon Error: 18456, Severity: 14, State: 23.
2008-12-03 13:56:22.29 Logon Login failed for user 'fvm'. [CLIENT: 180.1.217.171]
2008-12-03 13:56:22.29 spid78 Error: 18056, Severity: 20, State: 23.
2008-12-03 13:56:22.29 spid78 The client was unable to reuse a session with SPID 78, which had been reset for connection pooling. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.
2008-12-03 13:56:22.40 spid12s Service Broker manager has shut down.
2008-12-03 13:56:22.44 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.
2008-12-03 13:56:22.44 spid5s SQL Trace was stopped due to server shutdown. Trace ID = '1'. This is an informational message only; no user action is required.
Anything there that helps?
Thanks for any help you can provide.
Paul
December 11, 2008 at 1:59 pm
Paul,
the part of the errorlog you've posted is from before the failover. I would be more interested in the errorlog after the failover if it contains any messages why your database didn't start.
[font="Verdana"]Markus Bohse[/font]
December 11, 2008 at 2:21 pm
The section of the log that you have provided appears to be from when the service was shutdown (prior to the failover).
We would need to see the section of the log when the service started up on the secondary node.
In the meantime, please verify where the data and log files reside for that database.
Jeffrey Williams
Problems are opportunities brilliantly disguised as insurmountable obstacles.
How to post questions to get better answers faster
Managing Transaction Logs
December 11, 2008 at 2:58 pm
Markus & Jeffrey,
The data & log files for both databases are located in the ‘E:\MSSQL\MSSQL.1\MSSQL\’ directory.
Here is the windows system log from the time I 1st tried to fail it over from FusionDB1 to FusionDB2 until I thought it had successfully failed over.
12/3/2008 1:56:10 PM ClusSvc 1203 N/A FUSIONDB1 The Cluster Service is attempting to offline the Resource Group "Cluster Group".
12/3/2008 1:56:11 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:13 PM ClusSvc 1200 N/A FUSIONDB2 The Cluster Service is attempting to bring online the Resource Group "Cluster Group".
12/3/2008 1:56:13 PM ClusSvc 1204 N/A FUSIONDB1 The Cluster Service brought the Resource Group "Cluster Group" offline.
12/3/2008 1:56:16 PM W32Time 37 N/A FUSIONDB2 The time provider NtpClient is currently receiving valid time data from luey.centracare.com (ntp.d|180.1.5.198:123->180.1.0.42:123).
12/3/2008 1:56:19 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The SQL Server Agent (MSSQLSERVER) service was successfully sent a stop control.
12/3/2008 1:56:19 PM ClusSvc 1203 N/A FUSIONDB1 The Cluster Service is attempting to offline the Resource Group "SQL Group".
12/3/2008 1:56:21 PM Service Control Manager 7036 N/A FUSIONDB1 The SQL Server Agent (MSSQLSERVER) service entered the stopped state.
12/3/2008 1:56:22 PM Service Control Manager 7023 N/A FUSIONDB2 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:22 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:22 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:22 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:22 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The Distributed Transaction Coordinator service was successfully sent a start control.
12/3/2008 1:56:22 PM Service Control Manager 7036 N/A FUSIONDB1 The SQL Server FullText Search (MSSQLSERVER) service entered the stopped state.
12/3/2008 1:56:22 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The SQL Server FullText Search (MSSQLSERVER) service was successfully sent a stop control.
12/3/2008 1:56:22 PM Service Control Manager 7036 N/A FUSIONDB1 The SQL Server (MSSQLSERVER) service entered the stopped state.
12/3/2008 1:56:22 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The SQL Server (MSSQLSERVER) service was successfully sent a stop control.
12/3/2008 1:56:23 PM Service Control Manager 7023 N/A FUSIONDB2 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:23 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:23 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:23 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:23 PM ClusSvc 1069 N/A FUSIONDB2 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:23 PM ClusSvc 1042 N/A FUSIONDB2 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:23 PM Service Control Manager 7036 N/A FUSIONDB2 The Distributed Transaction Coordinator service entered the running state.
12/3/2008 1:56:24 PM Service Control Manager 7023 N/A FUSIONDB2 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:24 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:24 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:24 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:24 PM ClusSvc 1069 N/A FUSIONDB2 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:24 PM ClusSvc 1042 N/A FUSIONDB2 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:25 PM Service Control Manager 7023 N/A FUSIONDB2 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:25 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:25 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:25 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:25 PM ClusSvc 1069 N/A FUSIONDB2 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:25 PM ClusSvc 1042 N/A FUSIONDB2 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:26 PM Service Control Manager 7036 N/A FUSIONDB2 The Distributed Transaction Coordinator service entered the stopped state.
12/3/2008 1:56:26 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The Distributed Transaction Coordinator service was successfully sent a stop control.
12/3/2008 1:56:26 PM ClusSvc 1203 N/A FUSIONDB2 The Cluster Service is attempting to offline the Resource Group "Cluster Group".
12/3/2008 1:56:26 PM ClusSvc 1205 N/A FUSIONDB2 The Cluster Service failed to bring the Resource Group "Cluster Group" completely online or offline.
12/3/2008 1:56:26 PM ClusSvc 1069 N/A FUSIONDB2 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:26 PM ClusSvc 1042 N/A FUSIONDB2 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:27 PM ClusSvc 1205 N/A FUSIONDB2 The Cluster Service failed to bring the Resource Group "Cluster Group" completely online or offline.
12/3/2008 1:56:27 PM ClusSvc 1153 N/A FUSIONDB2 Cluster service is attempting to failover the Cluster Resource Group 'Cluster Group' from node FUSIONDB2 to node FUSIONDB1.
12/3/2008 1:56:27 PM ClusSvc 1200 N/A FUSIONDB1 The Cluster Service is attempting to bring online the Resource Group "Cluster Group".
12/3/2008 1:56:28 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The SQL Server Analysis Services (MSSQLSERVER) service was successfully sent a stop control.
12/3/2008 1:56:28 PM Service Control Manager 7036 N/A FUSIONDB1 The SQL Server Analysis Services (MSSQLSERVER) service entered the stopped state.
12/3/2008 1:56:29 PM ClusSvc 1200 N/A FUSIONDB2 The Cluster Service is attempting to bring online the Resource Group "SQL Group".
12/3/2008 1:56:29 PM W32Time 29 N/A FUSIONDB1 The time provider NtpClient is configured to acquire time from one or more time sources, however none of the sources are currently accessible. No attempt to contact a source will be made for 1 minutes. NtpClient has no source of accurate time.
12/3/2008 1:56:29 PM ClusSvc 1204 N/A FUSIONDB1 The Cluster Service brought the Resource Group "SQL Group" offline.
12/3/2008 1:56:30 PM Service Control Manager 7036 N/A FUSIONDB2 The SQL Server FullText Search (MSSQLSERVER) service entered the running state.
12/3/2008 1:56:30 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The SQL Server FullText Search (MSSQLSERVER) service was successfully sent a start control.
12/3/2008 1:56:30 PM W32Time 35 N/A FUSIONDB1 The time service is now synchronizing the system time with the time source TSLICENSE.centracare.com (ntp.d|180.1.5.197:123->180.1.5.53:123).
12/3/2008 1:56:30 PM W32Time 37 N/A FUSIONDB1 The time provider NtpClient is currently receiving valid time data from TSLICENSE.centracare.com (ntp.d|180.1.5.197:123->180.1.5.53:123).
12/3/2008 1:56:39 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The SQL Server Analysis Services (MSSQLSERVER) service was successfully sent a start control.
12/3/2008 1:56:40 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The SQL Server (MSSQLSERVER) service was successfully sent a start control.
12/3/2008 1:56:40 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:40 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:40 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The Distributed Transaction Coordinator service was successfully sent a start control.
12/3/2008 1:56:41 PM Service Control Manager 7023 N/A FUSIONDB1 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:41 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:41 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:41 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:41 PM ClusSvc 1069 N/A FUSIONDB1 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:41 PM ClusSvc 1042 N/A FUSIONDB1 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:41 PM Service Control Manager 7023 N/A FUSIONDB1 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:41 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:41 PM Service Control Manager 7036 N/A FUSIONDB1 The Distributed Transaction Coordinator service entered the running state.
12/3/2008 1:56:42 PM Service Control Manager 7023 N/A FUSIONDB1 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:42 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:42 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:42 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:42 PM ClusSvc 1069 N/A FUSIONDB1 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:42 PM ClusSvc 1042 N/A FUSIONDB1 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:43 PM Service Control Manager 7036 N/A FUSIONDB2 The SQL Server Analysis Services (MSSQLSERVER) service entered the running state.
12/3/2008 1:56:43 PM Service Control Manager 7023 N/A FUSIONDB1 "The TSM Client Acceptor fusiondbcl service terminated with the following error:
%%406"
12/3/2008 1:56:43 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the stopped state.
12/3/2008 1:56:43 PM Service Control Manager 7036 N/A FUSIONDB1 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:43 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:43 PM ClusSvc 1069 N/A FUSIONDB1 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:43 PM ClusSvc 1042 N/A FUSIONDB1 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:44 PM Service Control Manager 7036 N/A FUSIONDB1 The Distributed Transaction Coordinator service entered the stopped state.
12/3/2008 1:56:44 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB1 The Distributed Transaction Coordinator service was successfully sent a stop control.
12/3/2008 1:56:44 PM ClusSvc 1203 N/A FUSIONDB1 The Cluster Service is attempting to offline the Resource Group "Cluster Group".
12/3/2008 1:56:44 PM ClusSvc 1205 N/A FUSIONDB1 The Cluster Service failed to bring the Resource Group "Cluster Group" completely online or offline.
12/3/2008 1:56:44 PM ClusSvc 1069 N/A FUSIONDB1 Cluster resource 'TSM Client Acceptor fusiondbcl' in Resource Group 'Cluster Group' failed.
12/3/2008 1:56:44 PM ClusSvc 1042 N/A FUSIONDB1 Cluster generic service 'TSM Client Acceptor fusiondbcl' failed.
12/3/2008 1:56:45 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The SQL Server Agent (MSSQLSERVER) service was successfully sent a start control.
12/3/2008 1:56:45 PM Service Control Manager 7036 N/A FUSIONDB2 The SQL Server (MSSQLSERVER) service entered the running state.
12/3/2008 1:56:45 PM ClusSvc 1205 N/A FUSIONDB1 The Cluster Service failed to bring the Resource Group "Cluster Group" completely online or offline.
12/3/2008 1:56:45 PM ClusSvc 1153 N/A FUSIONDB1 Cluster service is attempting to failover the Cluster Resource Group 'Cluster Group' from node FUSIONDB1 to node FUSIONDB2.
12/3/2008 1:56:46 PM ClusSvc 1200 N/A FUSIONDB2 The Cluster Service is attempting to bring online the Resource Group "Cluster Group".
12/3/2008 1:56:47 PM Service Control Manager 7036 N/A FUSIONDB2 The SQL Server Agent (MSSQLSERVER) service entered the running state.
12/3/2008 1:56:47 PM ClusSvc 1201 N/A FUSIONDB2 The Cluster Service brought the Resource Group "SQL Group" online.
12/3/2008 1:56:47 PM W32Time 35 N/A FUSIONDB2 The time service is now synchronizing the system time with the time source luey.centracare.com (ntp.d|180.1.5.200:123->180.1.0.42:123).
12/3/2008 1:56:47 PM W32Time 37 N/A FUSIONDB2 The time provider NtpClient is currently receiving valid time data from luey.centracare.com (ntp.d|180.1.5.200:123->180.1.0.42:123).
12/3/2008 1:56:57 PM Service Control Manager 7036 N/A FUSIONDB2 The Distributed Transaction Coordinator service entered the running state.
12/3/2008 1:56:57 PM Service Control Manager 7036 N/A FUSIONDB2 The TSM Client Acceptor fusiondbcl service entered the running state.
12/3/2008 1:56:57 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The TSM Client Acceptor fusiondbcl service was successfully sent a start control.
12/3/2008 1:56:57 PM Service Control Manager 7035 ST_CLOUD\clusteradmin FUSIONDB2 The Distributed Transaction Coordinator service was successfully sent a start control.
12/3/2008 1:56:58 PM ClusSvc 1201 N/A FUSIONDB2 The Cluster Service brought the Resource Group "Cluster Group" online.
Here is the complete SQL Error log for 12/3 (This log is from FusionDB1, which owned the cluster at the start - and the end - of this process.)
2008-12-03 00:00:03.17 spid21s This instance of SQL Server has been using a process ID of 216 since 10/31/2008 1:45:41 PM (local) 10/31/2008 6:45:41 PM (UTC). This is an informational message only; no user action is required.
2008-12-03 00:15:24.12 Backup Database backed up. Database: FM, creation date(time): 2008/06/13(09:24:54), pages dumped: 109204, first LSN: 39935:1433:126, last LSN: 39935:1581:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'E:\MSSQL\MSSQL.1\MSSQL\Backup\FM_backup_200812030015.bak'}). This is an informational message only. No user action is required.
2008-12-03 00:15:24.31 Backup Database backed up. Database: master, creation date(time): 2008/10/31(13:45:39), pages dumped: 363, first LSN: 275:328:50, last LSN: 275:360:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'E:\MSSQL\MSSQL.1\MSSQL\Backup\master_backup_200812030015.bak'}). This is an informational message only. No user action is required.
2008-12-03 13:56:21.13 spid51 Configuration option 'show advanced options' changed from 0 to 1. Run the RECONFIGURE statement to install.
2008-12-03 13:56:21.13 spid51 Configuration option 'Agent XPs' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 13:56:21.15 spid51 Configuration option 'show advanced options' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 13:56:22.27 Logon Error: 18456, Severity: 14, State: 23.
2008-12-03 13:56:22.27 Logon Login failed for user 'fvm'. [CLIENT: 180.1.217.171]
2008-12-03 13:56:22.27 spid83 Error: 18056, Severity: 20, State: 23.
2008-12-03 13:56:22.27 spid83 The client was unable to reuse a session with SPID 83, which had been reset for connection pooling. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.
2008-12-03 13:56:22.29 Logon Error: 18456, Severity: 14, State: 23.
2008-12-03 13:56:22.29 Logon Login failed for user 'fvm'. [CLIENT: 180.1.217.171]
2008-12-03 13:56:22.29 spid78 Error: 18056, Severity: 20, State: 23.
2008-12-03 13:56:22.29 spid78 The client was unable to reuse a session with SPID 78, which had been reset for connection pooling. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.
2008-12-03 13:56:22.40 spid12s Service Broker manager has shut down.
2008-12-03 13:56:22.44 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.
2008-12-03 13:56:22.44 spid5s SQL Trace was stopped due to server shutdown. Trace ID = '1'. This is an informational message only; no user action is required.
2008-12-03 13:56:40.48 Server Microsoft SQL Server 2005 - 9.00.3054.00 (Intel X86)
Mar 23 2007 16:28:52
Copyright (c) 1988-2005 Microsoft Corporation
Standard Edition on Windows NT 5.2 (Build 3790: Service Pack 2)
2008-12-03 13:56:40.54 Server (c) 2005 Microsoft Corporation.
2008-12-03 13:56:40.54 Server All rights reserved.
2008-12-03 13:56:40.54 Server Server process ID is 3024.
2008-12-03 13:56:40.54 Server Authentication mode is MIXED.
2008-12-03 13:56:40.56 Server Logging SQL Server messages in file 'E:\MSSQL\MSSQL.1\MSSQL\LOG\ERRORLOG'.
2008-12-03 13:56:40.56 Server This instance of SQL Server last reported using a process ID of 216 at 12/3/2008 1:56:22 PM (local) 12/3/2008 7:56:22 PM (UTC). This is an informational message only; no user action is required.
2008-12-03 13:56:40.56 Server Registry startup parameters:
2008-12-03 13:56:40.56 Server -d E:\MSSQL\MSSQL.1\MSSQL\DATA\master.mdf
2008-12-03 13:56:40.56 Server -e E:\MSSQL\MSSQL.1\MSSQL\LOG\ERRORLOG
2008-12-03 13:56:40.56 Server -l E:\MSSQL\MSSQL.1\MSSQL\DATA\mastlog.ldf
2008-12-03 13:56:40.61 Server SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
2008-12-03 13:56:40.61 Server Detected 8 CPUs. This is an informational message; no user action is required.
2008-12-03 13:56:40.86 Server Set AWE Enabled to 1 in the configuration parameters to allow use of more memory.
2008-12-03 13:56:41.28 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.
2008-12-03 13:56:41.64 Server Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
2008-12-03 13:56:44.14 Server Attempting to recover in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required.
2008-12-03 13:56:44.20 Server Database mirroring has been enabled on this instance of SQL Server.
2008-12-03 13:56:44.28 spid5s Starting up database 'master'.
2008-12-03 13:56:44.50 spid5s SQL Trace ID 1 was started by login "sa".
2008-12-03 13:56:44.51 spid5s Starting up database 'mssqlsystemresource'.
2008-12-03 13:56:44.51 spid5s The resource database build version is 9.00.3042. This is an informational message only. No user action is required.
2008-12-03 13:56:44.68 spid9s Starting up database 'model'.
2008-12-03 13:56:44.68 spid5s Server name is 'FUSIONSQL'. This is an informational message only. No user action is required.
2008-12-03 13:56:44.68 spid5s The NETBIOS name of the local node that is running the server is 'FUSIONDB2'. This is an informational message only. No user action is required.
2008-12-03 13:56:44.75 spid9s Clearing tempdb database.
2008-12-03 13:56:44.86 spid9s Starting up database 'tempdb'.
2008-12-03 13:56:44.90 spid12s The Service Broker protocol transport is disabled or not configured.
2008-12-03 13:56:44.90 spid12s The Database Mirroring protocol transport is disabled or not configured.
2008-12-03 13:56:44.95 spid12s Service Broker manager has started.
2008-12-03 13:56:45.11 Server A self-generated certificate was successfully loaded for encryption.
2008-12-03 13:56:45.12 Server Server is listening on [ 180.1.5.200 1433].
2008-12-03 13:56:45.12 Server Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ].
2008-12-03 13:56:45.12 Server Server named pipe provider is ready to accept connection on [ \\.\pipe\$$\FUSIONSQL\sql\query ].
2008-12-03 13:56:45.15 Server The SQL Network Interface library could not register the Service Principal Name (SPN) for the SQL Server service. Error: 0x2098, state: 15. 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.
2008-12-03 13:56:45.15 Server SQL Server is now ready for client connections. This is an informational message; no user action is required.
2008-12-03 13:56:45.18 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.
2008-12-03 13:56:45.28 spid5s Starting up database 'msdb'.
2008-12-03 13:56:45.31 Logon Error: 18456, Severity: 14, State: 16.
2008-12-03 13:56:45.31 Logon Login failed for user 'fvm'. [CLIENT: 180.1.5.195]
2008-12-03 13:56:45.36 spid5s Recovery is complete. This is an informational message only. No user action is required.
2008-12-03 13:56:45.90 spid53 Starting up database 'FM'.
2008-12-03 13:56:46.07 spid53 Recovery is writing a checkpoint in database 'FM' (5). This is an informational message only. No user action is required.
2008-12-03 13:56:46.15 spid52 Configuration option 'show advanced options' changed from 0 to 1. Run the RECONFIGURE statement to install.
2008-12-03 13:56:46.15 spid52 Configuration option 'Agent XPs' changed from 0 to 1. Run the RECONFIGURE statement to install.
2008-12-03 13:56:46.17 spid52 Configuration option 'show advanced options' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 13:56:46.86 spid52 Using 'xpsqlbot.dll' version '2005.90.3042' to execute extended stored procedure 'xp_qv'. This is an informational message only; no user action is required.
2008-12-03 13:56:47.21 spid52 Using 'xpstar90.dll' version '2005.90.3042' to execute extended stored procedure 'xp_instance_regread'. This is an informational message only; no user action is required.
2008-12-03 13:56:47.26 spid52 Using 'xplog70.dll' version '2005.90.3042' to execute extended stored procedure 'xp_msver'. This is an informational message only; no user action is required.
2008-12-03 16:04:15.57 spid52 Configuration option 'show advanced options' changed from 0 to 1. Run the RECONFIGURE statement to install.
2008-12-03 16:04:15.58 spid52 Configuration option 'Agent XPs' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 16:04:15.58 spid52 Configuration option 'show advanced options' changed from 1 to 0. Run the RECONFIGURE statement to install.
2008-12-03 16:04:16.63 spid12s Service Broker manager has shut down.
2008-12-03 16:04:16.68 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.
2008-12-03 16:04:16.68 spid5s SQL Trace was stopped due to server shutdown. Trace ID = '1'. This is an informational message only; no user action is required
If you want to take this offline, just let me know & I'll provide you w/my email address.
Thanks again,
Paul
December 11, 2008 at 3:36 pm
I see no references to the DMI database - either starting up or shutting down. That would tell me that the database does not exist in that instance. Do you have any portion of the SQL Server log that shows that database starting up?
I only need to see the portion of the log up to where the database is started and recovered. It should look like: Starting up database 'DMI'. There will also be a message in the log for the CHECKDB operation on that database after it was started.
Jeffrey Williams
Problems are opportunities brilliantly disguised as insurmountable obstacles.
How to post questions to get better answers faster
Managing Transaction Logs
December 11, 2008 at 3:57 pm
JHeffrey,
The only mention of the 'DMI' database in any log on that day is in the Windows Application Event log on FusuionDB1 - from when I failed it back over to FusionDB1 from FusionDB2:
12/3/2008 4:05:15 PM MSSQLSERVER Information -2 17137 N/A FUSIONSQL Starting up database 'DMI'.
12/3/2008 4:05:16 PM MSSQLSERVER Information -2 3454 N/A FUSIONSQL Recovery is writing a checkpoint in database 'DMI' (6). This is an informational message only. No user action is required.
Now that I know what to look for, can you tell me how to troubleshoot why it didn't start up when I failed it over from FusionDB1 to FusionDB2?
Thank you,
Paul
December 11, 2008 at 5:29 pm
At this point, I really could not say how to troubleshoot this problem. It appears (to me) that the DMI database does not reside in that instance of SQL Server. Is it possible that you have installed multiple instances on the cluster?
You really should be able to see that message in the SQL Server log. SQL Server will log that message for every database that it starts up.
Jeffrey Williams
Problems are opportunities brilliantly disguised as insurmountable obstacles.
How to post questions to get better answers faster
Managing Transaction Logs
December 11, 2008 at 5:48 pm
Could you or someone have installed this database on one of the individual instances and not the virtual?
Follow me on Twitter: http://www.twitter.com/way0utwest
Forum Etiquette: How to post data/code on a forum to get the best help
My Blog: www.voiceofthedba.com
December 12, 2008 at 10:28 am
Jeffrey & Steve,
It's hard for me to say exactly how DMI was installed, because the vendor installed it using a sql script on 9/4/08. When I open SQL Server Mgt Studio and connect to the FusionSQL instance the DMI database appears directly above the FM database in the 'Databases' directory. The permissions look the same on both databases. The DMI database works fine on the FusionDB1 node. It's just when I fail over to FusionDB2 that it doesn't start. This is a production system that I can't take down except briefly in the wee hours of the am. Any ideas on what to try next? Even if not, I really appreciate the time all of you have taken to try to help me with this.
Paul
December 12, 2008 at 11:37 am
Well, to be perfectly honest I am now at a complete loss. You really should be able to see that database being started by SQL Server. It really shouldn't matter what node you are on - when the system is restarted.
However, having just said that - where exactly are the log files stored? Are the log files on a shared/cluster resource, or are they on the C: drive? Not sure why somebody would move them to a non-clustered resource though.
You wouldn't happen to know if you are using mount points for your database files? Heck, I am just throwing stuff out there for consideration.
Any way you could identify how the cluster is actually configured? What cluster groups do you have, what resources are assigned in each group and what are their dependencies?
Jeffrey Williams
Problems are opportunities brilliantly disguised as insurmountable obstacles.
How to post questions to get better answers faster
Managing Transaction Logs
December 12, 2008 at 2:51 pm
Jeffrey,
The log files are stored on the 'E:SQLData' drive, which is a cluster resource. The full path to the directory is "E:\MSSQL\MSSQL.1\MSSQL\LOG".
I don't know about the 'mount points' question. I'll research what that means and get back to you on that one.
The cluster includes two groups:
The 'Cluster Group' which has the following resources:
Cluster IP Address (No dependencies) (Type=IP Address)
Cluster Name (Dep=Cluster IP Address)
Disk Q (No dependencies) (Type=Physical Disk)
Fusion Audio (Dep=Voice Files) (Type=Physical Disk)
MSDTC (Dep=Cluster Name & Disk Q) (Type=Dist Trans Coor)
TSM Client Acceptor fusiondbcl (Dep=Cluster IP Address, Cluster Name, Disk Q:, Voice Files) (Type=Generic Service)
Voice Files (No dependencies) (Type=Physical Disk)
The 'SQL Group' which includes the following resources:
Analysis Services (Dep=SQL Data & SQL Network Name (FusionSQL)) (Type=Generic Service)
SQL Data (No dependencies) (Type=Physical Disk)
SQL IP Address 1 (FusionSQL) (No dependencies) (Type=IP Address)
SQL Network Name (FusionSQL) (Dep=SQL IP Address 1 (FusionSQL)) (Type=Network Name)
SQL Server (Dep=SQL Data & SQL Network Name (FusionSQL)) (Type=SQL Server)
SQL Server Agent (Dep=SQL Server) (Type=SQL Server Agent)
SQL Server Fulltext (Dep=SQL Data) (Type=Generic Service)
Everything in both groups is online. Everything in both groups was online when I failed over to the other server. Very strange.
Thanks again,
Paul
December 12, 2008 at 3:48 pm
Everything looks right - don't see anything that jumps out and says there might be a problem with the cluster setup.
Sorry, I can't think of anything else to look at.
Jeffrey Williams
Problems are opportunities brilliantly disguised as insurmountable obstacles.
How to post questions to get better answers faster
Managing Transaction Logs
February 25, 2009 at 11:45 am
This topic may be closed. This issue fixed itself somehow. The next time I failed it over, everything worked like it should. A momentary glich of some kind.
Viewing 15 posts - 1 through 14 (of 14 total)
You must be logged in to reply to this topic. Login to reply