Why would a SELECT query cause writes?

Question

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?

Answer 1

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:\temp\spools_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

Answer 2

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:\temp\FooActivity2016.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.

Answer 3

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:\temp\batches_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.