HiveBrain v1.2.0
Get Started
← Back to all entries
patternsqlModerate

Why are virtual log files not always allocated in order?

Submitted by: @import:stackexchange-dba··
0
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 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 DISK
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

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 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';
GO


output:

╔════════════╦═════════════════════╗
║ 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
GO


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:

USE TestVLFSeq;
BEGIN TRANSACTION
INSERT INTO dbo.TestData DEFAULT VALUES
GO


Now, 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
GO


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 ║

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';
GO
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
GO
USE TestVLFSeq;
BEGIN TRANSACTION
INSERT INTO dbo.TestData DEFAULT VALUES
GO
BACKUP DATABASE TestVLFSeq TO DISK = 'NUL:' WITH INIT;
BACKUP LOG TestVLFSeq TO DISK = 'NUL:' WITH INIT;
GO
INSERT INTO dbo.TestData DEFAULT VALUES
 /* insert 64 rows - ~512 KB of log usage */
GO 64

DBCC LOGINFO
GO

Context

StackExchange Database Administrators Q#199144, answer score: 11

Revisions (0)

No revisions yet.