patternsqlModerate
Why are virtual log files not always allocated in order?
Viewed 0 times
whyorderlogarealwaysfilesallocatednotvirtual
Problem
Quarterly I check the VLF on all of my servers through CMS with a query from the tigertoolbox/Fixing-VLFs/ on github. This includes suggestions (and code) for correcting what is found. I always try to get a full understanding of what is going before making any adjustments. 90% of the time the VLF solution I apply is not the same as the recommendation, though it is usually close.
Using
says it can happen, but not why.
Because virtual log files are not always allocated in order,
This would seem to conflict with Jonathan Kehayias; An XEvent a Day (23 of 31) – How it Works – Multiple Transaction Log Files
We can see that of the 130 VLF only two (line 51 & 52) are currently used. The largest FSeqNo is 41808, subtract 130 = 41678. I don't see any FSeqNo lower then 41678 so presumably all have been used in the last 130 VLF rollovers.
IF we look at lines 108 - 109, we see line 110 is written to first, then line 109, then line 108. Also the parity is off (not sure what this adds to the scenario) The LSN show they are created in the opposite order.
I would expect that once whatever caused the disruption in sequence order has passed, the next time through the VLFs would be written to in order created. Why are they not?
Notice line 86 is in both images, to show consistency.
The example is from a SQL 2014 server, the database is currently in FUll recovery and has been for a year or more. The server has is part of 3 node AG, the results above are taken from the secondary server where the t-logs are backed up hourly. The last 10 grows occurred through auto grow of 1000MB (2014+ creates 1VLF). The log file currently has a Initial size of 115,000MB and autogrow of 1,000MB.
Edit
Max Vernon Thank you for the link in your answer. I understood h
Using
DBCC LOGINFO I find that several of the VLFs are not used in sequential order. I am trying to understand why. This highly voted answer to; DBCC SHRINKFILE on log file not reducing size even after BACKUP LOG TO DISKsays it can happen, but not why.
Because virtual log files are not always allocated in order,
This would seem to conflict with Jonathan Kehayias; An XEvent a Day (23 of 31) – How it Works – Multiple Transaction Log Files
We can see that of the 130 VLF only two (line 51 & 52) are currently used. The largest FSeqNo is 41808, subtract 130 = 41678. I don't see any FSeqNo lower then 41678 so presumably all have been used in the last 130 VLF rollovers.
IF we look at lines 108 - 109, we see line 110 is written to first, then line 109, then line 108. Also the parity is off (not sure what this adds to the scenario) The LSN show they are created in the opposite order.
I would expect that once whatever caused the disruption in sequence order has passed, the next time through the VLFs would be written to in order created. Why are they not?
Notice line 86 is in both images, to show consistency.
The example is from a SQL 2014 server, the database is currently in FUll recovery and has been for a year or more. The server has is part of 3 node AG, the results above are taken from the secondary server where the t-logs are backed up hourly. The last 10 grows occurred through auto grow of 1000MB (2014+ creates 1VLF). The log file currently has a Initial size of 115,000MB and autogrow of 1,000MB.
Edit
Max Vernon Thank you for the link in your answer. I understood h
Solution
Paul Randal details a scenario where log VLFs may be allocated out of the expected sequence in this blog post.
Essentially, log file growth may result in unexpected allocation order, even in simple mode, when the existing VLFs cannot be re-used.
Why are you wondering about the order-of-allocation? VLFs are used in
Having a database in Full Recovery model does not prevent out-of-order VLF allocation order. I've created a minimally complete verifiable example:
output:
╔════════════╦═════════════════════╗
║ name ║ recovery_model_desc ║
╠════════════╬═════════════════════╣
║ TestVLFSeq ║ FULL ║
╚════════════╩═════════════════════╝
output:
╔════════════════╦════════╦══════════╦═════════════╦════════╦════════╦════════╦═══════════╗
║ RecoveryUnitId ║ FileId ║ FileSize ║ StartOffset ║ FSeqNo ║ Status ║ Parity ║ CreateLSN ║
╠════════════════╬════════╬══════════╬═════════════╬════════╬════════╬════════╬═══════════╣
║ 0 ║ 2 ║ 253952 ║ 8192 ║ 34 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 262144 ║ 35 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 516096 ║ 36 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 278528 ║ 770048 ║ 0 ║ 0 ║ 0 ║ 0 ║
╚════════════════╩════════╩══════════╩═════════════╩════════╩════════╩════════╩═══════════╝
As you can see in the above output, we have 3 VLFs allocated.
Now, in a separate query window, run this to create log records that cannot be cleared, even by a log backup:
Now, switch back to the first query window, and backup the database and the log to clear any VLFs that cleared:
(The
Now, when we check
╔════════════════╦════════╦══════════╦═════════════╦════════╦════════╦════════╦═══════════╗
║ RecoveryUnitId ║ FileId ║ FileSize ║ StartOffset ║ FSeqNo ║ Status ║ Parity ║ CreateLSN ║
╠════════════════╬════════╬══════════╬═════════════╬════════╬════════╬════════╬═══════════╣
║ 0 ║ 2 ║ 253952 ║ 8192 ║ 34 ║ 0 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 262144 ║ 35 ║ 0 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 516096 ║ 36 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 278528 ║ 770048 ║ 0 ║ 0 ║ 0 ║ 0 ║
╚════════════════╩════════╩══════════╩═════════════╩════════╩════════╩════════╩═══════════╝
The first and second VLF have been cleared. If we now insert another 64 rows into the table, and look at
We see:
╔════════════════╦════════╦══════════╦═════════════╦════════╦════════╦════════╦═══════════════════╗
║ RecoveryUnitId ║ FileId ║ FileSize ║ StartOffset ║ FSeqNo ║ Status ║ Parity ║ CreateLSN ║
╠════════════════╬════════╬══════════╬═════════════╬════════╬════════╬════════╬═══════════════════╣
║ 0 ║ 2 ║ 253952 ║ 8192 ║ 38 ║ 2 ║ 128 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 262144 ║ 35 ║ 0 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 516096 ║ 36 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 278528 ║ 770048 ║ 37 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 1048576 ║ 39 ║ 2 ║ 64 ║ 38000000039500007 ║
║ 0 ║ 2 ║ 253952 ║ 1302528 ║ 0 ║ 0 ║ 0 ║ 38000000039500007 ║
║
Essentially, log file growth may result in unexpected allocation order, even in simple mode, when the existing VLFs cannot be re-used.
Why are you wondering about the order-of-allocation? VLFs are used in
FSeqNo order, both when writing new log records, and when performing rollback and rollforward recovery operations.Having a database in Full Recovery model does not prevent out-of-order VLF allocation order. I've created a minimally complete verifiable example:
SET NOCOUNT ON;
USE master;
GO
IF EXISTS (SELECT 1 FROM sys.databases d WHERE d.name = N'TestVLFSeq')
BEGIN
ALTER DATABASE TestVLFSeq SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
DROP DATABASE TestVLFSeq;
END
GO
CREATE DATABASE TestVLFSeq
ON (NAME = 'system', FILENAME = 'C:\temp\TestVLFSeq.mdf', SIZE = 10MB, FILEGROWTH = 10MB, MAXSIZE = 100MB)
LOG ON (NAME = 'log', FILENAME = 'C:\temp\TestVLFSeq.ldf', SIZE = 1MB, FILEGROWTH = 1MB, MAXSIZE = 10MB);
GO
ALTER DATABASE TestVLFSeq SET RECOVERY FULL;
BACKUP DATABASE TestVLFSeq TO DISK = 'NUL:';
GO
SELECT d.name
, d.recovery_model_desc
FROM sys.databases d
WHERE d.name = N'TestVLFSeq';
GOoutput:
╔════════════╦═════════════════════╗
║ name ║ recovery_model_desc ║
╠════════════╬═════════════════════╣
║ TestVLFSeq ║ FULL ║
╚════════════╩═════════════════════╝
USE TestVLFSeq;
GO
CREATE TABLE dbo.TestData
(
someVal varchar(8000) NOT NULL
CONSTRAINT DF_TestData
DEFAULT ((CRYPT_GEN_RANDOM(8000)))
);
GO
INSERT INTO dbo.TestData DEFAULT VALUES
/* insert 64 rows - ~512 KB of log usage */
GO 64
DBCC LOGINFO
GOoutput:
╔════════════════╦════════╦══════════╦═════════════╦════════╦════════╦════════╦═══════════╗
║ RecoveryUnitId ║ FileId ║ FileSize ║ StartOffset ║ FSeqNo ║ Status ║ Parity ║ CreateLSN ║
╠════════════════╬════════╬══════════╬═════════════╬════════╬════════╬════════╬═══════════╣
║ 0 ║ 2 ║ 253952 ║ 8192 ║ 34 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 262144 ║ 35 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 516096 ║ 36 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 278528 ║ 770048 ║ 0 ║ 0 ║ 0 ║ 0 ║
╚════════════════╩════════╩══════════╩═════════════╩════════╩════════╩════════╩═══════════╝
As you can see in the above output, we have 3 VLFs allocated.
Now, in a separate query window, run this to create log records that cannot be cleared, even by a log backup:
USE TestVLFSeq;
BEGIN TRANSACTION
INSERT INTO dbo.TestData DEFAULT VALUES
GONow, switch back to the first query window, and backup the database and the log to clear any VLFs that cleared:
BACKUP DATABASE TestVLFSeq TO DISK = 'NUL:' WITH INIT;
BACKUP LOG TestVLFSeq TO DISK = 'NUL:' WITH INIT;
GO(The
BACKUP DATABASE is not strictly required, but what the heck, we're backing up to "ether" anyway).Now, when we check
DBCC LOGINFO, we see:╔════════════════╦════════╦══════════╦═════════════╦════════╦════════╦════════╦═══════════╗
║ RecoveryUnitId ║ FileId ║ FileSize ║ StartOffset ║ FSeqNo ║ Status ║ Parity ║ CreateLSN ║
╠════════════════╬════════╬══════════╬═════════════╬════════╬════════╬════════╬═══════════╣
║ 0 ║ 2 ║ 253952 ║ 8192 ║ 34 ║ 0 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 262144 ║ 35 ║ 0 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 516096 ║ 36 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 278528 ║ 770048 ║ 0 ║ 0 ║ 0 ║ 0 ║
╚════════════════╩════════╩══════════╩═════════════╩════════╩════════╩════════╩═══════════╝
The first and second VLF have been cleared. If we now insert another 64 rows into the table, and look at
DBCC LOGINFO:INSERT INTO dbo.TestData DEFAULT VALUES
/* insert 64 rows - ~512 KB of log usage */
GO 64
DBCC LOGINFO
GOWe see:
╔════════════════╦════════╦══════════╦═════════════╦════════╦════════╦════════╦═══════════════════╗
║ RecoveryUnitId ║ FileId ║ FileSize ║ StartOffset ║ FSeqNo ║ Status ║ Parity ║ CreateLSN ║
╠════════════════╬════════╬══════════╬═════════════╬════════╬════════╬════════╬═══════════════════╣
║ 0 ║ 2 ║ 253952 ║ 8192 ║ 38 ║ 2 ║ 128 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 262144 ║ 35 ║ 0 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 516096 ║ 36 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 278528 ║ 770048 ║ 37 ║ 2 ║ 64 ║ 0 ║
║ 0 ║ 2 ║ 253952 ║ 1048576 ║ 39 ║ 2 ║ 64 ║ 38000000039500007 ║
║ 0 ║ 2 ║ 253952 ║ 1302528 ║ 0 ║ 0 ║ 0 ║ 38000000039500007 ║
║
Code Snippets
SET NOCOUNT ON;
USE master;
GO
IF EXISTS (SELECT 1 FROM sys.databases d WHERE d.name = N'TestVLFSeq')
BEGIN
ALTER DATABASE TestVLFSeq SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
DROP DATABASE TestVLFSeq;
END
GO
CREATE DATABASE TestVLFSeq
ON (NAME = 'system', FILENAME = 'C:\temp\TestVLFSeq.mdf', SIZE = 10MB, FILEGROWTH = 10MB, MAXSIZE = 100MB)
LOG ON (NAME = 'log', FILENAME = 'C:\temp\TestVLFSeq.ldf', SIZE = 1MB, FILEGROWTH = 1MB, MAXSIZE = 10MB);
GO
ALTER DATABASE TestVLFSeq SET RECOVERY FULL;
BACKUP DATABASE TestVLFSeq TO DISK = 'NUL:';
GO
SELECT d.name
, d.recovery_model_desc
FROM sys.databases d
WHERE d.name = N'TestVLFSeq';
GOUSE TestVLFSeq;
GO
CREATE TABLE dbo.TestData
(
someVal varchar(8000) NOT NULL
CONSTRAINT DF_TestData
DEFAULT ((CRYPT_GEN_RANDOM(8000)))
);
GO
INSERT INTO dbo.TestData DEFAULT VALUES
/* insert 64 rows - ~512 KB of log usage */
GO 64
DBCC LOGINFO
GOUSE TestVLFSeq;
BEGIN TRANSACTION
INSERT INTO dbo.TestData DEFAULT VALUES
GOBACKUP DATABASE TestVLFSeq TO DISK = 'NUL:' WITH INIT;
BACKUP LOG TestVLFSeq TO DISK = 'NUL:' WITH INIT;
GOINSERT INTO dbo.TestData DEFAULT VALUES
/* insert 64 rows - ~512 KB of log usage */
GO 64
DBCC LOGINFO
GOContext
StackExchange Database Administrators Q#199144, answer score: 11
Revisions (0)
No revisions yet.