Monday, February 10, 2014

High Virtual Log Files (VLF) Count

Virtual log files are basically segments of the database log file. Every time the transaction log grow in size, the number of virtual log files would also grow. If you have a database with transaction log that keep growing in small increment each time, you can end up with a lot of virtual log files, and that can be a bad thing.

In SQL Server 2012, if you have a database with more than 10,000 virtual log file, you will get a warning message on the SQL Server logs. To demonstrate this:

First I would create a database called VLFTest. I set the log file for the database to have an initial size of 512 KB (for this size 2 VLF will be created).

USE [master];

IF DB_ID('VLFTest') IS NOT NULL
BEGIN
DROP DATABASE VLFTest;
END;
GO

CREATE DATABASE VLFTest
ON (
NAME = 'VLFTest_Data',
FILENAME = 'C:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\VLFTest_Data.mdf')
LOG ON (
NAME = 'VLFTest_Log',
FILENAME = 'C:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\VLFTest_Log.ldf',
SIZE = 512 KB,
MAXSIZE = 10240 MB,
FILEGROWTH = 512 KB);
GO

Once the database is created, I can check the number of VLF created by running the following query:

DBCC LOGINFO ('VLFTest');

The query should return 2 rows, which would indicate that there are two VLFs created.

The next thing I would do is to grow the transaction log size by 512 KB increment for 5,000 times. Since each time we increment the transaction log by 512 KB, 2 new VLFs would be created. Thus, doing it for 5,000 times would cause it to generate 10,000 new VLFs. So at the end I would end up with 10,002 VLFs. I can do this by using the following script:

DECLARE @CurrentSize AS INT,
@LogFileQuery AS NVARCHAR(1000);

--- Get current log file size.
PRINT 'Current log file size is ' + CAST(@CurrentSize AS VARCHAR(1000)) + ' KB';
SELECT @CurrentSize = size*8 FROM sys.master_files WHERE database_id = DB_ID('VLFTest') AND name = 'VLFTest_Log'

--- Try to grow the transaction log by 512 KB. This should result in two additional VLF.
PRINT 'Growing the transaction log to ' + CAST((@CurrentSize + 1) AS VARCHAR(1000)) + ' KB';
SET @LogFileQuery = 'ALTER DATABASE VLFTest MODIFY FILE (NAME = VLFTest_Log, SIZE = ' + CAST((@CurrentSize + 512) AS VARCHAR(1000)) + ' KB);';
EXEC (@LogFileQuery);
GO 5000

Now if I run the following query:

DBCC LOGINFO('VLFTest');

I would get back 10,002 rows back, which means that I have 10,002 VLFs on VLFTest database’s transaction log.

Now, the warning in SQL Server log unfortunately will not be trigger when the VLF count goes beyond 10,000. I found out that it will be trigger under the following conditions:

  • When the SQL Server is restarted
  • When the VLF database is set online (after it is set offline)
  • When we restore the database

So for a quick test, I try to set the database offline and then back online by using the following query:

USE master;
GO
ALTER DATABASE VLFTest SET OFFLINE;
GO
ALTER DATABASE VLFTest SET ONLINE;
GO

After VLFTest database is back online, when I go to SQL Server log, I would get the following message:

image

Database VLFTest has more than 1000 virtual log files which is excessive. Too many virtual log files can cause long startup and backup times. Consider shrinking the log and using a different growth increment to reduce the number of virtual log files.

Why Having Too Much of VLFs Count Can Be Bad Thing?

Having an excessive VLFs count can be a bad thing to your database. For one, when I tried to make the database back online after turning it offline, it took longer than expected. When I run the following query:

USE master;
ALTER DATABASE VLFTest SET OFFLINE;
GO
SET STATISTICS TIME ON;
ALTER DATABASE VLFTest SET ONLINE;
GO

After running it 5 times, on average it took about 23 seconds for the database to be online. Now compare this with the following:

USE master;
GO
IF DB_ID('VLFTest2') IS NOT NULL
BEGIN
DROP DATABASE VLFTest2;
END;
GO

CREATE DATABASE VLFTest2
ON (
NAME = 'VLFTest2_Data',
FILENAME = 'C:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\VLFTest2_Data.mdf')
LOG ON (
NAME = 'VLFTest2_Log',
FILENAME = 'C:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\VLFTest2_Log.ldf',
SIZE = 2560512 KB,
MAXSIZE = 10240 MB,
FILEGROWTH = 1024 KB);
GO

It is basically the same database, but instead of growing the transaction log file from 512 KB to 2,560,512 KB by 512 KB increment (and in the process created 10,002 VLFs), I immediately create the transaction log with size 2,560,512 KB. By doing this, I only have 16 VLFs. Now when I try to run the following query:

USE master;
ALTER DATABASE VLFTest2 SET OFFLINE;
GO
SET STATISTICS TIME ON;
ALTER DATABASE VLFTest2 SET ONLINE;
GO

After running it 5 times, on average it took about 0.2 seconds to bring VLFTest2 database online. That’s quite a huge difference, 23 seconds vs. 0.2 seconds (about 2,200% difference).

I also noticed big difference in the time that it took to restore VLFTest1 database (with 10,002 VLFs) compared to the VLFTest2 database (with 16 VLFs). It took about 1 minutes and 35 seconds to restore VLFTest1 database, but it only took about 6 seconds to restore VLFTest2.

In addition to the above, having an excessive number of VLFs in your database can also have an impact on the database transaction. A while ago, Linchi Shea wrote a blog post regarding this. It can be found here.

Take Away

Having a high count of VLFs can hurt your database. To avoid it, we need to carefully plan our database size, especially in this case, the transaction log size. We also need to make sure that the transaction file growth size is not too small. This is to ensure that we don’t end up with many auto growth on the transaction log file, which cause the VLFs to grow.

Further Reading

You might also want to read Kimberly Tripp’s blog post regarding VLF. It can be found here.

3 comments:

  1. Nice post, never knew that high vlf could slow down a restart!

    ReplyDelete
  2. Once you write or download a log monitoring script or tool like the one above, you can have Nagios or CRON run it on a regular basis which will in turn enable you to keep a bird's eye view on all the logged activities of your important servers.seo log analyzer

    ReplyDelete