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

Why is CHECKDB reading the transaction log file on a database with a memory optimized table?

Submitted by: @import:stackexchange-dba··
0
Viewed 0 times
whyreadingthefilelogwithoptimizeddatabasecheckdbtransaction

Problem

tl;dr: why is CHECKDB reading the transaction log for a user database with memory optimized tables?

It appears that CHECKDB is reading the transaction log file of the user database when it's checking on one of my databases - in particular, a database that uses in-memory OLTP tables.

CHECKDB for this database still finishes in a reasonable amount of time, so I'm mostly just curious about the behavior; but it's definitely the longest duration for CHECKDB of all the databases on this instance.

In looking over Paul Randal's epic "CHECKDB From Every Angle: Complete description of all CHECKDB stages," I see that pre-SQL 2005 CHECKDB used to read the log in order to get a consistent view of the database. But since this is 2016, it uses an internal database snapshot.

However, one of the prerequisites for snapshots is that:

The source database must not contain a MEMORY_OPTIMIZED_DATA filegroup

My user database has one of these filegroups, so it looks like snapshots are off the table.

According to the CHECKDB docs:

If a snapshot cannot be created, or TABLOCK is specified, DBCC CHECKDB acquires locks to obtain the required consistency. In this case, an exclusive database lock is required to perform the allocation checks, and shared table locks are required to perform the table checks.

Okay, so we're doing database and table locking instead of snapshots. But that still doesn't explain why it has to read the transaction log. So what gives?

I've provided a script below to reproduce the scenario. It uses sys.dm_io_virtual_file_stats to identify the log file reads.

Note that most of the time it reads a small portion of the log (480 KB), but it occasionally reads much more (48.2 MB). In my production scenario, it reads most of the log file (~1.3 GB of the 2 GB file) every night at midnight when we run CHECKDB.

Here's an example of the outputs I've gotten so far with the script:

```
collection_time num_of_reads num_of_bytes_read
2018-04-04 15:12:29.

Solution

Even though the SQL Server documentation states that databases with "In-Memory" tables do not support snapshots, the "internal" snapshot required for DBCC CHECKDB can still be created since the checkdb operation does not touch in-memory tables, and the snapshot only captures changes to the on-disk tables.

Presumably, Microsoft chose to prevent user-created snapshots on databases with In-Memory tables since they would need to duplicate the in-memory structures in order for the snapshot to really be a complete snapshot from the normal, user-centric, sense. Duplicating the in-memory tables for a snapshot could easily make the server run out of memory, which is not A Good Thing™

You can prove for yourself that an internal DBCC snapshot is being created by watching the data folder where the primary database datafile resides while running DBCC CHECKDB. If an internal snapshot is created, you'll see a file named LogFileRead_Test.mdf_MSSQL_DBCC7 (the 7 may be different - it represents the database id for your database).

Once the snapshot file has been created, it is necessary for SQL Server to run recovery on the database to bring it into a consistent state that is required for DBCC CHECKDB to run. Any log-reading action you're seeing is likely to be a result of that recovery process. I built a quick rig for checking the output of multiple DBCC CHECKDB actions, which proves that if there are no transactions between checkdbs, there are no log-file reads.

```
USE master;
SET IMPLICIT_TRANSACTIONS OFF;
USE [master];
IF (DB_ID(N'LogFileRead_Test') IS NOT NULL)
BEGIN
ALTER DATABASE [LogFileRead_Test]
SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
DROP DATABASE [LogFileRead_Test];
END

CREATE DATABASE [LogFileRead_Test]
ALTER DATABASE [LogFileRead_Test]
MODIFY FILE
(
NAME = LogFileRead_Test_log,
SIZE = 128MB
);

ALTER DATABASE [LogFileRead_Test]
ADD FILEGROUP [LatencyTestInMemoryFileGroup] CONTAINS MEMORY_OPTIMIZED_DATA;
ALTER DATABASE [LogFileRead_Test]
ADD FILE
(
NAME = [LatencyTestInMemoryFile],
FILENAME = 'C:\temp\LogFileRead_Test_SessionStateInMemoryFile'
) TO FILEGROUP [LatencyTestInMemoryFileGroup];
GO

USE LogFileRead_Test;

CREATE TABLE [dbo].[InMemoryStuff] (
[InMemoryId] NVARCHAR (88) COLLATE Latin1_General_100_BIN2 NOT NULL,
[Created] DATETIME2 (7) NOT NULL,
CONSTRAINT [PK_InMemoryStuff_InMemoryId]
PRIMARY KEY NONCLUSTERED
HASH ([InMemoryId]) WITH (BUCKET_COUNT = 240)
)
WITH (MEMORY_OPTIMIZED = ON);

;WITH src AS (
SELECT n.Num
FROM (VALUES (0), (1), (2), (3), (4), (5), (6), (7), (8), (9))n(Num)
)
INSERT INTO [dbo].[InMemoryStuff] (InMemoryId, Created)
SELECT 'Description' + CONVERT(varchar(30)
, ((s1.Num * 10000)
+ (s2.Num * 1000)
+ (s3.Num * 100)
+ (s4.Num * 10)
+ (s5.Num)))
, GETDATE()
FROM src s1
CROSS JOIN src s2
CROSS JOIN src s3
CROSS JOIN src s4
CROSS JOIN src s5;
USE master;

DECLARE @cmd nvarchar(max);
DECLARE @msg nvarchar(1000);
DECLARE @l int;
DECLARE @m int;
SET @m = 10;
SET @l = 1;
IF OBJECT_ID(N'tempdb..#vfs', N'U') IS NOT NULL DROP TABLE #vfs;
CREATE TABLE #vfs (
vfs_run int NOT NULL IDENTITY(1,1) PRIMARY KEY CLUSTERED
, collection_time datetime2(7)
, num_of_reads bigint
, num_of_bytes_read bigint
);

WHILE @l <= @m
BEGIN
SET @msg = N'loop ' + CONVERT(nvarchar(10), @l);
RAISERROR (@msg, 0, 1) WITH NOWAIT;

SET @cmd = 'USE [LogFileRead_Test];
-- grab a baseline of virtual file stats to be diff''d later
select f.num_of_reads, f.num_of_bytes_read
into #dm_io_virtual_file_stats
from sys.dm_io_virtual_file_stats(default, default) f
where database_id = db_id(''LogFileRead_Test'') and file_id = FILE_IDEX(''LogFileRead_Test_log'');

DBCC CHECKDB ([LogFileRead_Test]) WITH NO_INFOMSGS, ALL_ERRORMSGS, DATA_PURITY;

-- grab the latest virtual file stats, and compare with the previous capture
select f.num_of_reads, f.num_of_bytes_read
into #checkdb_stats
from sys.dm_io_virtual_file_stats(default, default) f
where database_id = db_id(''LogFileRead_Test'') and file_id = FILE_IDEX(''LogFileRead_Test_log'');

select
collection_time = GETDATE()
, num_of_reads = - f.num_of_reads + t.num_of_reads
, num_of_bytes_read = - f.num_of_bytes_read + t.num_of_bytes_read
into #dm_io_virtual_file_stats_diff
from #dm_io_virtual_file_stats f, #checkdb_stats t;

--drop table #checkdb_stats;
--drop table #dm_io_virtual_file_stats;

-- CHECKDB ignored my comment
select collection_time, num_of_reads, num_of_bytes_read
from #dm_io_virtual_file_stats_diff d
order by d.collection_time;

--drop table #dm_io_virtual_file_stats_diff;
';
INSERT INTO #vfs (collection_time, num_of_reads, num_of_bytes_read)
EXEC sys.sp_executesql @cmd;

SET @l += 1;
END

USE master;
SET @cmd = 'USE [master];
ALTER DATABASE [LogFileRead_Test]
SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
DROP DATABASE [LogFileRead_Test];
';
EXEC sys.sp_executesql @cmd;

SELECT *
FROM

Code Snippets

USE master;
SET IMPLICIT_TRANSACTIONS OFF;
USE [master];
IF (DB_ID(N'LogFileRead_Test') IS NOT NULL) 
BEGIN
    ALTER DATABASE [LogFileRead_Test]
    SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
    DROP DATABASE [LogFileRead_Test];
END

CREATE DATABASE [LogFileRead_Test]
ALTER DATABASE [LogFileRead_Test]
MODIFY FILE
(
    NAME = LogFileRead_Test_log,
    SIZE = 128MB
);

ALTER DATABASE [LogFileRead_Test]
ADD FILEGROUP [LatencyTestInMemoryFileGroup] CONTAINS MEMORY_OPTIMIZED_DATA;
ALTER DATABASE [LogFileRead_Test]
ADD FILE 
(
    NAME = [LatencyTestInMemoryFile], 
    FILENAME = 'C:\temp\LogFileRead_Test_SessionStateInMemoryFile'
) TO FILEGROUP [LatencyTestInMemoryFileGroup];
GO

USE LogFileRead_Test;

CREATE TABLE [dbo].[InMemoryStuff] (
    [InMemoryId]   NVARCHAR (88)    COLLATE Latin1_General_100_BIN2 NOT NULL,
    [Created]     DATETIME2 (7)    NOT NULL,
    CONSTRAINT [PK_InMemoryStuff_InMemoryId] 
    PRIMARY KEY NONCLUSTERED 
    HASH ([InMemoryId]) WITH (BUCKET_COUNT = 240)
)
WITH (MEMORY_OPTIMIZED = ON);

;WITH src AS (
    SELECT n.Num
    FROM (VALUES (0), (1), (2), (3), (4), (5), (6), (7), (8), (9))n(Num)
)
INSERT INTO [dbo].[InMemoryStuff] (InMemoryId, Created) 
SELECT 'Description' + CONVERT(varchar(30)
        , ((s1.Num * 10000) 
         + (s2.Num * 1000) 
         + (s3.Num * 100) 
         + (s4.Num * 10) 
         + (s5.Num)))
    , GETDATE()
FROM src s1
    CROSS JOIN src s2
    CROSS JOIN src s3
    CROSS JOIN src s4
    CROSS JOIN src s5;
USE master;

DECLARE @cmd nvarchar(max);
DECLARE @msg nvarchar(1000);
DECLARE @l int;
DECLARE @m int;
SET @m = 10;
SET @l = 1;
IF OBJECT_ID(N'tempdb..#vfs', N'U') IS NOT NULL DROP TABLE #vfs;
CREATE TABLE #vfs (
    vfs_run int NOT NULL IDENTITY(1,1) PRIMARY KEY CLUSTERED
    , collection_time datetime2(7)
    , num_of_reads bigint
    , num_of_bytes_read bigint
);

WHILE @l <= @m 
BEGIN
SET @msg = N'loop ' + CONVERT(nvarchar(10), @l);
RAISERROR (@msg, 0, 1) WITH NOWAIT;

SET @cmd = 'USE [LogFileRead_Test];
-- grab a baseline of virtual file stats to be diff''d later
select f.num_of_reads, f.num_of_bytes_read
into #dm_io_virtual_file_stats
from sys.dm_io_virtual_file_stats(default, default) f
where database_id = db_id(''LogFileRead_Test'') and file_id = FILE_IDEX(''LogFileRead_Test_log'');

DBCC CHECKDB ([LogFileRead_Test]) WITH NO_INFOMSGS, ALL_ERRORMSGS, DATA_PURITY;

-- grab the latest virtual file stats, and compare with the previous capture
select f.num_of_reads, f.num_of_bytes_read
into #checkdb_stats
from sys.dm_io_virtual_file_stats(default, default) f
where database_id = db_id(''LogFileRead_Test'') and file_id = FILE_IDEX(''LogFileRead_Test_log'');

select 
        collection_time = GETDATE() 
        , num_of_reads = - f.num_of_reads + t.num_of_reads
        , num_of_bytes_read = - f.num_of_bytes_read + t.num_of_bytes_read
into #dm_io_virtual_file_stats_diff
from #dm_io_virtual_file_stats f, #checkdb_stats t;

--drop table #checkdb_stats;
--drop table #dm_io_virtual_file_stats;

-- 
;WITH src AS (
    SELECT n.Num
    FROM (VALUES (0), (1), (2), (3), (4), (5), (6), (7), (8), (9))n(Num)
)
INSERT INTO [dbo].[InMemoryStuff] (InMemoryId, Created) 
SELECT 'Description' + CONVERT(varchar(30)
     , ((s1.Num * 10000) 
      + (s2.Num * 1000) 
      + (s3.Num * 100) 
      + (s4.Num * 10) 
      + (s5.Num)))
    , GETDATE()
FROM src s1
    CROSS JOIN src s2
    CROSS JOIN src s3
    CROSS JOIN src s4
    CROSS JOIN src s5;

Context

StackExchange Database Administrators Q#203063, answer score: 10

Revisions (0)

No revisions yet.