0

I have a virtual SQL Server 2016 SP2 CU2 with SAN storage. TempDB has 8 files. I know it is recommended to put TempDB on SSD but TempDB is hardly used so spinning disks are cheaper. I've noticed that sometimes their is write latency on all my TempDB files of approx 200ms. I checked this using a snapshot on sys.dm_io_virtual_file_stats and calculated io_stall_write_ms/num_of_writes.

The first thing I did was look at sys.dm_exec_query_stats to check if there was a query with high number of spills but no such query. Next I wrote an extended event to look if there where queries executed on tempdb but also this returned nothing.

So where does the write latency come from? I decided to track the file_write_completed event on tempdb. Here I saw that on moment of the latency that session 22 wrote something with a size of 8192 (don't know the unit) to all files of tempdb. In sys.dm_exec_sessions the last command of this session was 'RESOURCE MONITOR'.
The first thing I did was checking sys.dm_os_ring_buffers with following query:

SELECT  
    EventTime, 
    record.value('(/Record/ResourceMonitor/Notification)[1]', 'varchar(max)') as [Type], 
    record.value('(/Record/ResourceMonitor/IndicatorsProcess)[1]', 'int') as [IndicatorsProcess], 
    record.value('(/Record/ResourceMonitor/IndicatorsSystem)[1]', 'int') as [IndicatorsSystem], 
    record.value('(/Record/MemoryRecord/AvailablePhysicalMemory)[1]', 'bigint')/1024. AS [Avail Phys Mem, MB], 
    record.value('(/Record/MemoryRecord/AvailableVirtualAddressSpace)[1]', 'bigint') AS [Avail VAS, Kb] 
FROM ( 
    SELECT 
        DATEADD (ss, (-1 * ((cpu_ticks / CONVERT (float, ( cpu_ticks / ms_ticks ))) - [timestamp])/1000), GETDATE()) AS EventTime, 
        CONVERT (xml, record) AS record 
    FROM sys.dm_os_ring_buffers 
    CROSS JOIN sys.dm_os_sys_info 
    WHERE ring_buffer_type = 'RING_BUFFER_RESOURCE_MONITOR') AS tab 
ORDER BY EventTime DESC;

But again the result of the query didn't match with the moment of latency.

I also monitored the tempdb-drive with perfmon, using the counters 'Avg. Disk sec/Write' and 'Current Disk Queue Length'. On moment of latency the latency was 6ms and the queue length was 18.

I ran CrystalDiskMark and this is the avg result of multiple runs:

╔═════════════╦═══════════╦═════════╦══════════╦═══════╗
║             ║ seq Q32T1 ║ 4k q8T8 ║ 4K Q32T1 ║ 4Q1T1 ║
╠═════════════╬═══════════╬═════════╬══════════╬═══════╣
║ Read(MB/s)  ║ 1596,57   ║ 505,77  ║ 336,27   ║ 20,94 ║
║ Write(MB/s) ║ 591,01    ║ 127,6   ║ 87,87    ║ 2,74  ║
╚═════════════╩═══════════╩═════════╩══════════╩═══════╝

After some extended research I discovered that on moment of latency the lazy writer process starts flushing pages to disk. If I understand correctly, SQL Server removes the least used pages (dirty and clean) from the buffer pool when memory is needed.
So If above is correct, I should see high number of physical reads at moment of latency, this I will investigate further.
Also at moment of latency there are no checkpoints running.

This is my conclusion so far:

  • Resource Monitor is writing to Tempdb (detected with extended events, what/why is written I don't know)
  • Lazy Writer process is flushing pages from bufferpool because memory is needed. (I don't think this can cause write latency on Tempdb)

All this looks like signs of memory pressure to me. But what I don't understand is why is this causing write latency on Tempdb? What can I do to investigate this problem further?

  • What makes you think that 'TempDB is hardly ever used'? – George.Palacios Dec 20 '18 at 10:04
  • Almost no queries are executed using tempdb, no spills, our monitoring tool shows almost any usage of tempdb. – Frederik Vanderhaegen Dec 20 '18 at 10:29
  • Is this local or SAN storage? Are you seeing 15 second IO warnings in the error log? – Erik Darling Dec 20 '18 at 13:31
  • @sp_BlitzErik: the server is on SAN Storage but no IO warnings are present in the error log. – Frederik Vanderhaegen Dec 20 '18 at 13:53
  • The cause is likely the path from the server to the SAN. I'd check with the SAN admins about the speed and number of connections. If you're using like 1Gb iSCSI, that's gonna suck when you try to do anything that touches tempdb, like run CHECKDB. – Erik Darling Dec 20 '18 at 13:59

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.