{"id":1969,"date":"2015-03-18T00:00:00","date_gmt":"2015-03-18T00:00:00","guid":{"rendered":"https:\/\/test.simple-talk.com\/uncategorized\/never-ignore-a-sort-warning-in-sql-server\/"},"modified":"2022-05-06T17:37:53","modified_gmt":"2022-05-06T17:37:53","slug":"never-ignore-a-sort-warning-in-sql-server","status":"publish","type":"post","link":"https:\/\/www.red-gate.com\/simple-talk\/databases\/sql-server\/performance-sql-server\/never-ignore-a-sort-warning-in-sql-server\/","title":{"rendered":"Never Ignore a Sort Warning in SQL Server"},"content":{"rendered":"
\n

There is a very common performance problem on SQL Server which the Database warns you about with a ‘Sort Warning’. I bet that all of you who read this article have at least one sort warning entry in your default trace. Yes, it is warning about a problem that will hurt the performance of your queries badly. It goes like this …<\/p>\n

“<\/em>Sort warning operations that do not fit into memory can degrade query and server performance because multiple passes over the data are required to sort the data. It is important to optimize queries by removing them.<\/em>“<\/em><\/p>\n

We know about it, and I’ve already written about it <\/a>here at Simple Talk, and \u00a0there is also plenty of information about it on the internet.<\/p>\n

Any kind of SORT operation should be avoided if at all possible, but if you are seeing SORT warnings that the operation has had to spill into TempDB, then they should be investigated and fixed. When you are checking a query that is triggering these warnings, have you ever wondered why SQL Server does not ask for more memory to perform an in-progress sort to avoid spilling onto TempDB? If I tell you that it actually does that, would you believe it?<\/p>\n

In this article, I’ll show you how to see what is going on behind the scenes and suggest how to fix the problem<\/p>\n

All Sorts of Issues with SORT<\/h1>\n

When talking about the SORT operator, I like to say that a sort will have one of three consequences: bad, dreadful and awful. Let me demonstrate.<\/p>\n

The Bad Sort<\/h2>\n

If you have a beautifully-crafted and clean query, with a sort running entirely in memory, I would say even that is bad: It is bad because you can sometimes avoid the sort operation and no sort is better than one sort. Creating an index would help by making SQL Server read data that is already ordered and thereby avoid the need for a sort. Let’s see a sample.<\/p>\n

Here is a script to create a database and a table that we’ll use to test the truth of what I’ve written.<\/p>\n

\t\t\t\t\t -- Creating a DB\r\n\t\t\t CREATE DATABASE MyDB\r\n\t\t\t GO\r\n\t\t\t USE MyDB\r\n\t\t\t GO\r\n\t\t\t -- Creating a table\r\n\t\t\t IF OBJECT_ID('SortTable') IS NOT NULL\r\n\t\t\t \u00a0 DROP TABLE SortTable\r\n\t\t\t GO\r\n\t\t\t SELECT TOP 100000\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 IDENTITY(INT, 1,1) AS OrderID,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 ABS(CHECKSUM(NEWID()) \/ 10000000) AS CustomerID,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 CONVERT(DATETIME, GETDATE() - (CHECKSUM(NEWID()) \/ 1000000)) AS OrderDate,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 ISNULL(ABS(CONVERT(NUMERIC(18,2), (CHECKSUM(NEWID()) \/ 1000000.5))),0) AS Value,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 CONVERT(CHAR(500), NEWID()) AS ColChar\r\n\t\t\t \u00a0 INTO SortTable\r\n\t\t\t \u00a0 FROM sysobjects A\r\n\t\t\t \u00a0CROSS JOIN sysobjects B CROSS JOIN sysobjects C CROSS JOIN sysobjects D\r\n\t\t\t GO\r\n\t\t\t CREATE CLUSTERED INDEX ix1 ON SortTable (OrderID)\r\n\t\t\t GO\r\n<\/pre>\n
First, we will perform a query that manages to do the SORT operation in memory, and here is our test query to do that: I’ve forced the Query Optimizer to do a sort by neglecting to put an index on ColChar<\/strong> (CREATE INDEX <\/strong>ixColChar<\/strong> ON <\/strong>SortTable<\/strong>(<\/strong>ColChar<\/strong>)<\/strong>) I’ve used a CONVERT trick so as to get more memory grant and avoid the spill through to TempDB:<\/p>\n
\t\t\tDECLARE @v1 Char(500), @v2 Int\r\n\t\tSELECT @v1 = ColChar, @v2 = OrderID\r\n\t\t\u00a0 FROM SortTable\r\n\t\t\u00a0ORDER BY CONVERT(VarChar(5000), ColChar) + ''\r\n\t\tOPTION  (MAXDOP 1, RECOMPILE)\r\n<\/pre>\n
This is the actual execution plan:<\/p>\n
\"2161-1-70a669d3-541d-448d-8b33-62d6e05ae\"<\/p>\n
As we can see, the query plan is estimating that the sort operation represents 60% of the entire cost of the query. But, how bad is it? I mean, how much time did it take to execute the sort? How much CPU and disk did it use?<\/p>\n
Well, on SQL Server 2014 we have access to the dm_exec_query_profiles<\/strong><\/a> DMV with all that information. So, let’s check it out.<\/p>\n
\t\t\t\t\t SELECT node_id,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 physical_operator_name,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 CAST(SUM(row_count)*100 AS float) \/ SUM(estimate_row_count) AS percent_complete,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(elapsed_time_ms) AS elapsed_time_ms,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(cpu_time_ms) AS cpu_time_ms,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(logical_read_count) AS logical_read_count,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(physical_read_count) AS physical_read_count,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(write_page_count) AS write_page_count,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(estimate_row_count) AS estimate_row_count\r\n\t\t\t \u00a0 FROM sys.dm_exec_query_profiles\r\n\t\t\t \u00a0WHERE session_id = 57 -- spid running query\r\n\t\t\t \u00a0GROUP BY node_id,\r\n\t\t\t \u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 physical_operator_name\r\n\t\t\t \u00a0ORDER BY node_id;\r\n\t\t<\/pre>\n
\"2161-1-e0739b97-97e2-4dbd-9fa0-48373115e\"<\/p>\n
I ran the query on exec_query_profiles<\/strong> DMV when the sort query was running (session 57) and, I was able to see that the clustered index scan took only 92ms to run and with 95% of the sort operation completed it took 1.2 sec and used a lot more of CPU.<\/p>\n
As you can see, the sort is an expensive operation. If we take out the ‘convert’ trick and create the index on ColChar that I’ve mentioned it would be enough to avoid the sort and improve the query performance.<\/p>\n
\"2161-1-fcdf9e82-d333-4259-bd8c-a96d82237\"<\/p>\n
The Dreadful sort<\/h2>\n
The “very bad” consequence happens when execution of the sort happens in-disk, it means it is<\/em><\/strong> using<\/em><\/strong> TempDB to spill data there. Let’s simulate this, and see the performance results.<\/p>\n
Here is the same query, but now without<\/em><\/strong> the CONVERT trick that I used to get more memory grant and avoid the spill. We will run it without the ixColChar<\/strong> index:<\/p>\n
\t\t\tDECLARE @v1 Char(500), @v2 Int\r\n\t\tSELECT @v1 = ColChar, @v2 = OrderID\r\n\t\t\u00a0 FROM SortTable\r\n\t\t\u00a0ORDER BY ColChar\r\n\t\tOPTION  (MAXDOP 1, RECOMPILE)\r\n\t<\/pre>\n
This is the actual execution plan:<\/p>\n
\"2161-1-0670d97a-fc86-4cb5-a009-22eb6de6f\"<\/p>\n
As we can see this is showing the warning on the sort operation, which means: “operator used TempDB to spill data during execution”.<\/p>\n
Let’s check the results of the DMV exec_query_profiles<\/strong>:<\/p>\n
\"2161-1-c2756bb9-9aad-4e71-ab79-c6d03b99a\"<\/p>\n
Notice that now the sort operator is much worse and is taking almost 3.1 seconds to run 98% of the sort.<\/p>\n
The Awful Sort<\/h2>\n
Now we will run the same query as before, the query that is using TempDB to spill data. But now I’ve set the TempDB to a very busy and slow disk.<\/p>\n
Check what happens when I ran the query:<\/p>\n
Results from the DMV:<\/p>\n
\"2161-1-0bd1c812-5d47-426b-845a-cdb8b49e9\"<\/p>\n
Exactly, it is taking almost 20 seconds to finish because I\/O is very poor, and the response time for the writes was very bad.<\/p>\n
Unfortunately this is a very common experience. We should remember to make sure that TempDB is located on as fast as possible a storage system to avoid this nightmare experience, period.<\/p>\n
Just in case you are wondering about the disk response time when the query was running, here it is:<\/p>\n
\"2161-1-d212cab5-8258-421e-87e1-4dccda8c0\"<\/p>\n
This is a very slow response time.<\/p>\n
Some Good News and Some Bad News!<\/h1>\n
As I said in the beginning of the article, SQL Server does<\/em><\/strong> ask for more memory for an in-progress sort to avoid spilling to TempDB. But (there is always a ‘but’), it is not for regular sorts. It only works for index sorts.<\/p>\n
What I’m saying is that if you try to create an index that internally will do the same sort operation, that index sort will not spill to disk, even if it initially did not ask for the correct memory grant.<\/p>\n
Let me show you. Consider the following command:<\/p>\n
\t\t\tCREATE INDEX ix2 ON SortTable(ColChar) INCLUDE(OrderID) WITH(MAXDOP = 1)\r\n\t<\/pre>\n
Here is the actual execution plan:<\/p>\n
\"2161-1-5ddb6934-0379-49f4-9989-8bd0e4d0b\"<\/p>\n
As you can see, in order to create the index, SQL Server is reading the data from the clustered index and sorting it by ColChar<\/strong>. This is the same thing as the query we tried. The sort operation does not have the warning, and I’m sure it is not using TempDB. I’ve set a sysinternals process monitor to track the write operations, and it is not using TempDB.<\/p>\n
What is happening here is that SQL Server is asking for more memory on the fly. And we can prove it just by looking at an obscure extended event called s<\/strong>ort_memory_grant_adjustment<\/strong>.<\/strong><\/p>\n
\"2161-1-a4eeb10e-0854-4126-92fb-6c6b7a593\"<\/p>\n
\"2161-1-0f6896e0-462a-48e5-97fb-53b116d71\"<\/p>\n
As we can see, it asked for 9968kb (1246 * 8) of extra memory and it was enough to avoid the spill to disk.<\/p>\n
We can also check the DMV dm_exec_query_memory_grants<\/strong> to see the granted memory for a query. Here is what it is showing:<\/p>\n
\"2161-1-a633415d-b146-4a3e-a7f8-f8ca16738\"<\/p>\n
This was initially using 68288kb of memory, but at some point it requested the extra 9968kb, totaling 78256kb of granted memory.<\/p>\n
The interesting thing here is that it can “steal” from the buffer pool as much memory as it needs, so as to avoid a spill to disk. Of course this comes at a price, since it would not be good to have a huge memory grant for nasty queries.<\/p>\n
The whole point of resource governance and memory grants is to ensure that some memory is kept aside for queries that start later. If this was the default option it would have bad consequences, such as having one huge query that uses all the available memory. The code that does the sort is not able to return memory once it has stolen it. That means that a greedy approach that ignores the memory grant could cause later queries to be delayed and\/or fail.<\/p>\n
I think Microsoft uses an assumption that any large CREATE INDEX operations are more likely to be running on an idle system (e.g., during a maintenance window) and at that time it is more likely to be ok to use all the available memory for CREATE INDEX operations.<\/p>\n
In my opinion it would be very useful to have a traceflag, a hint or a parameter to allow me to enable this “memory grant adjustment” for regular queries. Unfortunately, there is not.<\/p>\n
Conclusion<\/h1>\n
There is no such thing as a good SORT operation in a query. They should be avoided where possible. If you are getting SORT warnings, this is a call for action, because on a hard-working server this will lead to slow-running queries that will lead to even more demands on TempDB. Fortunately, SQL Server now has a range of ways of giving you information about what is going on with a query that is doing a SORT and will give details of how and when requests are made for memory.<\/p>\n
That\u00c2\u00b4s all folks.<\/p>\n<\/div>\n","protected":false},"excerpt":{"rendered":"
It is always bad news if your SQL queries are having to use the SORT operator. It is worse news if you get a warning that sort operations are spilling onto TempDB. If you have a busy, slow TempDB, then the effect on performance can be awful. You should check your query plans to try to eliminate SORTs and never leave a SORT warning unheeded. Fabiano Amorim shows the range of ways of getting information on what is going on with a query that is doing a SORT and when requests are made for memory.…<\/p>\n","protected":false},"author":65554,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[143529],"tags":[4178,4150,5842,4151],"coauthors":[6809],"class_list":["post-1969","post","type-post","status-publish","format-standard","hentry","category-performance-sql-server","tag-bi","tag-sql","tag-sql-monitor","tag-sql-server"],"acf":[],"_links":{"self":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/1969","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/users\/65554"}],"replies":[{"embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/comments?post=1969"}],"version-history":[{"count":6,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/1969\/revisions"}],"predecessor-version":[{"id":94204,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/1969\/revisions\/94204"}],"wp:attachment":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/media?parent=1969"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/categories?post=1969"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/tags?post=1969"},{"taxonomy":"author","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/coauthors?post=1969"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}