It is finally time to revisit a blog posting I started on Dec 21st, 2016.
That post is titled “SQL Server – Error – Cannot shrink log file because the logical file located at the end of the file is in use“.
And, it is here.
Received an alarm that our database files are growing and so sought to find out why.
Transaction Log – Utilization Metrics from Performance Counter
if schema_id('transactionLog') is null
exec('create schema [transactionLog] authorization [dbo]')
if object_id('[transactionLog].[IUDF_UtilizationMetricsFromPerformanceCounters]') is null
'create function [transactionLog].[IUDF_UtilizationMetricsFromPerformanceCounters]
[shell] = 1/0
alter function [transactionLog].[IUDF_UtilizationMetricsFromPerformanceCounters]
, cntr_value log_size_kb
FROM sys.dm_os_performance_counters tblDMOPC
WHERE tblDMOPC.object_name = 'SQLServer:Databases'
AND tblDMOPC.counter_name like 'Log File' + '%'
AND tblDMOPC.instance_name <> '_Total'
for [counter] in
[Log File(s) Used Size (KB)]
, [Log File(s) Size (KB)]
) as avgSize
, [usedMB] = [Log File(s) Used Size (KB)]
, [totalMB] = [Log File(s) Size (KB)]
( [Log File(s) Used Size (KB)] * 100.00)
/ ( [Log File(s) Size (KB)])
as decimal(10,2 )
, [log reuse wait]
from ctePivot cteP
inner join sys.databases tblSD
on cteP.[dbid] = tblSD.database_id
- Before capturing the screenshot above, our target database, QA_rbpivr1, was in FULL RECOVERY
- It’s transaction log size was 8 GB
- And, 3.2 GB of the 8GB is in use
Why so much Transaction Log is being held up?
Again for QA_rbpiv1 3.2 GB is being used.
Let us review how database is configured
We see that the Recovery Mode for our database is Full.
- The last full backup was taken last night Feb 2nd, 2017 and it completed at 8:35 PM
- And, the last Transaction backup was taken on Sunday Feb 5th, 2017 at 6 PM
Transaction Backup History
Let us review our Transaction Backup History
- Before today, transaction backups were occurred on 2/5/2017, 1/29/2017, 1/22/2017
- And, they were occurring each hour
- Looked back at the Calendar and those days fell on Sundays
Review Scheduled Transaction Backup
- Schedule is Weekly on Sundays
- And, the frequency is each hour
- Changed Schedule’s frequency from Weekly to Daily
Review Checkpoints in Error Log File
Enable Logging of Checkpoints in ErrorLog file
Enable Trace Flags
dbcc traceon (3502, 3504, 3605, -1 )
Review ErrorLog file
Let us review our error logs and make sure that Checkpoints are indeed been logged.
if object_id('transactionLog.sp_checkPointsInErrorLogFileAggregate') is null
exec('create procedure [transactionLog].[sp_checkPointsInErrorLogFileAggregate] as ')
alter procedure [transactionLog].[sp_checkPointsInErrorLogFileAggregate]
set nocount on;
declare @p1 INT
declare @p2 INT
declare @p3 VARCHAR(255)
declare @p4 VARCHAR(255)
declare @tblErrorLog TABLE
[id] int not null
, [LogDate] datetime
, [ProcessInfo] sysname
, [Text] varchar(600) null
, primary key
, INDEX INDX_ID
set @p1 = 0 -- current
set @p2 = 1 -- error log
set @p3 = 'Ckpt'
set @p3 = 'Ckpt dbid'
set @p4 = ''
insert into @tblErrorLog
@p1 = @p1
, @p2 = @p2
, @p3 = @p3
, @p4 = @p4
from sys.databases tblSD
left outer join @tblErrorLog tblEL
on tblEL.[Text] like '%' + cast(tblSD.database_id as varchar(10)) + '%'
and tblEL.[Text] like 'Ckpt dbid ' + '%' + 'started'
, count(tblEL.LogDate) desc
- From digging in the Transaction Log File, we can see that the last Transaction Log on 2017-02-06 20:34
- The timeline is Yesterday, Monday Feb 6th, 2017 8:34 PM
- LogDateMin is 2017-01-15 04:00
- In readable term Jan 15th, 2017 @ 4 AM
In summary, our transaction size is growing and not being pruned because unfortunately our scheduled Transaction backup job was incorrectly set to only occur on Sundays.
Please keep in mind this only affects databases set for FULL RECOVERY.
From the metrics above, we can see that our identified database Transaction Log Checkpoints are only occurring at the tail end of Full Backups.
And, as aforementioned on Sundays.