Tuesday, May 17, 2022

Why is my transaction log growing?

I advise on the management of multiple large databases. One of them had a steadily growing transaction log.  Figuring out exactly why the log was growing was not a simple process. Here's the steps that I took to narrow down specifically which processes were causing the growth.

First, the most precise way to figure out what, specifically, is causing log growth, is through extended events. The event database_file_size_change will log all available data about the change (size, time, specifically which SQL cause the size change, etc).

If you've never used extended events before, do a little reading to learn about them first. They're insanely handy and highly recommended, but not necessarily straightforward. The below SQL will create an extended event to track the details. 

 CREATE EVENT SESSION [DB_Size_Tracking] ON SERVER   
 ADD EVENT sqlserver.database_file_size_change(  
 ACTION(sqlserver.client_app_name,  
 sqlserver.client_hostname,  
 sqlserver.database_name,  
 sqlserver.nt_username,  
 sqlserver.plan_handle,  
 sqlserver.query_hash,  
 sqlserver.query_plan_hash,  
 sqlserver.server_principal_name,  
 sqlserver.session_id,  
 sqlserver.session_nt_username,  
 sqlserver.sql_text,  
 sqlserver.username))  
 ADD TARGET package0.event_file(SET filename=N'D:\ExtendedEvents\DB_Size_Tracking.xel')  
 WITH (MAX_MEMORY=4096 KB,  
 EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,  
 MAX_DISPATCH_LATENCY=30 SECONDS,  
 MAX_EVENT_SIZE=0 KB,  
 MEMORY_PARTITION_MODE=NONE,  
 TRACK_CAUSALITY=OFF,  
 STARTUP_STATE=ON)  
 GO  

Once this extended event has been started, you can begin to see what, specifically is causing the size changes. Here's what I use to return data from the extended event session.

 If object_id('tempdb..#SizeChanges') is not null drop table tempdb..#SizeChanges  
 Select  
   -- Object_Name = n.value ('(data[@name="object_name"]/value)[1]', 'nvarchar(256)')   
   -- ,Duration = n.value ('(data[@name="duration"]/value)[1]', 'int')   
   SQLText = n.value('(action[@name="sql_text"]/value)[1]', 'nvarchar(max)')      
   ,Size_Change_KB = n.value ('(data[@name="size_change_kb"]/value)[1]', 'int')   
   ,Timestamp = convert(smalldatetime, n.value('(@timestamp)[1]', 'datetime2'))  
   ,database_name = n.value ('(data[@name="database_name"]/value)[1]', 'nvarchar(256)')   
   ,database_name_Action = n.value('(action[@name="database_name"]/value)[1]', 'nvarchar(256)')      
   ,file_name = n.value ('(data[@name="file_name"]/value)[1]', 'nvarchar(256)')   
 Into #SizeChanges  
 From (  
   Select cast(event_data as XML) as event_data  
   -- need to edit this for correct file, then UNCOMMENT  
   From sys.fn_xe_file_target_read_file('D:\ExtendedEvents\DB_Size_Tracking*.xel', null, null, null)  
   ) ed  
 Cross apply ed.event_data.nodes('event') as q(n)  
 Select * From #SizeChanges   

Once you have the temp table #SizeChanges created, you can do all kinds of queries and analysis.

In my situation, I found that a regular index maintenance job was causing the problem. Specifically, a large table with a clustered index built on a Unique Identifier field (never a good idea) was causing transaction growth, when the index was maintained. Once this was fixed, the transaction log growth was no longer a problem.