SQL Server Puzzling Performance

  • Hi Guys,

    Been hanging around these forms for a very long time but never posted much. I am experiencing something that is very puzzling, I have a SQL Server 2012 running on Windows 2012 Standard 64bit in a virtualized environment. The Physical server has 24GB Ram and I have allocated 8 GB Ram to this VM. The other VMs on this server take up another 8GB of RAM.

    The puzzling thing is that there is a query that I run on this server and it take more than 4 mins to execute if the Max Memory setting of the SQL Server is set at any value over 3856 MB.

    When i set the Max memory setting to anything below this value the query executes in less than 2 secs. Have any of you ever expeirenced anything like this before and if so what is the cause of it and how can I fix it to enable me allocate more RAM to the server.

    I forgot to mention that this server is not running any other services.

    FK

    P.S. I can post the query if it is necessary.

  • Francis Kioko (10/24/2013)


    When i set the Max memory setting to anything below this value the query executes in less than 2 secs.

    i dont think reducing memory can boost the performance.

    the execution time in 4 min (with more mem) and 2 secs (with less memory) is it a regular pattern ? i doubt here though

    -------Bhuvnesh----------
    I work only to learn Sql Server...though my company pays me for getting their stuff done;-)

  • Hi

    It sounds crazy but it is very true. I have tried it in two separate environments i.e. another physical host using SQL Server 2012 and SQL Server 2008 and I get the same results. Below a certain MAX Memory threshold which varies from 4323 to 3856 the performance of the query increases exponentially from minutes (4 to 10 mins) to less than 4 secs. The query in question is below

    SELECT t11.DocNum, convert(nvarchar, t11.DocDate,103), t11.Filler as 'Origin W/H',

    t11.U_RecWshe as 'Final W/H', t12.ItemCode, t12.Dscription,

    (SELECT t13.ItmsGrpNam FROM OITB t13 , OITM t14 WHERE t13.ItmsGrpCod=t14.ItmsGrpCod and t14.ItemCode=t12.ItemCode) as 'Item Group', t12.Quantity

    FROM OWTR t11, WTR1 t12

    WHERE t11.DocEntry=t12.DocEntry and t11.DocNum in

    (SELECT t0.DocNum FROM OWTR t0 t0.U_TrnType=1 AND t0.DocDate<='2012/12/31' and t0.U_EType=0

    AND CONVERT(NVARCHAR, t0.DocNum) NOT IN

    (SELECT CONVERT(NVARCHAR,ISNULL(t11.U_TrnDocNo,'')) FROM OWTR t11))

    Has anyone ever encountered this?

    Basically when it takes 4 mins during that time the CPU usage shoots up to 100% for the entire time.

    Regards

    FK

    P.S. I have attached actual query execution plans.

  • Francis Kioko (10/24/2013)


    It sounds crazy but it is very true. I have tried it in two separate environments i.e. another physical host using SQL Server 2012 and SQL Server 2008 and I get the same results. Below a certain MAX Memory threshold which varies from 4323 to 3856 the performance of the query increases exponentially from minutes (4 to 10 mins) to less than 4 secs.

    can you also provide result of set stattics io on and set statistics cpu on from both environments(dont forget to remove exec plan selection )

    -------Bhuvnesh----------
    I work only to learn Sql Server...though my company pays me for getting their stuff done;-)

  • can you also provide result of set stattics io on and set statistics cpu on from both environments(dont forget to remove exec plan selection )

    Here are the results

    When the memory is reduced to below the threshold and the query executes in less than 2 seconds

    SQL Server parse and compile time:

    CPU time = 327 ms, elapsed time = 328 ms.

    SQL Server Execution Times:

    CPU time = 0 ms, elapsed time = 0 ms.

    (45 row(s) affected)

    Table 'OWTR'. Scan count 48, logical reads 54504, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'Worktable'. Scan count 83, logical reads 298, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'WTR1'. Scan count 38, logical reads 187, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'OITB'. Scan count 0, logical reads 72, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'OITM'. Scan count 0, logical reads 108, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    SQL Server Execution Times:

    CPU time = 594 ms, elapsed time = 415 ms.

    When i increase the max memory and the query runs for more than 4 mins these are the results

    SQL Server Execution Times:

    CPU time = 0 ms, elapsed time = 0 ms.

    (45 row(s) affected)

    Table 'OWTR'. Scan count 47, logical reads 233120944, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'WTR1'. Scan count 38, logical reads 187, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'Worktable'. Scan count 84, logical reads 300, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'OITB'. Scan count 0, logical reads 72, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'OITM'. Scan count 0, logical reads 108, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

    SQL Server Execution Times:

    CPU time = 1138776 ms, elapsed time = 292035 ms.

    The difference with in both results is that when the first query was run the max memory setting was set at 3856 and it took a couple of seconds to execute.

    When i increased the memory to 3857 the exact same query took almost 5 mins to execute.

    Regards

    FK

  • SscLover (10/25/2013)


    Since no one has replied on the topic, thats new thing to me that increasing the server memory causing bad plan for query,

    yes server memory is one of aspect which affect the execution plan

    but it should not go worse after increasing the memory,

    i request you please update the statistics with full table scan for all underlying tables affecting the query.

    All the perfect size bullets to hit the bird BUT here scenario is bit different . OP is using same server the only change which is occurring is "increasiing the memory" but server is SAME(or did i overlook some here?)?

    What strange thing here is performance is getign worst after addition of memory ?

    See the CPU and logical reads of first table from the last post of OP.

    -------Bhuvnesh----------
    I work only to learn Sql Server...though my company pays me for getting their stuff done;-)

  • Hi SSClover

    Your redesigned query is very good but unfortuantly it still runs slower. From what i can tell, it seems to be a problem with SQL Server Database Engine and not the query itself. Has anyone ever experienced this?

    Regards

    FK

  • Francis,

    Can ypu try one more thing ?

    start the profiler and look for "Sort Warning" option and see if its is coming when you execute the SP ? loo in both the cases .

    -------Bhuvnesh----------
    I work only to learn Sql Server...though my company pays me for getting their stuff done;-)

  • From what I can tell after a quick look, your issue is that with the lower memory setting SQL Server decides to do a hash match, whereas with more memory it correctly decides to do a nested loop. I suspect that your index is massively fragmented, so when it does the order for the nested loop it spills to disk which would consume a massive amount of CPU. I also dislike the amount of implicit conversions that are going on in your query, you're forcing the optimizer to do more work than is necessary.

    Really, you could do with Gail taking a look but with the amount of information you've added to this post, I think it's unlikely she'd stop by 😉

    A couple of bits of advice: -

    1. Have a read through this article (http://www.sqlservercentral.com/articles/SQLServerCentral/66909/) on how to post performance issues. It'll explain what information is required for people to help you.[/url]

    2. Formatting your code when posting it online is a godsend. What you've posted is a bit of a mess which makes it difficult to see what is going on. If we instead do it like this: -

    SELECT t11.DocNum,

    convert(NVARCHAR, t11.DocDate, 103),

    t11.Filler AS 'Origin W/H',

    t11.U_RecWshe AS 'Final W/H',

    t12.ItemCode,

    t12.Dscription,

    (SELECT t13.ItmsGrpNam

    FROM OITB t13, OITM t14

    WHERE t13.ItmsGrpCod = t14.ItmsGrpCod

    AND t14.ItemCode = t12.ItemCode) AS 'Item Group',

    t12.Quantity

    FROM OWTR t11, WTR1 t12

    WHERE t11.DocEntry = t12.DocEntry

    AND t11.DocNum IN (SELECT t0.DocNum

    FROM OWTR t0

    WHERE t0.U_TrnType = 1

    AND t0.DocDate <= '2012/12/31'

    AND t0.U_EType = 0

    AND CONVERT(NVARCHAR, t0.DocNum) NOT IN (SELECT CONVERT(NVARCHAR, ISNULL(t11.U_TrnDocNo, ''))

    FROM OWTR t11)

    );

    It becomes much more obvious what is going on.

    After formatting it, I'd immediately stop doing the old style joins that you have going on in your query and start using the "new" (the old style for outer joins was deprecated in SQL Server 2005).

    SELECT t11.DocNum,

    convert(NVARCHAR, t11.DocDate, 103),

    t11.Filler AS 'Origin W/H',

    t11.U_RecWshe AS 'Final W/H',

    t12.ItemCode,

    t12.Dscription,

    (SELECT t13.ItmsGrpNam

    FROM OITB t13, OITM t14

    WHERE t13.ItmsGrpCod = t14.ItmsGrpCod

    AND t14.ItemCode = t12.ItemCode) AS 'Item Group',

    t12.Quantity

    FROM OWTR t11

    INNER JOIN WTR1 t12 ON t11.DocEntry = t12.DocEntry

    WHERE t11.DocNum IN (SELECT t0.DocNum

    FROM OWTR t0

    WHERE t0.U_TrnType = 1

    AND t0.DocDate <= '2012/12/31'

    AND t0.U_EType = 0

    AND CONVERT(NVARCHAR, t0.DocNum) NOT IN (SELECT CONVERT(NVARCHAR, ISNULL(t11.U_TrnDocNo, ''))

    FROM OWTR t11)

    );

    The next thing I'd want to do is move the Item Group into an APPLY.

    SELECT t11.DocNum,

    convert(NVARCHAR, t11.DocDate, 103),

    t11.Filler AS 'Origin W/H',

    t11.U_RecWshe AS 'Final W/H',

    t12.ItemCode,

    t12.Dscription,

    oa.[Item Group],

    t12.Quantity

    FROM OWTR t11

    INNER JOIN WTR1 t12 ON t11.DocEntry = t12.DocEntry

    OUTER APPLY (SELECT t13.ItmsGrpNam

    FROM OITB t13

    INNER JOIN OITM t14 ON t13.ItmsGrpCod = t14.ItmsGrpCod

    WHERE t14.ItemCode = t12.ItemCode) oa([Item Group])

    WHERE t11.DocNum IN (SELECT t0.DocNum

    FROM OWTR t0

    WHERE t0.U_TrnType = 1

    AND t0.DocDate <= '2012/12/31'

    AND t0.U_EType = 0

    AND CONVERT(NVARCHAR, t0.DocNum) NOT IN (SELECT CONVERT(NVARCHAR, ISNULL(t11.U_TrnDocNo, ''))

    FROM OWTR t11)

    );

    Next, I'd get rid of the implicit conversions.

    SELECT t11.DocNum,

    convert(NVARCHAR, t11.DocDate, 103),

    t11.Filler AS 'Origin W/H',

    t11.U_RecWshe AS 'Final W/H',

    t12.ItemCode,

    t12.Dscription,

    oa.[Item Group],

    t12.Quantity

    FROM OWTR t11

    INNER JOIN WTR1 t12 ON t11.DocEntry = t12.DocEntry

    OUTER APPLY (SELECT t13.ItmsGrpNam

    FROM OITB t13

    INNER JOIN OITM t14 ON t13.ItmsGrpCod = t14.ItmsGrpCod

    WHERE t14.ItemCode = t12.ItemCode) oa([Item Group])

    WHERE t11.DocNum IN (SELECT CAST(t0.DocNum AS NVARCHAR(30))

    FROM OWTR t0

    WHERE t0.U_TrnType = '1'

    AND t0.DocDate <= '2012/12/31'

    AND t0.U_EType = '0'

    AND CONVERT(NVARCHAR, t0.DocNum) NOT IN (SELECT CONVERT(NVARCHAR, ISNULL(t11.U_TrnDocNo, ''))

    FROM OWTR t11)

    );

    I'd consider the following index: -

    /*

    The Query Processor estimates that implementing the following index could improve the query cost by 41.9829%.

    WARNING: This is only an estimate, and the Query Processor is making this recommendation based solely upon analysis

    of this specific query. It has not considered the resulting index size, or its workload-wide impact, including its

    impact on INSERT, UPDATE, DELETE performance. These factors should be taken into account before creating this index.

    */

    CREATE NONCLUSTERED INDEX [SQL_SERVER_SUGGESTED_INDEX] ON [dbo].[OWTR] ([DocDate]) INCLUDE ([DocNum],[U_TrnType],[U_EType]);


    Forever trying to learn
    My blog - http://www.cadavre.co.uk/
    For better, quicker answers on T-SQL questions, click on the following...http://www.sqlservercentral.com/articles/Best+Practices/61537/
    For better, quicker answers on SQL Server performance related questions, click on the following...http://www.sqlservercentral.com/articles/SQLServerCentral/66909/

  • Obviously, adding more memory results in a different, less efficient plan.

    Could you try what happens if you simulate even more memory, like let's say 16Gb.

    You can do this by using DBCC OPTIMIZER_WHATIF

    DBCC TRACEON(3604) WITH NO_INFOMSGS

    DBCC OPTIMIZER_WHATIF(MemoryMbs,16000) WITH NO_INFOMSGS;

    GO

    Run your Query now.

    For more info on this undocumented DBCC command see here:

    https://www.simple-talk.com/sql/database-administration/using-optimizer_whatif-and-statsstream-to-simulate-a-production-environment/

    [font="Verdana"]Markus Bohse[/font]

  • Worth reading here http://www.dbsophic.com/SQL-Server-Articles/sql-server-logical-reads-what-they-really-tell.html

    -------Bhuvnesh----------
    I work only to learn Sql Server...though my company pays me for getting their stuff done;-)

  • Hi Guys,

    I can say that after trying to resolve this issue by optimizing my code and checking my server configuration i ended up refering the issue to MS support and they found the solution in a couple of days. See below.

    Thank you guys for the time you put in to help out. Your the best

    Regards

    FK

    Hi Francis,

    I did some research on this issue and found that it’s not a very common behavior of optimizer but we see this often with specific queries.

    When optimizer compiles for a plan, various factors such as memory, CPU and cardinality are used to determine the most effective plan.

    There have been a few cases where inefficient query plan results from large amount of memory, though it is very rare.

    In these cases, what we experience is that if we reduce max server memory setting, the query runs faster.

    So, the issue faced by you is very much similar and the point where its suddenly changing the plan is something we refer as “Tipping point”.

    Recommendation:

    =================

    You can use trace flag 2335 to see if the problem is resolved.

    This trace flag 2335 assumes SQL Server only has 1GB of memory available for query execution, and uses this memory setting to generate the query plan.

    This will results in less memory intensive query plans such as nested loops.

    Note: Setting this trace flag only affects optimizer for plan generation. It does not limit SQL Server from using all available memory for data buffers, query executions, etc.

    We have a KB article http://support.microsoft.com/kb/2413549 documenting this.

    Please let me know if this helps in fixing the issue.

    Waiting for your findings so that we can move to next level of troubleshooting.

    This did not work until I added this other trace flag as per their email below.

    There is one more trace flag 4199 which is for implementing all optimizer fixes introduced so far.

    Could you please implement both these trace flags in your SQL server startup parameter and then restart the SQL server services.

    Please ensure that the trace flags are enabled from SQL server errorlog.

    Let me know how this go.

Viewing 12 posts - 1 through 11 (of 11 total)

You must be logged in to reply to this topic. Login to reply