Freigeben über

Lazy Log Truncation – Clearing of SQL transaction log VLF status deferred

  • Artikel

I came across an oddity in the transaction log when I was testing Availability Group backup scenarios which really had me confused.  It required some help from my colleague Denzil and a few others to figure out what was going on.  This adventure taught us about Lazy Log Truncation.  This is not new to SQL 2012 as it also exists in SQL 2008R2 (and possibly prior), but only when a database is being mirrored or participating in an Availability Group.

For more on VLF’s and transaction log architecture: Transaction Log Physical Architecture

Before getting into the oddity that Lazy Log Truncation brings into play, let’s first look at what you normally see in the transaction log as it is filled and truncated.

I started off creating a database with a fixed log file size of 100MB in full recovery model.  I have this all in the attached script for you to try on your own as well. Once that is set up, take a full database backup to get full recovery model going.  Then run DBCC LOGINFO to show you the current VLFs in the database.

 

USE [LLTTest]

GO

DBCC LOGINFO --you see here that there are 8 VLFs with 1 that has a status of 2

GO

clip_image002

The status value of 2 means that it is the active portion of the log, meaning that it contains data that needs to be backed up in order for that VLF to be able to be used again.

Next we will do some work in the database that will generate a little log activity.

CREATE TABLE test1 ( myvarchar varchar(5000))

GO

INSERT INTO test1 VALUES( replicate('*',5000))

GO 5000

DELETE FROM test1

Now take a look at DBCC LOFINGO again and you can see that more of the VLFs contain active transaction log data.

clip_image004

Next, we take a backup of the transaction log in order to clear out all the full VLFs and run DBCC LOGINFO again. Note that FSeqNo 35 is still marked as active.  This is because only full VLFs that do not contain log records for active transactions or records needed for replication (mirroring, CDC, replication, etc) are truncated. Also note that there must always be at least 1 active VLF.

BACKUP LOG [LLTTest] TO DISK = N'C:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\Backup\LLTTest.bak' WITH NOFORMAT, NOINIT, NAME = N'LLTTest-Transaction Log Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10

GO

DBCC LOGINFO --after the tlog backup all but one of the VLFs are inactive (status 0)

GO

 

clip_image006

 

This is exactly what you would expect to see, no surprises here.    When it becomes interesting is when you do this same test against a database participating in an Availability Group.  For the sake of keeping this blog entry from being too long, I am not showing you how to add this db to an availability group, but you can do so on your own using the GUI tools.

After adding this database to an availability group, there was no change to the output of DBCC LOGINFO, but one interesting thing to note is that the DBCC LOGINFO output will be identical across all the replicas when everything is synchronized.

Now, we are doing to do the same work we did before to put some activity in the transaction log.

INSERT INTO test1 VALUES( replicate('*',5000))

GO 5000

GO

DELETE FROM test1

GO

DBCC LOGINFO --Nothing special here, you can see more active VLFs

GO

This looks similar to what we saw before, it is just that different VLFs are being used and the activity rolled over to the beginning of the log file since I have the file set to a fixed size (to make this easier to demo).

clip_image008

Now we will backup the transaction log to truncate the VLFs, right? 

BACKUP LOG [LLTTest] TO DISK = N'C:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\Backup\LLTTest.bak' WITH NOFORMAT, NOINIT, NAME = N'LLTTest-Transaction Log Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10

GO

DBCC LOGINFO

GO

ACK! The status didn't clear to 0 on any of the VLFs?! The DBCC LOGINFO output did not change at all. The replica is fully synchronized, so we know it is not due to data not being at all the replicas. The transaction log backup file does contain data, so are those VLFs cleared out or not?

clip_image010

 

If we do work again, what will happen? We think the transaction log was just backed up so there should be plenty of free space right? Running DBCC SQLPERF ('LOGSPACE') confirms that. So what will happen? Will the transaction log fill and return an error? This seems very confusing. Well let's give it a shot!

INSERT INTO test1 VALUES( replicate('*',5000))

GO 5000

DELETE FROM test1

--Spoiler Alert: IT WORKS!!

GO

DBCC LOGINFO

GO

 

You can see that FSeqNo 32-35 have been replaced with 40-43.  Even though the VLFs were still considered active, they were able to be reused since they were part of the previous transaction log backup.

clip_image012

We noticed that in a mirroring or Availability Group scenario, Lazy Log Truncation marks the VLFs for truncation, but it does not actually truncate the log unless those VLFs are necessary.  Why is this done?  Well, the primary log truncation has to retain log which may be in use at any of the secondaries. When adding a replica, this aids in minimizing the number of transaction log backups that must be restored in order to get the replica transaction log at the same point as the primary. 

Is this something that you need to be aware of?  Not really, but we thought it was an interesting tidbit about how Availability Groups and mirroring have had so much thought put into them.  We also didn’t want you to be concerned if you happened to notice that a lot of your VLFs are marked as active when you think they have been backed up and should be truncated.

Lisa Gardner – Premier Field Engineer

Comments

  • Anonymous
    July 03, 2013
    Lisa, We are just starting to use Availablility Groups so should we make our transaction logs bigger than they were on say SQL2005/SQL2008R2? We also have percent log used alerts to fire off log backups. Will these be affected by the lazy log truncation? We have these set at 65%. Should we change this down or up? Thanks Chris

  • Anonymous
    July 03, 2013
    Even though VLFs are not set as cleared, they are still able to be archived and will be in subsequent tlog backups.  The space will show as empty when you look at % used (via DBCC SQLPERF for example). The point to keep in mind is that any log fragments that have not yet been hardened on replicas cannot be cleared/overwritten.  Therefore, if you have a very long duration of time where a replica is disconnected from the primary, the used tlog space may grow.  So, lazy log truncation does not affect the percent used, but other factors may.  If you are familiar with mirroring, replication, or CDC, the same scenario is in play because there are now multiple points of truncation in the log..

  • Anonymous
    December 26, 2013
    Brilliant blog post and the answer to the question (Question was also well composed, with thoughts in it). Appreciate it.

  • Anonymous
    August 17, 2014
    Great post Lisa, I ran into this scenario this morning when testing some new availability groups and could not figure out why I was still seeing active vlfs using dbcc loginfo, your post has helped me understand.  

  • Anonymous
    September 14, 2014
    We've run into an issue where we need to shrink a tx log.  We've run a full backup and a transaction log backup.  DBCc SQLPERF now indicates that only 0.16% of the log is used.  Sys.databases log_reuse_wait_desc = nothing.  But all VLFs have a status of 2.   Is Lazy Truncation likely the issue here?  Any ideas how we can shrink the log?

  • Anonymous
    July 27, 2015
    Hello, I know this is an old thread but I thought I'd ask similar question about VLF's. I'm a "DBA" not by choice for a medium sized company ~40 SQL instances. We typically run our DB's in Simple recovery if anything for reduced maintenance. Anyway I have a SQL 2012 database that supports a help desk app (Trackit) that is in Simple mode. I typically set log autogrowth from default % to a set Megabyte value (256Meg in this case). After a few months of use the logfile has fragmented into 605 VLF's and counting and 13Gig. No big deal right? The weird things is the status on ALL but one of the 605 VLF's is = 2. So this log has one unused VLF and is 99% full. The data file is still at the 256Meg I set it to at the beginning.  I'm guessing all relevant data is stuck in the log file. Any ideas for how to fix this situation if indeed it is a problem. Thanks for any insight Ron

  • Anonymous
    July 27, 2015
    Just realized I hadn't logged on so I wouldn't get any notifications about the post I just placed.. doh!