I am writing an application which builds a database on a SQL server. The application loads data into some staging tables, then executes a series of stored procedures which merge the staging tables into the main tables.
The problem I'm seeing is that the merge itself is consistently much slower than I expect given the resources available to the server (8 cores, DB stored on RAID0 array of two SSDs, 32GB RAM, no other server processes running on the machine or other users of the SQL Server instance).
To be specific, during the merge:
- Server CPU usage is very low (a few percent)
- There are essentially no writes and reads to the logical volume that the database is stored on (measured in perfmon)
- In a 30s period during the merge, Brent Ozar's wait stats triage script (http://www.brentozar.com/responder/triage-wait-stats-in-sql-server/) reports a maximum wait time of only 0.6s (on the SOS_SCHEDULER_YIELD wait type)
dm_io_virtual_file_statsfor both tempdb and the main database before and after a 30s period during the merge shows that IO stall time increases by less than 0.1s, indicating that we are not blocked on IO
- Activity Monitor confirms the IO system is lightly loaded: maximum IO response latency is only 9ms, with very low number of bytes transferred
- Intel Performance Counter Monitor (http://www.intel.com/software/pcm) shows that we are not swamping RAM bandwidth because only about 500MB/s is being transferred (out of a benchmarked maximum on this machine of around 13GB/s)
dm_exec_sessionsfor the merging session before and after a 30s period during the merge shows that:
total_elapsed_timeincreased by ~10s (I assume this is not 30s because
dm_exec_sessionsonly gets updated periodically)
cpu_timeincreases by only 0.1s
memory_usageis only 2 pages both before and after
logical_readsare performed in this 10s period (i.e. 2,000 a second). This seems very low to me given that that only represents 16MB/s of data transfer.
readsare performed. (I'm not quite sure how to interpret this.)
SQL Profiler shows that it is the execution of statements of the following form that is slow (taking as much as 5s when there are ~1000 rows in the staging table
;WITH Source AS ( SELECT RowNumber = ROW_NUMBER() OVER (PARTITION BY GSAQuoteID, Date ORDER BY ID DESC) , Source.* FROM stage.[LastTradePrice] Source ) INSERT INTO @Stage ( GSAQuoteID , Date , Value ) SELECT Source.GSAQuoteID , Source.Date , Source.Value FROM Source OUTER APPLY ( SELECT TOP 1 Value = CASE WHEN ToSourceID IS NULL THEN Target.Value ELSE NULL END FROM dbo.[LastTradePrice] Target WHERE Target.GSAQuoteID = Source.GSAQuoteID AND Target.Date = Source.Date ORDER BY Target.FromSourceID DESC ) Target WHERE Source.RowNumber = 1 AND ( (Source.Value IS NULL AND Target.Value IS NOT NULL) OR (Source.Value IS NOT NULL AND Target.Value IS NULL) OR (Source.Value <> Target.Value) );
This query is the first stage of the merge: it selects those elements of the staging table
stage.LastTradePrice which are different from the data we already have in the main table
The query plan for this statement looks pretty much optimal (i.e. it sorts the staging table by
(GSAQuoteID,Date,ID DESC), segments it by
(GSAQuoteID,Date) and then does a single-row seek into the LastTradePrice table for the top row in each segment, before doing the final clustered index insert). More details:
stage.LastTradePricehas a clustered index on
ID, a synthetic integer primary key. Rows occur in the order they are bulk inserted by the application
dbo.LastTradePricehas a clustered index on
(GSAQuoteID, Date, FromSourceID)
- There are about 56M rows in
dbo.LastTradePrice, an average of 168 per
GSAQuoteIDand just over 1 per
The database itself is about 34GB in size and therefore should almost entirely fit into memory. This is confirmed by the very high buffer cache hit ratio of >=99.8% I see consistently.
This all leaves me a bit confused. If these slow statements aren't starved of CPU time, waiting on IO, waiting on a lock or starved of memory bandwidth, what actually is left as a possible cause of the slowdown?
The only thing that I think might be a bit unusual about the system is that there is a relatively large number of tables and stored procedures. For various reasons, each of the ~330 fields I wish to store (e.g. LastTradePrice, Volume, OpenPrice and lots more) are given their own table+staging table, each with a corresponding stored procedure that implements the merge. (All of the sprocs are generated from a template, so the merge logic is basically identical for all fields.).
I think the large number of sprocs may explain why I'm seeing what I believe is a relatively high "Stolen pages" count of 200,000 and plan cache hit ratio of only ~80% even though no adhoc SQL is being used. However, I don't see how this could explain my problem.