Last known good DBCC CHECKDB not always correct

On the internet you can find a lot of methods to find out when DBCC CHECKDB has last run on your databases. The 2 most common queries are the based on DBCC DBINFO() and DBCC PAGE.
Below you can find 2 examples of this (replace “YourDatabase” with the correct database name):

USE YourDatabase
GO
CREATE TABLE #tmp
	(ParentObject varchar(1000) NULL,Object varchar(1000) NULL,Field varchar(1000) NULL,Value varchar(1000) NULL)
insert into #tmp
EXEC ('DBCC DBINFO() WITH TABLERESULTS')
select cast(value as datetime) from #tmp where field='dbi_dbcclastknowngood'
drop table #tmp

OR

DBCC TRACEON (3604); 
GO
DBCC PAGE (YourDatabase, 1, 9, 3);
GO

In my morning DBA checklist, I’m using the first query to check if there has been a database integrity check for the last 7 days. This query works well, however, last week I’ve noticed an issue. As soon as a database is in read-only or emergency mode, the DBCC CHECKDB command will succeed but the dbi_dbcclastknowngood field will (or can) not be updated. For that reason, my check indicates a failed status for my read-only databases…

Let’s take an example. First of all, I’m going to perform a DBCC CHECKDB for my AdventureWorks database

DBCC CHECKDB(AdventureWorks2012)

Once the check is finished, let’s verify the last dbcc check date with the DBCC DBINFO() query.

DBCC

Now, let’s set the database to read-only and do the test again.

DBCC read only

As you might notice, the last DBCC CHECKDB time is the same in both cases.

I found a good tip (old blog post) of Jonathan Kehayias to find the correct information. Just scan the SQL Error Log for the last 7 days. If I check the logs from my previous tests, you can see that there was a DBCC CHECKDB at 14:57:22 which was on my read-only database.

Error Log

I’ve modified the script of Jonathan. I’m using the xp_readerrorlog and I’m not checking the SQL 2000 version anymore… I’ve also changed my DBCC Check in my DBA checklist with the query below.

CREATE TABLE #ErrorLog
	(
	  Logdate datetime ,
	  ProcessInfo VARCHAR(12) ,
	  MsgText VARCHAR(3000)
	)
CREATE TABLE #NumberOfErrorLogFiles
	(
		ArchiveID tinyint,
		FileDate datetime,
		FileSize int
	)
insert into #NumberOfErrorLogFiles
EXEC master..xp_enumerrorlogs

DECLARE @SinceDate datetime  
SET @SinceDate = DATEADD(dd, -7, GETDATE())
DECLARE @ErrorFile tinyint
DECLARE @Severity tinyint
DECLARE @SeverityString nvarchar(3)
DECLARE @LastLogFile tinyint
select @LastLogFile=min(ArchiveID) from #NumberOfErrorLogFiles
where FileDate<@SinceDate
DECLARE @DBCCStatement nvarchar(1024)
set @DBCCStatement=N'DBCC CHECKDB (' + DB_NAME() + ')'

set @ErrorFile=0
while @ErrorFile<=ISNULL(@LastLogFile,0)
begin
    insert into #Errorlog
	EXEC master.dbo.xp_readerrorlog @ErrorFile, 1, @DBCCStatement, NULL, @SinceDate, NULL, N'ASC'
	set @ErrorFile=@ErrorFile+1
end

select * from #ErrorLog where Logdate>@SinceDate

drop table #ErrorLog
drop table #NumberOfErrorLogFiles

Have fun!

Pieter

Speaking at SQL Saturday Oslo #317

To end the holiday period in Belgium in style, I’m going on a trip to Oslo.
Not on vacation but to speak on the first edition of SQL Saturday!
Well, in some cases, this might be considered as a small vacation 😉

I’m very honored and exited that my session “How to manage many SQL Servers the easy way” has been selected.
It was really an impressive list of submitted session but my session made it!
It’s the second time that I’ll be presenting this session on a SQL Saturday.
First time was on SQL Saturday Exeter a few months ago and got really good feedback!
The purpose of this sessions is to point out which SQL Server tools you can use for multi-server management.
It is bulk loaded with demos and it will give you a good idea what features can be helpful in your environment.

I’m really looking forward to meet Cathrine Willemsen (twitter | blog) and Tone Hansson (twitter | blog), the organizers of the event, who are doing an excellent job!
A lot of other great SQL names are on the schedule. Looking forward to meet some new speakers like Tim Ford, Bob Duffy,Niko Neugebauer, Régis Baccaro, Kalen Delaney and many others.
And of course the other international speakers that I have met before like Boris Hristov, Matija Lah, André Kamman, Marco Russo, …

Hope to see you all there!

Tracking login and user changes in SQL Server

Did you ever wanted to track SQL Server logins and database user changes on all your SQL Servers? At one of my customers, the IT guys are sysadmins on the SQL Servers. In fact, the IT department is managing the SQL Servers when I’m not around. One day, “somebody” removed a user and of course, nobody did it 😉

First thing that came up to me was implementing SQL Server Audit. Good solution but not all versions of SQL Server are supporting SQL Server Audit. SQL Server 2008 and R2 are supporting SQL audit only in Enterprise Edition and there is no audit at all on SQL Server 2005. So, I had to come up with a solution that worked on these versions as well. My solution is based on this blog post of Aaron Bertrand (twitter | blog) but I’ve extended it.

Server Audit

I’ve implemented SQL Server Audit on all SQL Server 2008 and R2 Enterprise servers and SQL 2012 servers. Unfortunately no SQL 2014 yet, but you should also implement SQL Audit on this version The audit is dumping all the audit information into a audit log file on the server.

USE [master]
GO

CREATE SERVER AUDIT [Audit Login Changes]
TO FILE 
(	FILEPATH = N'ENTERYOURFILEPATHHERE'
	,MAXSIZE = 1024 MB
	,MAX_FILES = 10
	,RESERVE_DISK_SPACE = OFF
)
WITH
(	QUEUE_DELAY = 1000
	,ON_FAILURE = CONTINUE
	,AUDIT_GUID = '33e055a9-1924-47c3-9798-e8875a5bcd42'
)
ALTER SERVER AUDIT [Audit Login Changes] WITH (STATE = ON)
GO

 

I defined following Audit Action Types because I wanted to know all changes made on logins, roles and users.

Audit Action Type Description
DATABASE_ROLE_MEMBER_CHANGE_GROUP Raised whenever a login is added to or removed from a database role
SERVER_ROLE_MEMBER_CHANGE_GROUP Raised whenever a login is added or removed from a fixed server role
DATABASE_PERMISSION_CHANGE_GROUP Raised for any database permission
SERVER_OBJECT_PERMISSION_CHANGE_GROUP Raised whenever a GRANT, REVOKE, or DENY is issued for a server object permission
SERVER_PERMISSION_CHANGE_GROUP Raised when a GRANT, REVOKE, or DENY is issued for permissions in the server scope, such as creating a login
DATABASE_PRINCIPAL_CHANGE_GROUP Raised when users, are created, altered, or dropped from a database
SERVER_PRINCIPAL_CHANGE_GROUP Raised when server principals are created, altered, or dropped

More information on the Audit Action Types can be found here.

USE [master]
GO

CREATE SERVER AUDIT SPECIFICATION [Audit Login]
FOR SERVER AUDIT [Audit Login Changes]
ADD (DATABASE_ROLE_MEMBER_CHANGE_GROUP),
ADD (SERVER_ROLE_MEMBER_CHANGE_GROUP),
ADD (DATABASE_PERMISSION_CHANGE_GROUP),
ADD (SERVER_OBJECT_PERMISSION_CHANGE_GROUP),
ADD (SERVER_PERMISSION_CHANGE_GROUP),
ADD (DATABASE_PRINCIPAL_CHANGE_GROUP),
ADD (SERVER_PRINCIPAL_CHANGE_GROUP)
WITH (STATE = ON)
GO

Event Notifications

As mentioned before, we cannot use SQL Audit for SQL 2008 and R2 Standard Edition or SQL 2005. As an alternative, you can setup event notifications which will capture messages via Service Broker. The scripts below are based on the scripts of Aaron but I’ve added more events to it as I wanted to trace more than just “change password”

Create the following table in the msdb database

USE [msdb];
GO

CREATE TABLE dbo.SecurityChangeLog
(
    ChangeLogID			 int IDENTITY(1,1),
	LoginName            SYSNAME,
    UserName             SYSNAME,
    DatabaseName         SYSNAME,
    SchemaName           SYSNAME,
    ObjectName           SYSNAME,
    ObjectType           VARCHAR(50),
    DDLCommand           VARCHAR(MAX),
	EventTime			 DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP,
	CONSTRAINT PK_ChangeLogID PRIMARY KEY (ChangeLogID)
);

 

Setup the queue

CREATE QUEUE SecurityChangeQueue;
GO

CREATE SERVICE SecurityChangeService ON QUEUE SecurityChangeQueue
  ([http://schemas.microsoft.com/SQL/Notifications/PostEventNotification]);
GO

 

Setup the event notificiation. If you check the “FOR”-clause, you will notice that these are the same actions as defined in the SQL Audit Specification.

CREATE EVENT NOTIFICATION CreateLoginNotification
    ON SERVER WITH FAN_IN
    FOR CREATE_LOGIN,ALTER_LOGIN,DROP_LOGIN,CREATE_USER,ALTER_USER,DROP_USER,ADD_SERVER_ROLE_MEMBER,DROP_SERVER_ROLE_MEMBER,ADD_ROLE_MEMBER,DROP_ROLE_MEMBER
    TO SERVICE 'SecurityChangeService', 'current database';
GO

 

Install the following stored procedure to log all the event notifications into the table we’ve just created. You might notice in the loop that I’m checking the version of SQL Server for some events. This is because the event notification content is different for SQL 2008 (R2) and SQL 2005.

USE [msdb];
GO
CREATE PROCEDURE [dbo].[LogSecurityChange]
WITH EXECUTE AS OWNER
AS
BEGIN
    SET NOCOUNT ON;
	DECLARE @version int
    DECLARE @message_body XML;
	set @version = (SELECT convert (int,REPLACE (LEFT (CONVERT (varchar, SERVERPROPERTY ('ProductVersion')),2), '.', '')))

    WHILE (1 = 1)
    BEGIN
       WAITFOR 
       ( 
         RECEIVE TOP(1) @message_body = message_body
         FROM dbo.SecurityChangeQueue
       ), TIMEOUT 1000;

       IF (@@ROWCOUNT = 1)
       BEGIN
		if CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/EventType)')) in ('DROP_USER','CREATE_USER','ALTER_USER') or @version>9
		BEGIN
			INSERT dbo.SecurityChangeLog(LoginName,UserName,DatabaseName,SchemaName,ObjectName,ObjectType,DDLCommand) 
			SELECT CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/LoginName)')), 
				CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/UserName)')),
				CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/DatabaseName)')),
				CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/DefaultSchema)')),
			    CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/ObjectName)')),
		        CONVERT(VARCHAR(50), @message_body.query('data(/EVENT_INSTANCE/ObjectType)')),
		        CONVERT(VARCHAR(MAX), @message_body.query('data(/EVENT_INSTANCE/TSQLCommand/CommandText)'))
		END
		ELSE
		BEGIN
			INSERT dbo.SecurityChangeLog(LoginName,UserName,DatabaseName,SchemaName,ObjectName,ObjectType,DDLCommand) 
			SELECT CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/LoginName)')), 
				CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/UserName)')),
				CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/DatabaseName)')),
				CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/SchemaName)')),
			    CONVERT(SYSNAME, @message_body.query('data(/EVENT_INSTANCE/ObjectName)')),
		        CONVERT(VARCHAR(50), @message_body.query('data(/EVENT_INSTANCE/ObjectType)')),
		        CONVERT(VARCHAR(MAX), @message_body.query('data(/EVENT_INSTANCE/EventType)')) + ' ' + 
				CONVERT(VARCHAR(MAX), @message_body.query('data(/EVENT_INSTANCE/RoleName)')) + ' FOR ' +
				CONVERT(VARCHAR(MAX), @message_body.query('data(/EVENT_INSTANCE/LoginType)')) + ' ' +
				CONVERT(VARCHAR(MAX), @message_body.query('data(/EVENT_INSTANCE/ObjectName)'))
		END
       END
    END
END

 

Last step is modifying the queue so that it will use the stored procedure and starts tracking the login and user changes.

ALTER QUEUE SecurityChangeQueue
WITH ACTIVATION
(
   STATUS = ON,
   PROCEDURE_NAME = dbo.LogSecurityChange,
   MAX_QUEUE_READERS = 1,
   EXECUTE AS OWNER
);
GO

Bring it all together

All the information is now logged on each individual server. I want all the audit log information in one central database so that the customer can run reports on it. First of all, I’ve created a database on one of the SQL Servers and created a table that will store all the audit logs of all the servers.

CREATE TABLE [dbo].[SecurityChangeLog](
	[ChangeLogID] [int] IDENTITY(1,1) NOT NULL,
	[ServerName] [sysname] NOT NULL,
	[LoginName] [sysname] NOT NULL,
	[DatabaseName] [sysname] NOT NULL,
	[ObjectName] [nvarchar](128) NULL,
	[ObjectType] [varchar](50) NULL,
	[DDLCommand] [nvarchar](max) NULL,
	[EventTime] [datetime2](7) NULL,
 CONSTRAINT [PK_ChangeLogID] PRIMARY KEY CLUSTERED 
(
	[ChangeLogID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]

 

Next step is retrieving all the log information from each server. I was thinking of using an SSIS package for this but it looked more easily to use Powershell instead. The script below is based on the central management server that I’m using. First I’m retrieving all the SQL Servers where I have to collect the audit data. This is stored in the table msdb.dbo.sysmanagement_shared_registered_servers_internal of the central management server. Make sure that you change YOURGROUPID with the appropriate groupid of your CMS and YOURCMS with the instance name of your CMS.

Once we have the list, I execute a script GetAuditLog.sql against each instance to retrieve the audit information.

The final step will write the retrieved audit information into the database. Make sure you change the YOURDATABASENAME and YOURSQLSERVERINSTANCE in the script to your database name and SQL instance.

Schedule a SQL Agent Job to execute the powershell script on a daily basis.

 

#Set-ExecutionPolicy -ExecutionPolicy Unrestricted
Import-Module “sqlps” -DisableNameChecking
cls
$InputFile = "YOURFILEPATH + GetAuditLog.sql"

#Get the list of servers from the Central Management Server
$InstanceNameList = Invoke-Sqlcmd -Query "select server_name from msdb.dbo.sysmanagement_shared_registered_servers_internal 
                                          where server_group_id=YOURGROUPID" -ServerInstance "YOURCMS"
                                         
Clear-variable -Name results
Clear-variable -Name record

#Get Audit information
foreach($instanceName in $instanceNameList) 
{ 
    write-host "Executing query against server: " $instanceName.server_name
    $results += Invoke-Sqlcmd -InputFile $InputFile -ServerInstance $instanceName.server_name
}
#Save the Audit Log into the database
foreach($record in $results)
{
#write-host "ServerName: " $record.ServerName " " $record.DDLCommand
Invoke-Sqlcmd -Query "insert into [YOURDATABASENAME].[dbo].[SecurityChangeLog] ([ServerName],[LoginName],[DatabaseName],[ObjectName],[ObjectType],[DDLCommand],[EventTime])  
                      Values('$($record.ServerName)','$($record.LoginName)','$($record.DatabaseName)','$($record.ObjectName)','$($record.ObjectType)','$($record.DDLCommand)','$($record.EventTime)')" -ServerInstance "YOURSQLSERVERINSTANCE" 
}

 

Below you can find the SQL script that is used to retrieve the audit information in the powershell script. Dependent on the version we will read the audit file or the event notification table. I’m only selecting the logs of the last day because the powershell is scheduled to run on a daily basis.

USE MSDB
GO
declare @AuditLog  table (
LoginName sysname,
DatabaseName sysname,
ObjectName nvarchar(128),
ObjectType varchar(50),
DDLCommand nvarchar(4000),
EventTime datetime)
declare @LogFilePath varchar(256)
declare @version int
set @version = (SELECT convert (int,REPLACE (LEFT (CONVERT (varchar, SERVERPROPERTY ('ProductVersion')),2), '.', '')))
IF (@version=10 and (select convert(varchar,SERVERPROPERTY('Edition'))) not like '%Standard%') OR (@version=11)
BEGIN
	select @LogFilePath=log_file_path from sys.server_file_audits
	where name='Audit Login Changes'
	IF @LogFilePath IS NOT NULL
	BEGIN
		set @LogFilePath=@LogFilePath +'*.sqlaudit'
		insert into @AuditLog
		SELECT session_server_principal_name,database_name,object_name,m.class_type_desc,statement,event_time FROM sys.fn_get_audit_file (@LogFilePath,default,default) f
		INNER JOIN sys.dm_audit_class_type_map m on m.class_type=f.class_type;
		select serverproperty('Servername') as ServerName,LoginName,DatabaseName,ObjectName,ObjectType,replace(DDLCommand,'''','''''') as DDLCommand,EventTime from @AuditLog
		where EventTime>dateadd(dd,-1,getdate())
	END
END
ELSE
BEGIN
	IF exists (select name from msdb.sys.tables where name='SecurityChangeLog')
		select serverproperty('Servername') as ServerName,LoginName,DatabaseName,ObjectName,ObjectType,replace(DDLCommand,'''','''''') as DDLCommand,EventTime from msdb.dbo.SecurityChangeLog
	    where EventTime>dateadd(dd,-1,getdate()) and DDLCommand<>''
END

Report

To make it easy for the customer to retrieve the data, I’ve created this report.

Security ChangesI know that this solution is not really secure because people can just stop the audit, disable the queue or delete the records from the tables but I think this is a good start to track the login and user modifications.

Have fun!