I am trying to learn more about system versioned tables in SQL Server so I am running a script to perform simple DML statements on a system versioned table and capturing different times stamps that are used for inspecting the tables between each statement.
Setup
IF EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[EXAMPLE_TABLE]') AND type in (N'U'))
ALTER TABLE [dbo].[EXAMPLE_TABLE] SET ( SYSTEM_VERSIONING = OFF )
GO
DROP TABLE IF EXISTS [dbo].[EXAMPLE_TABLE]
GO
DROP TABLE IF EXISTS [dbo].[EXAMPLE_TABLE_HISTORY]
GO
CREATE TABLE dbo.EXAMPLE_TABLE_HISTORY (
ID INT NOT NULL,
-- 'data'
ColA VARCHAR(255) NULL,
ColB VARCHAR(255) NULL,
ColC VARCHAR(255) NULL,
SysStartTime DATETIME2 NOT NULL,
SysEndTime DATETIME2 NOT NULL
);
CREATE CLUSTERED INDEX IX_EXAMPLE_TABLE_HISTORY__SysEndTime_SysStartTime
ON dbo.EXAMPLE_TABLE_HISTORY (SysEndTime ASC, SysStartTime ASC);
CREATE TABLE dbo.EXAMPLE_TABLE (
ID INT NOT NULL IDENTITY(104729, 1),
CONSTRAINT PK_EXAMPLE_TABLE
PRIMARY KEY CLUSTERED (ID),
-- 'data'
ColA VARCHAR(255) NULL,
ColB VARCHAR(255) NULL,
ColC VARCHAR(255) NULL,
-- system versioning
SysStartTime DATETIME2 GENERATED ALWAYS AS ROW START HIDDEN NOT NULL,
SysEndTime DATETIME2 GENERATED ALWAYS AS ROW END HIDDEN NOT NULL,
PERIOD FOR SYSTEM_TIME(SysStartTime, SysEndTime)
)
WITH (SYSTEM_VERSIONING = ON (HISTORY_TABLE = dbo.EXAMPLE_TABLE_HISTORY));
GO
Problem
I am running into a strange situation where the results don't appear to be correct unless I add delays into the code. For example, when running the below script I would expect the table to be empty at T0, however it returns data from the first insert.
-- perform simple dml statements
DECLARE @t0 DATETIME2 = SYSUTCDATETIME();
INSERT INTO dbo.EXAMPLE_TABLE (ColA, ColB, ColC) VALUES ('a', NULL, NULL);
DECLARE @t1 DATETIME2 = SYSUTCDATETIME();
UPDATE dbo.EXAMPLE_TABLE SET ColB = 'b' WHERE ColA = 'a';
INSERT INTO dbo.EXAMPLE_TABLE (ColA, ColB, ColC) VALUES ('d', NULL, 'f');
DECLARE @t2 DATETIME2 = SYSUTCDATETIME();
DELETE dbo.EXAMPLE_TABLE WHERE ColA = 'a';
DECLARE @t3 DATETIME2 = SYSUTCDATETIME();
-- inspect tables at specific points in time
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t0;
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t1;
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t2;
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t3;
SELECT * FROM dbo.EXAMPLE_TABLE;
'FIX?'
If I add in delays everything seems to work, but I am want to understand if the delays are needed or if they are 'working' accidentaly.
-- perform simple dml statements
DECLARE @t0 DATETIME2 = SYSUTCDATETIME();
WAITFOR DELAY '00:00:00.100';
INSERT INTO dbo.EXAMPLE_TABLE (ColA, ColB, ColC) VALUES ('a', NULL, NULL);
DECLARE @t1 DATETIME2 = SYSUTCDATETIME();
WAITFOR DELAY '00:00:00.100';
UPDATE dbo.EXAMPLE_TABLE SET ColB = 'b' WHERE ColA = 'a';
INSERT INTO dbo.EXAMPLE_TABLE (ColA, ColB, ColC) VALUES ('d', NULL, 'f');
DECLARE @t2 DATETIME2 = SYSUTCDATETIME();
WAITFOR DELAY '00:00:00.100';
DELETE dbo.EXAMPLE_TABLE WHERE ColA = 'a';
DECLARE @t3 DATETIME2 = SYSUTCDATETIME();
WAITFOR DELAY '00:00:00.100';
-- inspect tables at specific points in time
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t0;
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t1;
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t2;
SELECT * FROM dbo.EXAMPLE_TABLE FOR SYSTEM_TIME AS OF @t3;
SELECT * FROM dbo.EXAMPLE_TABLE;
At this point my best guess is SQL Server captures the time at the beginning of the DML statment and there is simply not a long enough delay at the precision of a datetime2
to distinguish between the time captured and the next statement.
Is this assumption correct? Any explanation or documentation would be helpful.
All testing was performed with SQL Server 2017.
Best Answer
You're sort of correct (although not in a good way, as it turns out). From the docs:
Normally though, unless these were explicit transactions, a
DATETIME2
variable should have more than enough precision to split the results, but that's not what we're seeing...Reproducing
This dbfiddle of 2017 matches OP's situation, but if I run locally on my 2017 instance I do not get results for
@t0
.I was unable to reproduce locally on an RTM of 2017 (Express) as well as the latest CU 17. I thus began to assume my laptop is either way too fast, or way too slow, to make this discrepancy obvious.
However, after playing around with multiple fiddles I have found the same code is returning different results, which leads me to believe there is undocumented lag or perhaps a bug in the time stamping feature for temporal tables.
Example
dbfiddle
Conclusion
It took 50+ executions of the same code to trigger all of these differing results (sorry for spamming the site, Jack) but eventually it became clear that the time stamping for temporal tables cannot be trusted on a sufficiently fast enough system. And not only that, but even when the time stamps matched up the results are still not guaranteed to be the same.
I am assuming this is most apparent on faster servers, since my laptop isn't actually all that great, and the
STATISTICS TIME
on my local tests were consistently 5-6x higher than the ones dbfiddle was returning.This is probably worth opening a bug with Microsoft about as it seems to be a pretty problematic behavior.