2

I'm setting up a website on new app and database servers. Server details are:

  • Windows 2016 Standard
  • SQL Server 2017 (RTM) - 14.0.1000.169 (X64)
  • 16GB RAM on SQL and 8GB on app server
  • 4 virtual CPUs on SQL and 1 on app server
  • VMs running on local servers (i.e. not in the cloud)
  • TCP/IP protocol is configured for SQL Server, Named Pipes disabled

Web pages are running slow so I've dug in to try and find the cause. What I ended up finding and can't explain is that if I have a simple query, e.g. (this query has the problem but I don't run it on the website):

SELECT 1

The query on its own has no problem, but if I pad it out with spaces so the query text is 676 characters or more (up to 675 runs fine) the execution will magically gain 500ms. If I keep adding spaces to around 1500 characters the performance is mostly slow with a random boost here and there. Adding more spaces to around 2000 characters the query becomes consistently fast again.

Running the query on the SQL server itself there is no problem, only when running remotely. I have tried a simple PowerShell script using SqlCommand on the app server and I've tried SQL Server Management Studio on another machine, both of these are slow. SQL Profiler shows the queries running instantly, Duration is 0 (CPU, Reads and Writes are also 0).

Here are some sample runs, this comes from SQL Management Studio client statistics with the slower instances where the query size are above 675 and the quicker instance below 676.

Client processing time      0       0       0       15      0
Total execution time        15      62      531     546     531
Wait time on server replies 15      62      531     531     531


Getting back to the website, I'm not running "SELECT 1" or padding queries with spaces in the website code. The actual queries being executed from the website are mainly from Entity Framework and because of the way those queries are constructed, the columns listed in the select clause, some queries have joins and where clauses, all those things result in the length of query text reaching that magical 676 character limit and the query runs slow. Here is an actual query from the website:

exec sp_executesql N'SELECT 
[Extent1].[Id] AS [Id], 
[Extent1].[ID] AS [Id1], 
[Extent1].[Name] AS [Name], 
[Extent1].[Code] AS [Code], 
[Extent1].[DisplayOrder] AS [DisplayOrder], 
[Extent1].[ScreenTypeId] AS [ScreenTypeId], 
[Extent1].[Exclude] AS [Exclude], 
[Extent1].[Author] AS [Author], 
[Extent1].[Editor] AS [Editor], 
[Extent1].[Created] AS [Created], 
[Extent1].[Modified] AS [Modified], 
[Extent2].[Id] AS [Id2], 
[Extent2].[Name] AS [Name1], 
[Extent2].[ScreenUrl] AS [ScreenUrl], 
[Extent2].[Author] AS [Author1], 
[Extent2].[Editor] AS [Editor1], 
[Extent2].[Created] AS [Created1], 
[Extent2].[Modified] AS [Modified1]
FROM  [dbo].[ProfitCentre] AS [Extent1]
INNER JOIN [dbo].[ScreenType] AS [Extent2] ON [Extent1].[ScreenTypeId] = [Extent2].[Id]
WHERE [Extent1].[ScreenTypeId] = @p__linq__0',N'@p__linq__0 int',@p__linq__0=16


Why are the queries taking so long when the length of the query text changes and how can I fix it?

TT.
  • 15,774
  • 6
  • 47
  • 88
davidp_1978
  • 131
  • 7
  • maybe it's related to plan cache. use `DBCC FREEPROCCACHE;` for remove all plan chache and run you query again. for mor information see https://learn.microsoft.com/en-us/sql/t-sql/database-console-commands/dbcc-freeproccache-transact-sql?view=sql-server-2017 – Hadi May 28 '19 at 04:35
  • It sounds like your query is sensitive to parameter sniffing. When you change the text by adding spaces, you bypass the plan cache and the query is compiled for your particular set of parameters so it's likely to be optimal for that set of parameters. – Ben Thul May 28 '19 at 04:42
  • Try to run the statement with recompile option and see whether you are still seeing the behaviour. Generally, in the background HASH is generated for the query and if the HASH of new query is different from existing ones, new plan is getting generated, otherwise if there is already an existing HASH existing plan is used. `SELECT 1 OPTION(RECOMPILE) ` – Venkataraman R May 28 '19 at 05:31
  • Another way, instead of `option(recompile)` which recompiles the query each time is to use `option(optimize for unknown)`. Some explanation [here](https://stackoverflow.com/a/35477849/243373). – TT. May 28 '19 at 06:07
  • I tried clearing the plan cache, I tried clearing the cache, running the query on it's own and clearing the cache then running with the spaces. Same weird behaviour. Also tried with both options, recompile and optimize for unknown, still runs slow with spaces and fast without. Would parameter sniffing still play a part even for something simple like the "select 1" as there are no parameters as such? We bumped the db server specs to ridiculous levels, 128GB RAM & 32 virtual CPUs, just to be sure... nope, still takes 500ms. – davidp_1978 May 28 '19 at 09:27
  • I took a random query (different to the ones in the OP), in Management Studio it is quick and from PowerShell it is slow, running from the same remote machine. I have SQL Profiler running with Showplan XML event and I compared the two plans, hovering over each operation I compared the two plans, exactly the same. I added a comment with several hundred characters (numbers 1..0 repeated). Now it is quick in both. I know it reeks of parameter sniffing but wouldn't that mean different query plans? – davidp_1978 May 28 '19 at 10:12
  • Hi again, I'm looking at the [SQL Server version list](https://sqlserverbuilds.blogspot.com/) and I'm seeing that there's [CU15 update](https://support.microsoft.com/en-us/help/4498951/cumulative-update-15-for-sql-server-2017). Before the first CU or SP, there can always some strange quirks still present in the version. Is it possible for you to try installing the CU and try again? – TT. May 28 '19 at 15:45
  • I installed all latest Windows updates and CU15, the problem remains. – davidp_1978 May 29 '19 at 02:16
  • @davidp_1978 Don't forget that if you want to address someone in comments, to add the text @ plus the user's name (see start of this comment e.g.). Have you tried from SSMS to include the actual execution plan and compare the two (the one where it's fast vs the one where it's slow)? – TT. May 29 '19 at 07:23
  • @TT. In the plan XML, when slow, the CompileTime and CompileCPU are 14 and 1 whereas when fast they are both 0. Everything else, including query hash and plan hash, are the same. – davidp_1978 May 29 '19 at 15:01
  • @davidp_1978 I have no real idea how EF works, still guessing here. I'd try create a stored procedure that returns the exact same resultset, having the same parameter as in the query you posted, but in the stored procedure add `option(optimize for unknown)` to the query therein. Then in your app, call the stored procedure instead of running the query directly. No idea if that is at all possible for you? – TT. May 29 '19 at 15:05
  • @TT. I created a stored proc, tried with and without 'option'. I didn't call it from code, just from Management Studio on another machine. Similar behaviour in that it runs quicker because of less characters but padding with a comment makes it slow. So one way to improve performance is to use stored procs, but only because it reduces character count. Annoying but possible, I'll leave it as the last resort. I made a request to get others to look at the server, waiting on their response... – davidp_1978 May 31 '19 at 06:11

1 Answers1

0

The issue in this case is due to the way the virtual machines were set up on the host environment. I don't deal with the infrastructure so I'm not sure the specific details but the infrastructure people shifted the VMs around into the appropriate cluster and that resolved the performance.

davidp_1978
  • 131
  • 7
  • Glad you got an answer. I was going to suggest that it was network packet/data block related between client & SQL Server. Longer text might tip it over the edge so the query needs 2 or more packets to send. Any errors or problems in routing would make it sensitive to packet size. – LoztInSpace Sep 14 '20 at 04:57
  • Slowing down due to additional packets being sent makes a lot of sense! Something else I could have tried is a couple queries of similar size returning different amounts of data, e.g. "where Deleted = 1" versus "where Deleted = 0", same query size but can return quite different results. – davidp_1978 Sep 15 '20 at 07:39