Decoding SQL Server Startup Process and Checking for Errors
There are various tasks that take place when SQL Server is started in a particular sequence. If there are any failures, it will be reported in the SQL Server Errorlog. In this article let’s try to understand what SQL Server does while it is starting up. There are many internal tasks which SQL Server performs, but will not be covered here as our focus is to understand what SQL Server is doing for a general user perspective by decoding the SQL Server Errorlog file.
Below is the snipped of SQL Server 2008 R2 errorlog, broken down into sections to understand what action is being performed.
At the very start of SQL Server we can find the details about SQL Server Version, Edition, Platform and Operating System related details.
Server Microsoft SQL Server 2008 R2 (RTM) – 10.50.1600.1 (X64)
Apr 25 2011 16:43:45
Copyright (c) Microsoft Corporation
Enterprise Edition (64-bit) on Windows NT 6.1
Server (c) Microsoft Corporation.
Server All rights reserved.
Next, we can find the process ID of SQLServr.exe process for this SQL Server instance. If it is a VMware system, we can find those details too
Server Server process ID is 566.
Server System Manufacturer: ‘VMware, Inc.’, System Model: ‘VMware Virtual Platform’.
Below shows us which Authentication Mode is SQL Server instance currently configured to allow connections. Mixed means, it allows both Windows and SQL Server Authentication.
Server Authentication mode is MIXED.
Next, we can find the location of the SQL Server Errorlog file where informational, Warning and Error Messages of SQL Server are logged.
Server Logging SQL Server messages in file ‘C:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQLSERVER\MSSQL\Log\ERRORLOG’.
We can next fine, what the the process ID of SQL Server used last time before the restart of SQL Server. Next, we can see SQL Server reads the registry details and identified the path of Master database .mdf and .ldf files locations.
Server This instance of SQL Server last reported using a process ID of 1844 at 5/21/2012 5:23:23 AM (local). This is an informational message only; no user action is required.
2011-03-28 19:13:01.850 Server Registry startup parameters:
-d C:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\master.mdf
-e C:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQLSERVER\MSSQL\Log\ERRORLOG
-l C:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQLSERVER\MSSQL\DATA\mastlog.ldf
The checks for the priority with which SQL Server should start and logs the same. Then there will be additional details identified like number of CPUs on the server detected by the SQL Server. It then checks if lock pages in memory privilege has been enabled for the SQL Server service account or not and logs if it is enabled. If any configuration to default lock settings was changed, it will read and shows the same.
Server SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
Server Detected 4 CPUs. This is an informational message; no user action is required.
Server Using locked pages for buffer pool.
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.
Server Node configuration: node 0: CPU mask: 0x000000000000000f:0 Active CPU mask: 0x000000000000000f:0. This message provides a description of the NUMA configuration for this computer. This is an informational message only. No user action is required.
Next, SQL Server will start the Master database and then performs recovery the master database. If it fails in this process, it will be logged here and SQL Services will be stopped.
spid5s Starting up database ‘master’.
spid5s Recovery is writing a checkpoint in database ‘master’ (1). This is an informational message only. No user action is required.
Some additional details related to additional features usages is logged as shows below it shows information related to Resource Governor, SQL Server Audits, FileStream, etc.
spid5s Resource governor reconfiguration succeeded.
spid5s SQL Server Audit is starting the audits. This is an informational message. No user action is required.
spid5s SQL Server Audit has started the audits. This is an informational message. No user action is required.
FILESTREAM: effective level = 0, configured level = 0, file system access share name = ‘MSSQLSERVER’.
If default trace configuration option is enabled, then it will start the same. Then it starts the internal hidden database Resource Database. We can see its version from here.
spid5s SQL Trace ID 1 was started by login “sa”.
spid5s Starting up database ‘mssqlsystemresource’.
spid5s The resource database build version is 10.50.1600. This is an informational message only. No user action is required.
We can notice the physical SQL Server server name. On cluster server, we can see the NetBios Name followed after this.
spid5s Server name is ‘Test_Server’. This is an informational message only. No user action is required.
Next Model database is started and same will be logged in the errorlog.
spid10s Starting up database ‘model’.
Additional information related to any SSL Certificates used by SQL Server or is it using the self-generated certificate is logged. Any failure using the SSL certificate will be logged here and then SQL Server will stop.
Server A self-generated certificate was successfully loaded for encryption.
SQL Server will check for the TCP/IP Port and Named Pipe details and same will be logged. Any failure using a particular port will be logged here.
Server Server is listening on [ ‘any’
Server Server is listening on [ ‘any’
Server Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ].
Server Server named pipe provider is ready to accept connection on [ \\.\pipe\sql\query ].
Server Server is listening on [ ::1
Server Server is listening on [ 127.0.0.1
Server Dedicated admin connection support was established for listening locally on port 1434.
TempDB is restarted each time, SQL Server starts, so we will see messages related to tempdb cleaning and then starting.
spid10s Clearing tempdb database.
spid10s Starting up database ‘tempdb’.
Next, it will check for SPN settings and try to setup SPN, if SQL Service account has enough permissions to create. If it fails, it will be reported and NTLM authentication will be used instead of kerberos.
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 i
Server SQL Server is now ready for client connections. This is an informational message; no user action is required.
Next, SQL Server starts and recovers all the user databases which are Online. Any failures starting a particular database will be logged here.
spid21s Starting up database ‘ReportServer’.
spid23s Starting up database ‘ReportServerTempDB’.
spid13s Starting up database ‘msdb’.
spid22s Starting up database ‘test_db’.
SQL Server startup completes here and any further messages logged will be related to activities performed on SQL Server which are configured to be logged in SQL Server Errorlog like, Full Backup and Log backup completion informational message, backup failure message, Login Failed Messages, any other warnings or errors.
Looking through the SQL Server Errorlog carefully will let us identify any problems causing SQL Server failure during startup or when it is stopped or restarted unexpectedly.
This is applicable on below versions of SQL Server
SQL Server 2005
SQL Server 2008 R2
SQL Server 2012
SQL Server 2014
Hope this was helpful.
In-Depth Blogs on SQL Server, Information about SQL Server Conferences and Events, SQL Server Frequently asked questions, SQL Server Trainings.