Audit Database File Size Changes

Recently I shared an article on how to track the growths and shrinks that occur within database files.  I shared that article here, you should read it before proceeding with today’s article.

Near the end of that article I declared that it was a really good method to track that information within SQL Server 2008.  What if you happen to be on SQL 2012 or SQL 2014 (as of this writing)?  Will it work there too?

Does it Work Past 2008?

It is a good question.  Does that extended event session I shared work in SQL Server 2012 or 2014?  Let’s take a quick look.  I am skipping the setup scripts for that XE session in this article, so you will need to get them from the previous article in order to follow along in this segment.

Before we can investigate if this extended event session will work, let’s take a quick look to confirm that the session is running on the server.  We can do that with a query similar to the following.

DECLARE @SessionName VARCHAR(64) = 'TrackDBFileChange'
SELECT sn.SessionName
, CASE WHEN ISNULL(es.name,'No') = 'No'
THEN 'NO'
ELSE 'YES'
End as XESessionExists
, CASE WHEN ISNULL(xe.name,'No') = 'No'
THEN 'NO'
ELSE 'YES'
End as XESessionRunning
FROM (Select @SessionName as SessionName) sn
LEFT OUTER JOIN sys.server_event_sessions es
ON sn.SessionName = es.name
LEFT OUTER JOIN sys.dm_xe_sessions xe
ON es.name = xe.name
;

Running that query will produce results very similar to the following.

This is good news.  If you noticed, I am querying a couple of views to get this information.  In the server_event_sessions catalog view I can determine if the event exists.  When checking the dm_xe_sessions DMV, I can see if the session is running or not by whether or not the session exists in the view.  When the session is enabled and running, then the DMV will return a record for it. Otherwise, the DMV does not hold a record for the session.

With a session running, we can now validate if it is running properly by running any script that will cause the files to grow or shrink.  Recall that in the previous article, it was shown that any growth or shrink operation will cause an event to fire with this session.  Here is a sample of the query I am running.

SELECT DB_NAME(database_id) AS DBName,name AS FileName,size/124.0 AS size_mb
FROM master.sys.master_files
WHERE database_id in (2,DB_ID('Sandbox2'));
USE [Sandbox2]
GO
DBCC SHRINKFILE (N'Sandbox2' , 1)
GO
USE [Sandbox2]
GO
DBCC SHRINKFILE (N'Sandbox2_log' , 1)
GO
SELECT DB_NAME(database_id) AS DBName,name AS FileName,size/124.0 AS size_mb
FROM master.sys.master_files
WHERE database_id in (2,DB_ID('Sandbox2'));
GO

That query has three distinct segments.  The first is just to check my file sizes.  The second segment performs my file shrink operations.  And the final segment checks the file sizes again.  Here is what the first and third segments would look like on the Sandbox2 database that I used in the previous article.

With the evidence that we have the session running and that there was indeed a file size change, let’s now check the event session data and confirm whether or not the session is working on this SQL 2014 server.

SELECT
    event_data.value('(event/@name)[1]', 'varchar(50)') AS event_name
,event_data.value('(event/@timestamp)[1]','varchar(max)') as timestamp
    ,event_data.value('(event/data[@name="count"]/value)[1]', 'bigint') AS TraceFlag
,event_data.value('(event/data[@name="increment"]/value)[1]', 'bigint') AS FlagType
,event_data.value('(event/action[@name="sql_text"]/value)[1]', 'varchar(max)') AS sql_text
,event_data.value('(event/action[@name="database_name"]/value)[1]', 'varchar(max)') AS DBQueryExecutedFrom
,db_name(event_data.value('(event/data[@name="database_id"]/value)[1]','int')) as DBNamethatShrunk
,event_data.value('(event/action[@name="client_hostname"]/value)[1]', 'varchar(max)') AS ClientHost
,event_data.value('(event/action[@name="session_id"]/value)[1]', 'varchar(max)') AS session_id
FROM(    SELECT evnt.query('.') AS event_data
        FROM
        (SELECT CAST(event_data AS xml) AS TargetData
            FROM sys.fn_xe_file_target_read_file('C:XEDBFileSizeChange*.xel','C:XEDBFileSizeChange*.xem',NULL, NULL)
        ) AS tab
        CROSS APPLY TargetData.nodes ('RingBufferTarget/event') AS split(evnt) 
    ) AS evts(event_data)
WHERE event_data.value('(event/@name)[1]', 'varchar(50)') = 'databases_log_file_size_changed'
or event_data.value('(event/@name)[1]', 'varchar(50)') = 'databases_data_file_size_changed'
or event_data.value('(event/@name)[1]', 'varchar(50)') = 'databases_log_growth'
ORDER BY timestamp asc;

The preceding is the query I am using to query the session data.  Running that query will produce the following results.

That’s right!  There is no session data despite the event having occurred and despite the session running currently.  We also know that this session works (we demonstrated it on SQL 2008).  So there must be a bug, something is broken.  Right?

What Now?

Since the extended event obviously no longer works, we are stuck with few options.  We could always try resorting back to the default trace.  After all, I demonstrated that the default trace is already trapping information about file shrinks.  That was discussed in the prior article and here as well.

So, what if we tried to go and capture all of the same information from the default trace?  We could certainly try that.  Assuming that the default trace is still running on the server, this query could get us pretty close.

SELECT
T.DatabaseName
,T.EventClass
,T.TextData
,T.HostName
,T.ApplicationName
,T.LoginName
,T.StartTime
,T.SPID
,T.Duration as DurationMS
,T.IntegerData as Number8KPagesChanged
,T.FileName as FileChanged
,CASE T.IsSystem
WHEN 1 THEN 'YES'
ELSE 'NO'
END AS IsSystem
/* Check IsSystem to help ensure Autoshrink didn't cause the shrink 
   MSDN indicates 1=system and 0=user
   My testing shows Null = user and 0 did not occur */FROM sys.fn_trace_gettable(CONVERT(VARCHAR(150), 
( SELECT REVERSE(SUBSTRING(REVERSE(path),
CHARINDEX('',REVERSE(path)),256)) + 'log.trc'
FROM    sys.traces
WHERE   is_default = 1)), DEFAULT) T
WHERE (T.TextData LIKE '%SHRINK%'
AND T.EventClass = 116) --Audit DBCC Event
OR T.EventClass = 92 --Data File Auto Grow
OR T.EventClass = 93 --Log File Auto Grow
OR T.EventClass = 94 --Data File Auto Shrink
OR T.EventClass = 95 --Log File Auto Shrink
ORDER BY T.StartTime,T.EventSequence
;

And this does a fairly decent job of getting the info we seek.  Sadly, though, it does not trap all of the necessary information.  Only the DBCC event (event 116) traps the sql statement that triggered the event to be recorded in the default trace.  But for the most part it can be a decent swing at getting the information.  Without the sql statements tied to the event, I’d rather not use it because it really just shows me how many times the size changed, what time the event occurred, and the size of the change.

There has got to be some other way of getting this to work in extended events.  A good question to ask is “Why does the extended event no longer work?”

A little digging, and one might eventually find a document that can shed some light on the problem.  Reading this document, we can see why the event no longer works.  It has been deprecated.  What?  After one release, they decide to take away a critical piece of information?  How can that be?

Time to back up those findings with something a little more authoritative such as this.  Looking at this article, we see that indeed the event was deprecated.  But wait a minute, the event was not just deprecated, it was also replaced with a new event.  We are in business so let’s do some querying within event sessions.

Back in Business

We could have probably spared some time by checking the available events in SQL Server by using this next query.  However, the events used in the previously used event session still exist.  If they did not exist, the session creation would have failed.  This can be a bit misleading, so it is good to have the information from Microsoft that the events have been deprecated and merged into a single event.

SELECT c.object_name as EventName,p.name as PackageName,o.description as EventDescription
FROM sys.dm_xe_objects o
INNER JOIN sys.dm_xe_object_columns c 
ON o.name = c.object_name
and o.package_guid = c.object_package_guid
INNER JOIN sys.dm_xe_packages p
on o.package_guid = p.guid
WHERE object_type='event'
AND c.name = 'channel'
AND (c.object_name like '%file_size%'
or c.object_name like '%growth%')
Order By o.package_guid;

This produces the desired results with the new event name specified in that Microsoft article.

Based on this information, a rewrite of the extended event session is possible and necessary.  We can update the extended event session that audits when a database file changes in size.  This will look something like the following session.

CREATE EVENT SESSION [TrackDBFileChange12] ON SERVER 
ADD EVENT sqlserver.database_file_size_change(
ACTION(sqlserver.session_id,sqlserver.database_name,sqlserver.client_hostname,
            sqlserver.sql_text)
)
,ADD EVENT sqlserver.databases_log_growth(
ACTION(sqlserver.session_id,sqlserver.database_name,sqlserver.client_hostname,
            sqlserver.sql_text)
)
ADD TARGET  package0.asynchronous_file_target(
     SET filename='C:XEDBFileSizeChange12.xel',max_file_size = 5,max_rollover_files = 4
         ,metadatafile='C:XEDBFileSizeChange12.xem')
,
ADD TARGET package0.ring_buffer-- Store events in the ring buffer target
(SET max_memory = 4096)
WITH (MAX_MEMORY = 4MB, EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS, TRACK_CAUSALITY = ON, MAX_DISPATCH_LATENCY = 1 SECONDS,startup_state = ON)
GO
ALTER EVENT SESSION TrackDBFileChange12
ON SERVER 
STATE = START;
GO

And since I happened to have that session also running at the same time as the shrinkfiles that were run previously in this article, I can go ahead and check to see if anything was captured.  To check the session data, I will use the following query.

SELECT
    event_data.value('(event/@name)[1]', 'varchar(50)') AS event_name
,event_data.value('(event/@timestamp)[1]','varchar(max)') as timestamp
    ,event_data.value('(event/data[@name="size_change_kb"]/value)[1]', 'bigint') AS SizeChangeKb
,event_data.value('(event/data[@name="total_size_kb"]/value)[1]', 'bigint') AS TotalSizeKb
,event_data.value('(event/data[@name="duration"]/value)[1]', 'bigint') AS Duration_ms
,event_data.value('(event/data[@name="is_automatic"]/value)[1]', 'varchar(20)') AS AutoChangeEvent
,event_data.value('(event/action[@name="sql_text"]/value)[1]', 'varchar(max)') AS sql_text
,event_data.value('(event/action[@name="database_name"]/value)[1]', 'varchar(max)') AS DBQueryExecutedFrom
,db_name(event_data.value('(event/data[@name="database_id"]/value)[1]','int')) as AffectedDB
,event_data.value('(event/data[@name="file_name"]/value)[1]','varchar(max)') as AffectedFile
,event_data.value('(event/data[@name="file_type"]/text)[1]','varchar(max)') as FileType
,event_data.value('(event/action[@name="client_hostname"]/value)[1]', 'varchar(max)') AS ClientHost
,event_data.value('(event/action[@name="session_id"]/value)[1]', 'varchar(max)') AS session_id
FROM(   SELECT CAST(event_data AS xml) AS TargetData
            FROM sys.fn_xe_file_target_read_file('C:XEDBFileSizeChange12*.xel',NULL,NULL, NULL)
        
    ) AS evts(event_data)
WHERE event_data.value('(event/@name)[1]', 'varchar(50)') = 'database_file_size_change'
or event_data.value('(event/@name)[1]', 'varchar(50)') = 'databases_log_growth'
ORDER BY AffectedDB,FileType,timestamp asc;

In this new event for 2012 and beyond, there is different data that is captured.  This means that I have access to better information about what is happening to my database files with regards to the size changes (growths and shrinks).

Conclusion

If you just so happen to be running on SQL Server 2012 or later, you will need to change your event sessions that were tracking file changes.  It is a bit of an exercise to make the change and can be frustrating, but it is well worth it.  The improved data that can be captured is going to help better control and oversee the environment.

For more help with your adventure into Extended Events, start here!