Checkpoint – One of the wonderful mechanisms baked within SQL Server to Flush Dirty Pages to Disk and to clear Transaction log(When a Database is Set to SIMPLE Recovery Model) automatically.
Few scenarios where CHECKPOINTS are triggered automatically:
When SQL Instance has been Shutdown, a checkpoint on all the databases.
A Checkpoint on Model Database each time a new database has been created.
T-Log 70% full and Database is in Simple Recovery Model.
A Manual CHECKPOINT by a Sysadmin or Database Owner/Backup Operator.
So…Is there any easy way to monitor the occurrences of Checkpoint??
Yes…We’ve a Documented Trace Flag 3502 which can be enabled Globally.
Demo: Scenario 1 – Shutting Down SQL Instance
I’ve enabled 3502 Traceflag and shut down my SQL Instance. See the Error Log contents below.
2011-09-19 22:12:08.200 spid52 Microsoft SQL Server 2008 R2 (SP1) – 10.50.2425.0 (X64)
Apr 6 2011 21:03:25
Copyright (c) Microsoft Corporation
Developer Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)
2011-09-19 22:12:08.210 spid52 (c) Microsoft Corporation.
2011-09-19 22:12:08.210 spid52 All rights reserved.
2011-09-19 22:12:08.210 spid52 Server process ID is 1968.
2011-09-19 22:12:08.210 spid52 System Manufacturer: ‘Dell Inc.’, System Model: ‘Studio 1555’.
2011-09-19 22:12:08.210 spid52 Authentication mode is MIXED.
2011-09-19 22:12:08.220 spid52 Logging SQL Server messages in file ‘C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\Log\ERRORLOG’.
2011-09-19 22:12:08.220 spid52 The error log has been reinitialized. See the previous log for older entries.
2011-09-19 22:12:29.830 spid52 DBCC TRACEON 3502, server process ID (SPID) 52. This is an informational message only; no user action is required.
2011-09-19 22:13:09.050 spid7s Checkpointing and truncating dbid 1 (master).
2011-09-19 22:13:09.060 spid7s Ckpt dbid 1 started (8)
2011-09-19 22:13:09.060 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.100 spid7s Ckpt dbid 1 phase 1 ended (8)
2011-09-19 22:13:09.130 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.140 spid7s Ckpt dbid 1 complete
2011-09-19 22:13:09.140 spid7s Checkpointing and truncating dbid 2 (tempdb).
2011-09-19 22:13:09.140 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.160 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.200 spid7s No checkpoint needed on dbid 3 (model).
2011-09-19 22:13:09.200 spid7s Checkpointing and truncating dbid 4 (msdb).
2011-09-19 22:13:09.220 spid7s Ckpt dbid 4 started (8)
2011-09-19 22:13:09.220 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.220 spid7s Ckpt dbid 4 phase 1 ended (8)
2011-09-19 22:13:09.260 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.310 spid7s Ckpt dbid 4 complete
2011-09-19 22:13:09.350 spid7s No checkpoint needed on dbid 5 (LiteSpeedLocal).
2011-09-19 22:13:09.360 spid7s No checkpoint needed on dbid 6 (LiteSpeedCentral).
2011-09-19 22:13:09.730 spid7s No checkpoint needed on dbid 8 (AdventureWorksDW2008R2).
2011-09-19 22:13:09.780 spid7s No checkpoint needed on dbid 9 (AdventureWorksLT2008R2).
2011-09-19 22:13:09.910 spid7s Checkpointing and truncating dbid 10 (AdventureWorks).
2011-09-19 22:13:09.910 spid7s Ckpt dbid 10 started (8)
2011-09-19 22:13:09.930 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.930 spid7s Ckpt dbid 10 phase 1 ended (8)
2011-09-19 22:13:09.930 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.980 spid7s Ckpt dbid 10 complete
2011-09-19 22:13:10.000 spid7s No checkpoint needed on dbid 11 (AdventureWorksDW).
2011-09-19 22:13:10.030 spid7s Checkpointing and truncating dbid 12 (AdventureWorksLT).
2011-09-19 22:13:10.030 spid7s Ckpt dbid 12 started (8)
2011-09-19 22:13:10.060 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.070 spid7s Ckpt dbid 12 phase 1 ended (8)
2011-09-19 22:13:10.070 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.120 spid7s Ckpt dbid 12 complete
2011-09-19 22:13:10.150 spid7s Checkpointing and truncating dbid 13 (AdventureWorks_11).
2011-09-19 22:13:10.150 spid7s Ckpt dbid 13 started (8)
2011-09-19 22:13:10.150 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.170 spid7s Ckpt dbid 13 phase 1 ended (8)
2011-09-19 22:13:10.170 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.210 spid7s Ckpt dbid 13 complete
2011-09-19 22:13:10.220 spid7s Checkpointing and truncating dbid 14 (AdventureWorks_tstst).
2011-09-19 22:13:10.220 spid7s Ckpt dbid 14 started (8)
2011-09-19 22:13:10.230 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.230 spid7s Ckpt dbid 14 phase 1 ended (8)
2011-09-19 22:13:10.240 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.280 spid7s Ckpt dbid 14 complete
2011-09-19 22:13:10.300 spid7s No checkpoint needed on dbid 15 (AdventureWorks_testst).
2011-09-19 22:13:10.320 spid7s No checkpoint needed on dbid 16 (tstrestore).
2011-09-19 22:13:10.350 spid7s Checkpointing and truncating dbid 17 (ReportServer).
2011-09-19 22:13:10.350 spid7s Ckpt dbid 17 started (8)
2011-09-19 22:13:10.350 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.370 spid7s Ckpt dbid 17 phase 1 ended (8)
2011-09-19 22:13:10.370 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.420 spid7s Ckpt dbid 17 complete
2011-09-19 22:13:10.450 spid7s Checkpointing and truncating dbid 18 (ReportServerTempDB).
2011-09-19 22:13:10.450 spid7s Ckpt dbid 18 started (8)
2011-09-19 22:13:10.480 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.500 spid7s Ckpt dbid 18 phase 1 ended (8)
2011-09-19 22:13:10.500 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.550 spid7s Ckpt dbid 18 complete
2011-09-19 22:13:10.570 spid7s Checkpointing and truncating dbid 19 (3014_demo).
2011-09-19 22:13:10.570 spid7s Ckpt dbid 19 started (8)
2011-09-19 22:13:10.580 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.590 spid7s Ckpt dbid 19 phase 1 ended (8)
2011-09-19 22:13:10.600 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.630 spid7s Ckpt dbid 19 complete
2011-09-19 22:13:10.630 spid7s Checkpointing and truncating dbid 32767 (mssqlsystemresource).
2011-09-19 22:13:11.160 spid14s Service Broker manager has shut down.
2011-09-19 22:13:11.250 spid7s Skipping CleanShutdownDB() checkpoint on dbid 19 (3014_demo) with 0 freedOutcomes.
2011-09-19 22:13:11.640 spid7s Skipping CleanShutdownDB() checkpoint on dbid 18 (ReportServerTempDB) with 0 freedOutcomes.
2011-09-19 22:13:11.740 spid7s Skipping CleanShutdownDB() checkpoint on dbid 17 (ReportServer) with 0 freedOutcomes.
2011-09-19 22:13:11.850 spid7s Ckpt dbid 16 started (8)
2011-09-19 22:13:11.850 spid7s About to log Checkpoint begin.
2011-09-19 22:13:11.870 spid7s Ckpt dbid 16 phase 1 ended (8)
2011-09-19 22:13:11.890 spid7s About to log Checkpoint end.
2011-09-19 22:13:11.920 spid7s Ckpt dbid 16 complete
2011-09-19 22:13:12.050 spid7s Skipping CleanShutdownDB() checkpoint on dbid 15 (AdventureWorks_testst) with 0 freedOutcomes.
2011-09-19 22:13:12.180 spid7s Skipping CleanShutdownDB() checkpoint on dbid 14 (AdventureWorks_tstst) with 0 freedOutcomes.
2011-09-19 22:13:12.280 spid7s Skipping CleanShutdownDB() checkpoint on dbid 13 (AdventureWorks_11) with 0 freedOutcomes.
2011-09-19 22:13:12.390 spid7s Skipping CleanShutdownDB() checkpoint on dbid 12 (AdventureWorksLT) with 0 freedOutcomes.
2011-09-19 22:13:12.480 spid7s Ckpt dbid 11 started (8)
2011-09-19 22:13:12.480 spid7s About to log Checkpoint begin.
2011-09-19 22:13:12.510 spid7s Ckpt dbid 11 phase 1 ended (8)
2011-09-19 22:13:12.530 spid7s About to log Checkpoint end.
2011-09-19 22:13:12.560 spid7s Ckpt dbid 11 complete
2011-09-19 22:13:12.690 spid7s Skipping CleanShutdownDB() checkpoint on dbid 10 (AdventureWorks) with 0 freedOutcomes.
2011-09-19 22:13:12.860 spid7s Ckpt dbid 9 started (8)
2011-09-19 22:13:12.860 spid7s About to log Checkpoint begin.
2011-09-19 22:13:12.900 spid7s Ckpt dbid 9 phase 1 ended (8)
2011-09-19 22:13:12.920 spid7s About to log Checkpoint end.
2011-09-19 22:13:12.950 spid7s Ckpt dbid 9 complete
2011-09-19 22:13:13.180 spid7s Ckpt dbid 8 started (8)
2011-09-19 22:13:13.180 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.200 spid7s Ckpt dbid 8 phase 1 ended (8)
2011-09-19 22:13:13.220 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.270 spid7s Ckpt dbid 8 complete
2011-09-19 22:13:13.410 spid7s Ckpt dbid 6 started (8)
2011-09-19 22:13:13.410 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.460 spid7s Ckpt dbid 6 phase 1 ended (8)
2011-09-19 22:13:13.480 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.510 spid7s Ckpt dbid 6 complete
2011-09-19 22:13:13.640 spid7s Ckpt dbid 5 started (8)
2011-09-19 22:13:13.640 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.660 spid7s Ckpt dbid 5 phase 1 ended (8)
2011-09-19 22:13:13.670 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.710 spid7s Ckpt dbid 5 complete
2011-09-19 22:13:13.880 spid7s Ckpt dbid 4 started (8)
2011-09-19 22:13:13.880 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.880 spid7s Ckpt dbid 4 phase 1 ended (8)
2011-09-19 22:13:13.890 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.890 spid7s Ckpt dbid 4 complete
2011-09-19 22:13:14.000 spid7s Skipping CleanShutdownDB() checkpoint on dbid 3 (model) with 0 freedOutcomes.
2011-09-19 22:13:14.140 spid7s Ckpt dbid 1 started (8)
2011-09-19 22:13:14.140 spid7s About to log Checkpoint begin.
2011-09-19 22:13:14.140 spid7s Ckpt dbid 1 phase 1 ended (8)
2011-09-19 22:13:14.140 spid7s About to log Checkpoint end.
2011-09-19 22:13:14.140 spid7s Ckpt dbid 1 complete
2011-09-19 22:13:14.140 spid7s 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.
2011-09-19 22:13:14.180 spid7s SQL Trace was stopped due to server shutdown. Trace ID = ‘1’. This is an informational message only; no user action is required.
Sooo….SQL Server is making sure that a CHECKPOINT is issued on all the Databases as mentioned above before Shutting down the SQL Instance.( Which plays a huge and a very critical role in crash recovery when SQL Instance has been started)
Scenario 2- Creating a new User Database:
I’ve created a Database called “Checkpoint_tst”. See the Error Log contents below.
2011-09-19 22:18:58.020 spid53 Microsoft SQL Server 2008 R2 (SP1) – 10.50.2425.0 (X64)
Apr 6 2011 21:03:25
Copyright (c) Microsoft Corporation
Developer Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)
2011-09-19 22:18:58.020 spid53 (c) Microsoft Corporation.
2011-09-19 22:18:58.020 spid53 All rights reserved.
2011-09-19 22:18:58.020 spid53 Server process ID is 9120.
2011-09-19 22:18:58.020 spid53 System Manufacturer: ‘Dell Inc.’, System Model: ‘Studio 1555’.
2011-09-19 22:18:58.020 spid53 Authentication mode is MIXED.
2011-09-19 22:18:58.020 spid53 Logging SQL Server messages in file ‘C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\Log\ERRORLOG’.
2011-09-19 22:18:58.020 spid53 The error log has been reinitialized. See the previous log for older entries.
2011-09-19 22:18:58.020 spid53 DBCC TRACEON 3502, server process ID (SPID) 53. This is an informational message only; no user action is required.
2011-09-19 22:20:11.500 spid53 Ckpt dbid 3 started (8)
2011-09-19 22:20:11.500 spid53 About to log Checkpoint begin.
2011-09-19 22:20:11.510 spid53 Ckpt dbid 3 phase 1 ended (8)
2011-09-19 22:20:11.510 spid53 About to log Checkpoint end.
2011-09-19 22:20:11.520 spid53 Ckpt dbid 3 complete
2011-09-19 22:20:11.790 spid53 Starting up database ‘checkpoint_tst’.
2011-09-19 22:20:11.840 spid53 Ckpt dbid 20 started (0)
2011-09-19 22:20:11.840 spid53 About to log Checkpoint begin.
2011-09-19 22:20:11.840 spid53 Ckpt dbid 20 phase 1 ended (0)
2011-09-19 22:20:11.840 spid53 About to log Checkpoint end.
2011-09-19 22:20:11.840 spid53 Ckpt dbid 20 complete
2011-09-19 22:20:55.860 spid11s About to log Checkpoint begin.
2011-09-19 22:20:55.870 spid11s About to log Checkpoint end.
(22 row(s) affected)
dbid= 3 is MODEL Database. You can pull that info by
select name,database_id from sys.databases where database_id = 3
Hope this is informative!
MSSQLTREK 