Question: Checking the SQL Server Logs on a server that recently rebooted, it looks as if SQL Server is actually running DBCC CHECKDB against most of my databases at startup. Only, execution is only taking a few seconds. What’s causing SQL Server to suspect my databases enough to run DBCC CHECKDB on them, and what options is it using when running DBCC CHECKDB to make it complete so quickly? More importantly, is there anything I can do to either stop this behavior, or stop SQL Server from thinking that there’s a problem with my databases?
Answer: When looking at the accompanying screenshot (Figure 1), it’s easy to see why you might be tempted to think that SQL Server is, indeed, checking your databases as part of the recovery process when it starts up – because SQL Server is pushing CHECKDB-related output into the logs as part of the startup process. However, SQL Server isn’t actually running DBCC CHECKDB at startup. Instead, it’s just echoing out information about the last time the database was successfully checked. Which, in turn, means that there are a couple of lessons to be learned from this kind of scenario.
Figure 1: It’s easy to see why you might THINK that SQL Server is running DBCC CHECKDB at startup.
Background / Explanation
Each time that DBCC CHECKDB successfully completes (i.e., detects no errors) against a database, SQL Server writes the outcome/timestamp of that operation into the database header page of the database in question. Specifically, it logs this information to page 9, into a value called dbi_dbccLastKnownGood – that you can query yourself by running DBCC PAGE() as shown below (after switching output to your local console):
Figure 2: Peeking at how SQL Server stores information about the last successful execution of DBCC CHECKDB().
When this information has been written to page 9, SQL Server will ‘echo’ it out when the server starts up – and as part of the process that SQL Server goes through to spin-up your database. The key thing to note, however, is that SQL Server is just spitting out the ‘last known good’ timestamp as recorded in page 9.
SQL Server is not, therefore, executing DBCC CHECKDB() – even though that might look like the case at first glance when reviewing SQL Server Logs.
Lessons Learned
In fact, if you look at the output in Figure 1, it might look like a handful of databases are started up, then it might look like CHECKDB kicks-off to validate databases. And, obviously, if you’ve run DBCC CHECKDB(), you know it typically takes a while to execute on databases of any size. Hence the reason it can seem so confusing that DBCC CHECKDB() seems like it is running in what literally amounts to seconds.
But, in this regard, there are a couple of lessons to be learned from this issue.
First, it’s easy to only pay attention to the timestamp in the Date column of the Log File Viewer. Furthermore, it would seemingly be logical to assume that entries added into the log are added in sequential order. (And they effectively are.) But that doesn’t mean the data being reported on is necessarily linear. More specifically, if you take a peek at the timestamps included as part of the MESSAGE in the rows displayed in Figure 1, you’ll see that DBCC CHECKD() actually occurred anywhere from 15 minutes (down to 6 minutes) prior to when the server in Figure 1 restarted. So, moral of the story: pay attention to the content (not just the summary/title) of log entries to stay ahead of the game.
Second, it sure would be confusing if SQL Server were somehow running a ‘light-weight’ or ‘faster’ version of DBCC CHECKDB() upon startup – because that would seem like there was a ‘secret’ version of the command that could be run by the server itself. Only, one of the key things that DBCC CHECKDB() needs in order to execute, is a transactionally-consistent view of the database – something it just can’t get if the database is in the middle of the recovery process.
Third, despite any worries that the existence of these messages in the event log might be a sign of problems, they are, in fact, just one more hallmark of a properly tuned and managed system. Stated differently: you want these messages in your event log.
