Why would a SELECT query cause writes?How can row estimates be improved in order to reduce chances of spills...
Misplaced noalign when centering tabularx cell
Portent, as it relates to the Gambling downtime rules from Xanathar's Guide to Everything
Have any astronauts or cosmonauts died in space?
What is the source for this Leonardo Da Vinci quote?
Is my plan for an air admittance valve ok?
Why is quixotic not Quixotic (a proper adjective)?
How to not forget my phone in the bathroom?
Buying a "Used" Router
Manager has noticed coworker's excessive breaks. Should I warn him?
How can I add more depth to my poem?
How would "The dog is older than the child" be translated?
Why would you use 2 alternate layout buttons instead of 1, when only one can be selected at once
Can I reorder the coordinates of a line when importing into QGIS a WKT linestring?
Getting size of dynamic C-style array vs. use of delete[]. Contradiction?
How to play songs that contain one guitar when we have two or more guitarists?
What dissuades people from lying about where they live in order to reduce state income taxes?
Is Apex Sometimes Case Sensitive?
Is it ethical to apply for a job on someone's behalf?
Why does finding small effects in large studies indicate publication bias?
A semicolon (';') is not needed after a function declaration. C++
How do sapient birds/theropods build their seats?
Found a major flaw in paper from home university – to which I would like to return
Microphone on Mars
Can you wish for more wishes from an Efreeti bound to service via an Efreeti Bottle?
Why would a SELECT query cause writes?
How can row estimates be improved in order to reduce chances of spills to tempdbHow to troubleshoot how resource governed query is being throttled in SQL 2012?Why are transactions running as distributed (DTCXact)?Running query against DMVs for Query Stats and Execution Plans joined to sys.databasesSQL Server tempdb high IOQuery memory grant and tempdb spillTracking Down Plan Cache ClearingNever ending Query Store searchUnexplainable write latency tempdbAvailability Group cluster memory issue after network issues. How to dump HADR Log Block Msg Pool?
I've noticed that on a server running SQL Server 2016 SP1 CU6 sometimes an Extended Events session shows a SELECT query causing writes.
For example:
The execution plan shows no obvious cause for the writes, such as a hash table, spool, or sort that could spill to TempDB:
Variable assignment to a MAX type or an automatic statistics update could also cause this, but neither was the cause of the writes in this case.
What else could the writes be from?
sql-server sql-server-2016
add a comment |
I've noticed that on a server running SQL Server 2016 SP1 CU6 sometimes an Extended Events session shows a SELECT query causing writes.
For example:
The execution plan shows no obvious cause for the writes, such as a hash table, spool, or sort that could spill to TempDB:
Variable assignment to a MAX type or an automatic statistics update could also cause this, but neither was the cause of the writes in this case.
What else could the writes be from?
sql-server sql-server-2016
1
I suspect this is also possible without Extended Events or trace being involved, and that is when the query (or the variable assignment) can involve tempdb (e.g. via worktable/workfile). Hard to prove without EE/trace though! :-)
– Aaron Bertrand♦
Nov 27 '17 at 19:51
6
assigning to a max variable can certainly cause writes stackoverflow.com/a/7613012/73226
– Martin Smith
Nov 27 '17 at 20:41
add a comment |
I've noticed that on a server running SQL Server 2016 SP1 CU6 sometimes an Extended Events session shows a SELECT query causing writes.
For example:
The execution plan shows no obvious cause for the writes, such as a hash table, spool, or sort that could spill to TempDB:
Variable assignment to a MAX type or an automatic statistics update could also cause this, but neither was the cause of the writes in this case.
What else could the writes be from?
sql-server sql-server-2016
I've noticed that on a server running SQL Server 2016 SP1 CU6 sometimes an Extended Events session shows a SELECT query causing writes.
For example:
The execution plan shows no obvious cause for the writes, such as a hash table, spool, or sort that could spill to TempDB:
Variable assignment to a MAX type or an automatic statistics update could also cause this, but neither was the cause of the writes in this case.
What else could the writes be from?
sql-server sql-server-2016
sql-server sql-server-2016
edited Nov 27 '17 at 22:14
James L
asked Nov 27 '17 at 18:31
James LJames L
2,46542040
2,46542040
1
I suspect this is also possible without Extended Events or trace being involved, and that is when the query (or the variable assignment) can involve tempdb (e.g. via worktable/workfile). Hard to prove without EE/trace though! :-)
– Aaron Bertrand♦
Nov 27 '17 at 19:51
6
assigning to a max variable can certainly cause writes stackoverflow.com/a/7613012/73226
– Martin Smith
Nov 27 '17 at 20:41
add a comment |
1
I suspect this is also possible without Extended Events or trace being involved, and that is when the query (or the variable assignment) can involve tempdb (e.g. via worktable/workfile). Hard to prove without EE/trace though! :-)
– Aaron Bertrand♦
Nov 27 '17 at 19:51
6
assigning to a max variable can certainly cause writes stackoverflow.com/a/7613012/73226
– Martin Smith
Nov 27 '17 at 20:41
1
1
I suspect this is also possible without Extended Events or trace being involved, and that is when the query (or the variable assignment) can involve tempdb (e.g. via worktable/workfile). Hard to prove without EE/trace though! :-)
– Aaron Bertrand♦
Nov 27 '17 at 19:51
I suspect this is also possible without Extended Events or trace being involved, and that is when the query (or the variable assignment) can involve tempdb (e.g. via worktable/workfile). Hard to prove without EE/trace though! :-)
– Aaron Bertrand♦
Nov 27 '17 at 19:51
6
6
assigning to a max variable can certainly cause writes stackoverflow.com/a/7613012/73226
– Martin Smith
Nov 27 '17 at 20:41
assigning to a max variable can certainly cause writes stackoverflow.com/a/7613012/73226
– Martin Smith
Nov 27 '17 at 20:41
add a comment |
3 Answers
3
active
oldest
votes
In some cases Query Store can cause writes to occur as an effect of a select statement, and in the same session.
This can be reproduced as follows:
USE master;
GO
CREATE DATABASE [Foo];
ALTER DATABASE [Foo] SET QUERY_STORE (OPERATION_MODE = READ_WRITE,
CLEANUP_POLICY = (STALE_QUERY_THRESHOLD_DAYS = 30),
DATA_FLUSH_INTERVAL_SECONDS = 900,
INTERVAL_LENGTH_MINUTES = 60,
MAX_STORAGE_SIZE_MB = 100,
QUERY_CAPTURE_MODE = ALL,
SIZE_BASED_CLEANUP_MODE = AUTO);
USE Foo;
CREATE TABLE Test (a int, b nvarchar(max));
INSERT INTO Test SELECT 1, 'string';
Create an Extended Events session for monitoring:
CREATE EVENT SESSION [Foo] ON SERVER
ADD EVENT sqlserver.rpc_completed(SET collect_data_stream=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0))),
ADD EVENT sqlserver.sql_batch_completed(SET collect_batch_text=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0)))
ADD TARGET package0.event_file(SET filename=N'C:tempFooActivity2016.xel',max_file_size=(11),max_rollover_files=(999999))
WITH (MAX_MEMORY=32768 KB,EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=ON,STARTUP_STATE=OFF);
Next run the following:
WHILE @@TRANCOUNT > 0 COMMIT
SET IMPLICIT_TRANSACTIONS ON;
SET NOCOUNT ON;
GO
DECLARE @b nvarchar(max);
SELECT @b = b FROM dbo.Test WHERE a = 1;
WAITFOR DELAY '00:00:01.000';
GO 86400
An implicit transaction may or may not be necessary to reproduce this.
By default, at the top of the next hour Query Store's statistics collection job will write out data. This appears to (sometimes?) occur as part of the first user query executed during the hour. The Extended Events session will show something similar to the following:
The transaction log shows the writes that have occurred:
USE Foo;
SELECT [Transaction ID], [Begin Time], SPID, Operation,
[Description], [Page ID], [Slot ID], [Parent Transaction ID]
FROM sys.fn_dblog(null,null)
/* Adjust based on contents of your transaction log */
WHERE [Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
OR [Parent Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
ORDER BY [Current LSN];
Inspecting the page with DBCC PAGE
shows that the writes are to sys.plan_persist_runtime_stats_interval
.
USE Foo;
DBCC TRACEON(3604);
DBCC PAGE(5,1,344,1); SELECT
OBJECT_NAME(229575856);
Note that the log entries show three nested transactions but only two commit records. In a similar situation in production, this led to an arguably faulty client library that used implicit transactions unexpectedly starting a write transaction, preventing the transaction log from clearing. The library was written to only issue a commit after running an update, insert, or delete statement, so it never issued a commit command and left a write transaction open.
add a comment |
There's another time when this may happen, and that's with an automatic stats update.
Here's the XE session we'll be looking at:
CREATE EVENT SESSION batches_and_stats
ON SERVER
ADD EVENT sqlserver.auto_stats
( ACTION ( sqlserver.sql_text )),
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempbatches_and_stats' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 30 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
Then we'll use this to collect information:
USE tempdb
DROP TABLE IF EXISTS dbo.SkewedUp
CREATE TABLE dbo.SkewedUp (Id INT NOT NULL, INDEX cx_su CLUSTERED (Id))
INSERT dbo.SkewedUp WITH ( TABLOCK ) ( Id )
SELECT CASE WHEN x.r % 15 = 0 THEN 1
WHEN x.r % 5 = 0 THEN 1000
WHEN x.r % 3 = 0 THEN 10000
ELSE 100000
END AS Id
FROM ( SELECT TOP 1000000 ROW_NUMBER() OVER ( ORDER BY @@DBTS ) AS r
FROM sys.messages AS m
CROSS JOIN sys.messages AS m2 ) AS x;
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = START
SELECT su.Id, COUNT(*) AS records
FROM dbo.SkewedUp AS su
WHERE su.Id > 0
GROUP BY su.Id
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = STOP
Some of the interesting results from the XE Session:
The auto stats update doesn't show any writes, but the query shows one write immediately after the stats update.
add a comment |
Clumsy
I couldn't remember if I included these in my original answer, so here's another couple.
Spools!
SQL Server has lots of different spools, which are temporary data structures stored off in tempdb. Two examples are Table and Index spools.
When they occur in a query plan, the writes to those spools will be associated with the query.
These will also be registered as writes in DMVs, profiler, XE, etc.
Index Spool
Table Spool
The amount of writes performed will go up with the size of the data spooled, obviously.
Spills
When SQL Server doesn't get enough memory for certain operators, it may spill some pages to disk. This primarily happens with sorts and hashes. You can see this in actual execution plans, and in newer versions of SQL server, spills are also tracked in dm_exec_query_stats.
SELECT deqs.sql_handle,
deqs.total_spills,
deqs.last_spills,
deqs.min_spills,
deqs.max_spills
FROM sys.dm_exec_query_stats AS deqs
WHERE deqs.min_spills > 0;
Tracking
You can use a similar XE session as the one I used above to see these in your own demos.
CREATE EVENT SESSION spools_and_spills
ON SERVER
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempspools_and_spills' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 1 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
add a comment |
Your Answer
StackExchange.ready(function() {
var channelOptions = {
tags: "".split(" "),
id: "182"
};
initTagRenderer("".split(" "), "".split(" "), channelOptions);
StackExchange.using("externalEditor", function() {
// Have to fire editor after snippets, if snippets enabled
if (StackExchange.settings.snippets.snippetsEnabled) {
StackExchange.using("snippets", function() {
createEditor();
});
}
else {
createEditor();
}
});
function createEditor() {
StackExchange.prepareEditor({
heartbeatType: 'answer',
autoActivateHeartbeat: false,
convertImagesToLinks: false,
noModals: true,
showLowRepImageUploadWarning: true,
reputationToPostImages: null,
bindNavPrevention: true,
postfix: "",
imageUploader: {
brandingHtml: "Powered by u003ca class="icon-imgur-white" href="https://imgur.com/"u003eu003c/au003e",
contentPolicyHtml: "User contributions licensed under u003ca href="https://creativecommons.org/licenses/by-sa/3.0/"u003ecc by-sa 3.0 with attribution requiredu003c/au003e u003ca href="https://stackoverflow.com/legal/content-policy"u003e(content policy)u003c/au003e",
allowUrls: true
},
onDemand: true,
discardSelector: ".discard-answer"
,immediatelyShowMarkdownHelp:true
});
}
});
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
StackExchange.ready(
function () {
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fdba.stackexchange.com%2fquestions%2f191825%2fwhy-would-a-select-query-cause-writes%23new-answer', 'question_page');
}
);
Post as a guest
Required, but never shown
3 Answers
3
active
oldest
votes
3 Answers
3
active
oldest
votes
active
oldest
votes
active
oldest
votes
In some cases Query Store can cause writes to occur as an effect of a select statement, and in the same session.
This can be reproduced as follows:
USE master;
GO
CREATE DATABASE [Foo];
ALTER DATABASE [Foo] SET QUERY_STORE (OPERATION_MODE = READ_WRITE,
CLEANUP_POLICY = (STALE_QUERY_THRESHOLD_DAYS = 30),
DATA_FLUSH_INTERVAL_SECONDS = 900,
INTERVAL_LENGTH_MINUTES = 60,
MAX_STORAGE_SIZE_MB = 100,
QUERY_CAPTURE_MODE = ALL,
SIZE_BASED_CLEANUP_MODE = AUTO);
USE Foo;
CREATE TABLE Test (a int, b nvarchar(max));
INSERT INTO Test SELECT 1, 'string';
Create an Extended Events session for monitoring:
CREATE EVENT SESSION [Foo] ON SERVER
ADD EVENT sqlserver.rpc_completed(SET collect_data_stream=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0))),
ADD EVENT sqlserver.sql_batch_completed(SET collect_batch_text=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0)))
ADD TARGET package0.event_file(SET filename=N'C:tempFooActivity2016.xel',max_file_size=(11),max_rollover_files=(999999))
WITH (MAX_MEMORY=32768 KB,EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=ON,STARTUP_STATE=OFF);
Next run the following:
WHILE @@TRANCOUNT > 0 COMMIT
SET IMPLICIT_TRANSACTIONS ON;
SET NOCOUNT ON;
GO
DECLARE @b nvarchar(max);
SELECT @b = b FROM dbo.Test WHERE a = 1;
WAITFOR DELAY '00:00:01.000';
GO 86400
An implicit transaction may or may not be necessary to reproduce this.
By default, at the top of the next hour Query Store's statistics collection job will write out data. This appears to (sometimes?) occur as part of the first user query executed during the hour. The Extended Events session will show something similar to the following:
The transaction log shows the writes that have occurred:
USE Foo;
SELECT [Transaction ID], [Begin Time], SPID, Operation,
[Description], [Page ID], [Slot ID], [Parent Transaction ID]
FROM sys.fn_dblog(null,null)
/* Adjust based on contents of your transaction log */
WHERE [Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
OR [Parent Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
ORDER BY [Current LSN];
Inspecting the page with DBCC PAGE
shows that the writes are to sys.plan_persist_runtime_stats_interval
.
USE Foo;
DBCC TRACEON(3604);
DBCC PAGE(5,1,344,1); SELECT
OBJECT_NAME(229575856);
Note that the log entries show three nested transactions but only two commit records. In a similar situation in production, this led to an arguably faulty client library that used implicit transactions unexpectedly starting a write transaction, preventing the transaction log from clearing. The library was written to only issue a commit after running an update, insert, or delete statement, so it never issued a commit command and left a write transaction open.
add a comment |
In some cases Query Store can cause writes to occur as an effect of a select statement, and in the same session.
This can be reproduced as follows:
USE master;
GO
CREATE DATABASE [Foo];
ALTER DATABASE [Foo] SET QUERY_STORE (OPERATION_MODE = READ_WRITE,
CLEANUP_POLICY = (STALE_QUERY_THRESHOLD_DAYS = 30),
DATA_FLUSH_INTERVAL_SECONDS = 900,
INTERVAL_LENGTH_MINUTES = 60,
MAX_STORAGE_SIZE_MB = 100,
QUERY_CAPTURE_MODE = ALL,
SIZE_BASED_CLEANUP_MODE = AUTO);
USE Foo;
CREATE TABLE Test (a int, b nvarchar(max));
INSERT INTO Test SELECT 1, 'string';
Create an Extended Events session for monitoring:
CREATE EVENT SESSION [Foo] ON SERVER
ADD EVENT sqlserver.rpc_completed(SET collect_data_stream=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0))),
ADD EVENT sqlserver.sql_batch_completed(SET collect_batch_text=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0)))
ADD TARGET package0.event_file(SET filename=N'C:tempFooActivity2016.xel',max_file_size=(11),max_rollover_files=(999999))
WITH (MAX_MEMORY=32768 KB,EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=ON,STARTUP_STATE=OFF);
Next run the following:
WHILE @@TRANCOUNT > 0 COMMIT
SET IMPLICIT_TRANSACTIONS ON;
SET NOCOUNT ON;
GO
DECLARE @b nvarchar(max);
SELECT @b = b FROM dbo.Test WHERE a = 1;
WAITFOR DELAY '00:00:01.000';
GO 86400
An implicit transaction may or may not be necessary to reproduce this.
By default, at the top of the next hour Query Store's statistics collection job will write out data. This appears to (sometimes?) occur as part of the first user query executed during the hour. The Extended Events session will show something similar to the following:
The transaction log shows the writes that have occurred:
USE Foo;
SELECT [Transaction ID], [Begin Time], SPID, Operation,
[Description], [Page ID], [Slot ID], [Parent Transaction ID]
FROM sys.fn_dblog(null,null)
/* Adjust based on contents of your transaction log */
WHERE [Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
OR [Parent Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
ORDER BY [Current LSN];
Inspecting the page with DBCC PAGE
shows that the writes are to sys.plan_persist_runtime_stats_interval
.
USE Foo;
DBCC TRACEON(3604);
DBCC PAGE(5,1,344,1); SELECT
OBJECT_NAME(229575856);
Note that the log entries show three nested transactions but only two commit records. In a similar situation in production, this led to an arguably faulty client library that used implicit transactions unexpectedly starting a write transaction, preventing the transaction log from clearing. The library was written to only issue a commit after running an update, insert, or delete statement, so it never issued a commit command and left a write transaction open.
add a comment |
In some cases Query Store can cause writes to occur as an effect of a select statement, and in the same session.
This can be reproduced as follows:
USE master;
GO
CREATE DATABASE [Foo];
ALTER DATABASE [Foo] SET QUERY_STORE (OPERATION_MODE = READ_WRITE,
CLEANUP_POLICY = (STALE_QUERY_THRESHOLD_DAYS = 30),
DATA_FLUSH_INTERVAL_SECONDS = 900,
INTERVAL_LENGTH_MINUTES = 60,
MAX_STORAGE_SIZE_MB = 100,
QUERY_CAPTURE_MODE = ALL,
SIZE_BASED_CLEANUP_MODE = AUTO);
USE Foo;
CREATE TABLE Test (a int, b nvarchar(max));
INSERT INTO Test SELECT 1, 'string';
Create an Extended Events session for monitoring:
CREATE EVENT SESSION [Foo] ON SERVER
ADD EVENT sqlserver.rpc_completed(SET collect_data_stream=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0))),
ADD EVENT sqlserver.sql_batch_completed(SET collect_batch_text=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0)))
ADD TARGET package0.event_file(SET filename=N'C:tempFooActivity2016.xel',max_file_size=(11),max_rollover_files=(999999))
WITH (MAX_MEMORY=32768 KB,EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=ON,STARTUP_STATE=OFF);
Next run the following:
WHILE @@TRANCOUNT > 0 COMMIT
SET IMPLICIT_TRANSACTIONS ON;
SET NOCOUNT ON;
GO
DECLARE @b nvarchar(max);
SELECT @b = b FROM dbo.Test WHERE a = 1;
WAITFOR DELAY '00:00:01.000';
GO 86400
An implicit transaction may or may not be necessary to reproduce this.
By default, at the top of the next hour Query Store's statistics collection job will write out data. This appears to (sometimes?) occur as part of the first user query executed during the hour. The Extended Events session will show something similar to the following:
The transaction log shows the writes that have occurred:
USE Foo;
SELECT [Transaction ID], [Begin Time], SPID, Operation,
[Description], [Page ID], [Slot ID], [Parent Transaction ID]
FROM sys.fn_dblog(null,null)
/* Adjust based on contents of your transaction log */
WHERE [Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
OR [Parent Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
ORDER BY [Current LSN];
Inspecting the page with DBCC PAGE
shows that the writes are to sys.plan_persist_runtime_stats_interval
.
USE Foo;
DBCC TRACEON(3604);
DBCC PAGE(5,1,344,1); SELECT
OBJECT_NAME(229575856);
Note that the log entries show three nested transactions but only two commit records. In a similar situation in production, this led to an arguably faulty client library that used implicit transactions unexpectedly starting a write transaction, preventing the transaction log from clearing. The library was written to only issue a commit after running an update, insert, or delete statement, so it never issued a commit command and left a write transaction open.
In some cases Query Store can cause writes to occur as an effect of a select statement, and in the same session.
This can be reproduced as follows:
USE master;
GO
CREATE DATABASE [Foo];
ALTER DATABASE [Foo] SET QUERY_STORE (OPERATION_MODE = READ_WRITE,
CLEANUP_POLICY = (STALE_QUERY_THRESHOLD_DAYS = 30),
DATA_FLUSH_INTERVAL_SECONDS = 900,
INTERVAL_LENGTH_MINUTES = 60,
MAX_STORAGE_SIZE_MB = 100,
QUERY_CAPTURE_MODE = ALL,
SIZE_BASED_CLEANUP_MODE = AUTO);
USE Foo;
CREATE TABLE Test (a int, b nvarchar(max));
INSERT INTO Test SELECT 1, 'string';
Create an Extended Events session for monitoring:
CREATE EVENT SESSION [Foo] ON SERVER
ADD EVENT sqlserver.rpc_completed(SET collect_data_stream=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0))),
ADD EVENT sqlserver.sql_batch_completed(SET collect_batch_text=(1)
ACTION(sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_name,sqlserver.is_system,sqlserver.server_principal_name,sqlserver.session_id,sqlserver.session_server_principal_name,sqlserver.sql_text)
WHERE ([writes]>(0)))
ADD TARGET package0.event_file(SET filename=N'C:tempFooActivity2016.xel',max_file_size=(11),max_rollover_files=(999999))
WITH (MAX_MEMORY=32768 KB,EVENT_RETENTION_MODE=ALLOW_MULTIPLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=ON,STARTUP_STATE=OFF);
Next run the following:
WHILE @@TRANCOUNT > 0 COMMIT
SET IMPLICIT_TRANSACTIONS ON;
SET NOCOUNT ON;
GO
DECLARE @b nvarchar(max);
SELECT @b = b FROM dbo.Test WHERE a = 1;
WAITFOR DELAY '00:00:01.000';
GO 86400
An implicit transaction may or may not be necessary to reproduce this.
By default, at the top of the next hour Query Store's statistics collection job will write out data. This appears to (sometimes?) occur as part of the first user query executed during the hour. The Extended Events session will show something similar to the following:
The transaction log shows the writes that have occurred:
USE Foo;
SELECT [Transaction ID], [Begin Time], SPID, Operation,
[Description], [Page ID], [Slot ID], [Parent Transaction ID]
FROM sys.fn_dblog(null,null)
/* Adjust based on contents of your transaction log */
WHERE [Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
OR [Parent Transaction ID] IN ('0000:0000042c', '0000:0000042d', '0000:0000042e')
ORDER BY [Current LSN];
Inspecting the page with DBCC PAGE
shows that the writes are to sys.plan_persist_runtime_stats_interval
.
USE Foo;
DBCC TRACEON(3604);
DBCC PAGE(5,1,344,1); SELECT
OBJECT_NAME(229575856);
Note that the log entries show three nested transactions but only two commit records. In a similar situation in production, this led to an arguably faulty client library that used implicit transactions unexpectedly starting a write transaction, preventing the transaction log from clearing. The library was written to only issue a commit after running an update, insert, or delete statement, so it never issued a commit command and left a write transaction open.
edited Nov 27 '17 at 23:10
answered Nov 27 '17 at 19:08
James LJames L
2,46542040
2,46542040
add a comment |
add a comment |
There's another time when this may happen, and that's with an automatic stats update.
Here's the XE session we'll be looking at:
CREATE EVENT SESSION batches_and_stats
ON SERVER
ADD EVENT sqlserver.auto_stats
( ACTION ( sqlserver.sql_text )),
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempbatches_and_stats' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 30 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
Then we'll use this to collect information:
USE tempdb
DROP TABLE IF EXISTS dbo.SkewedUp
CREATE TABLE dbo.SkewedUp (Id INT NOT NULL, INDEX cx_su CLUSTERED (Id))
INSERT dbo.SkewedUp WITH ( TABLOCK ) ( Id )
SELECT CASE WHEN x.r % 15 = 0 THEN 1
WHEN x.r % 5 = 0 THEN 1000
WHEN x.r % 3 = 0 THEN 10000
ELSE 100000
END AS Id
FROM ( SELECT TOP 1000000 ROW_NUMBER() OVER ( ORDER BY @@DBTS ) AS r
FROM sys.messages AS m
CROSS JOIN sys.messages AS m2 ) AS x;
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = START
SELECT su.Id, COUNT(*) AS records
FROM dbo.SkewedUp AS su
WHERE su.Id > 0
GROUP BY su.Id
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = STOP
Some of the interesting results from the XE Session:
The auto stats update doesn't show any writes, but the query shows one write immediately after the stats update.
add a comment |
There's another time when this may happen, and that's with an automatic stats update.
Here's the XE session we'll be looking at:
CREATE EVENT SESSION batches_and_stats
ON SERVER
ADD EVENT sqlserver.auto_stats
( ACTION ( sqlserver.sql_text )),
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempbatches_and_stats' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 30 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
Then we'll use this to collect information:
USE tempdb
DROP TABLE IF EXISTS dbo.SkewedUp
CREATE TABLE dbo.SkewedUp (Id INT NOT NULL, INDEX cx_su CLUSTERED (Id))
INSERT dbo.SkewedUp WITH ( TABLOCK ) ( Id )
SELECT CASE WHEN x.r % 15 = 0 THEN 1
WHEN x.r % 5 = 0 THEN 1000
WHEN x.r % 3 = 0 THEN 10000
ELSE 100000
END AS Id
FROM ( SELECT TOP 1000000 ROW_NUMBER() OVER ( ORDER BY @@DBTS ) AS r
FROM sys.messages AS m
CROSS JOIN sys.messages AS m2 ) AS x;
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = START
SELECT su.Id, COUNT(*) AS records
FROM dbo.SkewedUp AS su
WHERE su.Id > 0
GROUP BY su.Id
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = STOP
Some of the interesting results from the XE Session:
The auto stats update doesn't show any writes, but the query shows one write immediately after the stats update.
add a comment |
There's another time when this may happen, and that's with an automatic stats update.
Here's the XE session we'll be looking at:
CREATE EVENT SESSION batches_and_stats
ON SERVER
ADD EVENT sqlserver.auto_stats
( ACTION ( sqlserver.sql_text )),
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempbatches_and_stats' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 30 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
Then we'll use this to collect information:
USE tempdb
DROP TABLE IF EXISTS dbo.SkewedUp
CREATE TABLE dbo.SkewedUp (Id INT NOT NULL, INDEX cx_su CLUSTERED (Id))
INSERT dbo.SkewedUp WITH ( TABLOCK ) ( Id )
SELECT CASE WHEN x.r % 15 = 0 THEN 1
WHEN x.r % 5 = 0 THEN 1000
WHEN x.r % 3 = 0 THEN 10000
ELSE 100000
END AS Id
FROM ( SELECT TOP 1000000 ROW_NUMBER() OVER ( ORDER BY @@DBTS ) AS r
FROM sys.messages AS m
CROSS JOIN sys.messages AS m2 ) AS x;
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = START
SELECT su.Id, COUNT(*) AS records
FROM dbo.SkewedUp AS su
WHERE su.Id > 0
GROUP BY su.Id
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = STOP
Some of the interesting results from the XE Session:
The auto stats update doesn't show any writes, but the query shows one write immediately after the stats update.
There's another time when this may happen, and that's with an automatic stats update.
Here's the XE session we'll be looking at:
CREATE EVENT SESSION batches_and_stats
ON SERVER
ADD EVENT sqlserver.auto_stats
( ACTION ( sqlserver.sql_text )),
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempbatches_and_stats' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 30 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
Then we'll use this to collect information:
USE tempdb
DROP TABLE IF EXISTS dbo.SkewedUp
CREATE TABLE dbo.SkewedUp (Id INT NOT NULL, INDEX cx_su CLUSTERED (Id))
INSERT dbo.SkewedUp WITH ( TABLOCK ) ( Id )
SELECT CASE WHEN x.r % 15 = 0 THEN 1
WHEN x.r % 5 = 0 THEN 1000
WHEN x.r % 3 = 0 THEN 10000
ELSE 100000
END AS Id
FROM ( SELECT TOP 1000000 ROW_NUMBER() OVER ( ORDER BY @@DBTS ) AS r
FROM sys.messages AS m
CROSS JOIN sys.messages AS m2 ) AS x;
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = START
SELECT su.Id, COUNT(*) AS records
FROM dbo.SkewedUp AS su
WHERE su.Id > 0
GROUP BY su.Id
ALTER EVENT SESSION [batches_and_stats] ON SERVER STATE = STOP
Some of the interesting results from the XE Session:
The auto stats update doesn't show any writes, but the query shows one write immediately after the stats update.
answered Nov 27 '17 at 19:41
Erik DarlingErik Darling
21.2k1265105
21.2k1265105
add a comment |
add a comment |
Clumsy
I couldn't remember if I included these in my original answer, so here's another couple.
Spools!
SQL Server has lots of different spools, which are temporary data structures stored off in tempdb. Two examples are Table and Index spools.
When they occur in a query plan, the writes to those spools will be associated with the query.
These will also be registered as writes in DMVs, profiler, XE, etc.
Index Spool
Table Spool
The amount of writes performed will go up with the size of the data spooled, obviously.
Spills
When SQL Server doesn't get enough memory for certain operators, it may spill some pages to disk. This primarily happens with sorts and hashes. You can see this in actual execution plans, and in newer versions of SQL server, spills are also tracked in dm_exec_query_stats.
SELECT deqs.sql_handle,
deqs.total_spills,
deqs.last_spills,
deqs.min_spills,
deqs.max_spills
FROM sys.dm_exec_query_stats AS deqs
WHERE deqs.min_spills > 0;
Tracking
You can use a similar XE session as the one I used above to see these in your own demos.
CREATE EVENT SESSION spools_and_spills
ON SERVER
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempspools_and_spills' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 1 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
add a comment |
Clumsy
I couldn't remember if I included these in my original answer, so here's another couple.
Spools!
SQL Server has lots of different spools, which are temporary data structures stored off in tempdb. Two examples are Table and Index spools.
When they occur in a query plan, the writes to those spools will be associated with the query.
These will also be registered as writes in DMVs, profiler, XE, etc.
Index Spool
Table Spool
The amount of writes performed will go up with the size of the data spooled, obviously.
Spills
When SQL Server doesn't get enough memory for certain operators, it may spill some pages to disk. This primarily happens with sorts and hashes. You can see this in actual execution plans, and in newer versions of SQL server, spills are also tracked in dm_exec_query_stats.
SELECT deqs.sql_handle,
deqs.total_spills,
deqs.last_spills,
deqs.min_spills,
deqs.max_spills
FROM sys.dm_exec_query_stats AS deqs
WHERE deqs.min_spills > 0;
Tracking
You can use a similar XE session as the one I used above to see these in your own demos.
CREATE EVENT SESSION spools_and_spills
ON SERVER
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempspools_and_spills' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 1 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
add a comment |
Clumsy
I couldn't remember if I included these in my original answer, so here's another couple.
Spools!
SQL Server has lots of different spools, which are temporary data structures stored off in tempdb. Two examples are Table and Index spools.
When they occur in a query plan, the writes to those spools will be associated with the query.
These will also be registered as writes in DMVs, profiler, XE, etc.
Index Spool
Table Spool
The amount of writes performed will go up with the size of the data spooled, obviously.
Spills
When SQL Server doesn't get enough memory for certain operators, it may spill some pages to disk. This primarily happens with sorts and hashes. You can see this in actual execution plans, and in newer versions of SQL server, spills are also tracked in dm_exec_query_stats.
SELECT deqs.sql_handle,
deqs.total_spills,
deqs.last_spills,
deqs.min_spills,
deqs.max_spills
FROM sys.dm_exec_query_stats AS deqs
WHERE deqs.min_spills > 0;
Tracking
You can use a similar XE session as the one I used above to see these in your own demos.
CREATE EVENT SESSION spools_and_spills
ON SERVER
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempspools_and_spills' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 1 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
Clumsy
I couldn't remember if I included these in my original answer, so here's another couple.
Spools!
SQL Server has lots of different spools, which are temporary data structures stored off in tempdb. Two examples are Table and Index spools.
When they occur in a query plan, the writes to those spools will be associated with the query.
These will also be registered as writes in DMVs, profiler, XE, etc.
Index Spool
Table Spool
The amount of writes performed will go up with the size of the data spooled, obviously.
Spills
When SQL Server doesn't get enough memory for certain operators, it may spill some pages to disk. This primarily happens with sorts and hashes. You can see this in actual execution plans, and in newer versions of SQL server, spills are also tracked in dm_exec_query_stats.
SELECT deqs.sql_handle,
deqs.total_spills,
deqs.last_spills,
deqs.min_spills,
deqs.max_spills
FROM sys.dm_exec_query_stats AS deqs
WHERE deqs.min_spills > 0;
Tracking
You can use a similar XE session as the one I used above to see these in your own demos.
CREATE EVENT SESSION spools_and_spills
ON SERVER
ADD EVENT sqlserver.sql_batch_completed
( ACTION ( sqlserver.sql_text ))
ADD TARGET package0.event_file
( SET filename = N'c:tempspools_and_spills' )
WITH ( MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 1 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF );
GO
answered 9 mins ago
Erik DarlingErik Darling
21.2k1265105
21.2k1265105
add a comment |
add a comment |
Thanks for contributing an answer to Database Administrators Stack Exchange!
- Please be sure to answer the question. Provide details and share your research!
But avoid …
- Asking for help, clarification, or responding to other answers.
- Making statements based on opinion; back them up with references or personal experience.
To learn more, see our tips on writing great answers.
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
StackExchange.ready(
function () {
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2fdba.stackexchange.com%2fquestions%2f191825%2fwhy-would-a-select-query-cause-writes%23new-answer', 'question_page');
}
);
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function () {
StackExchange.helpers.onClickDraftSave('#login-link');
});
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
1
I suspect this is also possible without Extended Events or trace being involved, and that is when the query (or the variable assignment) can involve tempdb (e.g. via worktable/workfile). Hard to prove without EE/trace though! :-)
– Aaron Bertrand♦
Nov 27 '17 at 19:51
6
assigning to a max variable can certainly cause writes stackoverflow.com/a/7613012/73226
– Martin Smith
Nov 27 '17 at 20:41