Poor database queries

  1. 8 weeks ago

    Neil B

    Oct 22 Pre-Release Testers

    Our POS is very good overall but there is one utility that is very painful to use. One particular weekly EDI price update, takes 26 minutes to load, This is after the EDI data has been already downloaded and stored in the DB. We'll I finally wrote my own app to replace that and wow my app can do the same thing in 20ms.
    It's a local MS SQL Server database with Gigabit Ethernet.

    Any speculation what the app could possibly be doing that could take 26 minutes of 'Not Responding'? This seems to be 'off the charts' for bad performance.

    OK this query gets me all the info I need. It shows the last 1,000 queries, how long they took, and the full sql statement text.

    This is exactly what I needed to figured it all out! No more speculation needed.

    SELECT TOP 1000 * FROM(SELECT COALESCE(OBJECT_NAME(s2.objectid),'Ad-Hoc') AS ProcName, last_execution_time, execution_count, last_elapsed_time/1000 as last_elapsed_time_in_ms,s2.objectid,
      
        (SELECT TOP 1 SUBSTRING(s2.TEXT,statement_start_offset / 2+1 ,
          ( (CASE WHEN statement_end_offset = -1
      THEN (LEN(CONVERT(NVARCHAR(MAX),s2.TEXT)) * 2)
    ELSE statement_end_offset END)- statement_start_offset) / 2+1)) AS sql_statement
           
    FROM sys.dm_exec_query_stats AS s1
    CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS s2 ) x
    WHERE sql_statement NOT like 'SELECT TOP 50 * FROM(SELECT %'
    --and OBJECTPROPERTYEX(x.objectid,'IsProcedure') = 1
    ORDER BY last_execution_time DESC
  2. Kem T

    Oct 22 Pre-Release Testers, Xojo Pro, XDC Speakers New York

    Can you log the queries?

  3. Neil B

    Oct 22 Pre-Release Testers

    How would I do that? I didn't build the POS app, and have limited access to the DB.

  4. Kevin J

    Oct 22 Pre-Release Testers Georgia, USA

    I've seen similar queries. One of our vendors provided us with a stored procedure. They had one singular massive process. But when you looked closer and if you picked it apart, it forced a table scan. Basically, it executed an operation for each row on the table. This process took over 56 minutes.

    I picked it apart and split that singular process into 7 distinct queries, and a concluding UPDATE statement. This process took 11 seconds.

    "Take out the slow parts." - Some DBA someplace. Probably.

  5. Neil B

    Oct 22 Pre-Release Testers

    @Kem T Can you log the queries?

    OK I'm working on that now with the help of this: https://stackoverflow.com/questions/3579092/tsql-get-last-queries-ran
    I had no idea that feature was available.

  6. James D

    Oct 22 Pre-Release Testers Europe (Switzerland)

    Start by ensuring that the statistics are up to date https://docs.microsoft.com/en-us/sql/t-sql/statements/update-statistics-transact-sql?view=sql-server-2017

    Next generate the execution plans to see how the queries are running https://docs.microsoft.com/en-us/sql/relational-databases/performance/display-an-actual-execution-plan?view=sql-server-2017

  7. Neil B

    Oct 22 Pre-Release Testers Answer

    OK this query gets me all the info I need. It shows the last 1,000 queries, how long they took, and the full sql statement text.

    This is exactly what I needed to figured it all out! No more speculation needed.

    SELECT TOP 1000 * FROM(SELECT COALESCE(OBJECT_NAME(s2.objectid),'Ad-Hoc') AS ProcName, last_execution_time, execution_count, last_elapsed_time/1000 as last_elapsed_time_in_ms,s2.objectid,
      
        (SELECT TOP 1 SUBSTRING(s2.TEXT,statement_start_offset / 2+1 ,
          ( (CASE WHEN statement_end_offset = -1
      THEN (LEN(CONVERT(NVARCHAR(MAX),s2.TEXT)) * 2)
    ELSE statement_end_offset END)- statement_start_offset) / 2+1)) AS sql_statement
           
    FROM sys.dm_exec_query_stats AS s1
    CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS s2 ) x
    WHERE sql_statement NOT like 'SELECT TOP 50 * FROM(SELECT %'
    --and OBJECTPROPERTYEX(x.objectid,'IsProcedure') = 1
    ORDER BY last_execution_time DESC
  8. Julian S

    Oct 22 Pre-Release Testers, Xojo Pro UK

    Could you not just trace it using SQL Server Profiler and see what's happening and how long things are taking in real time?

  9. Neil B

    Oct 22 Pre-Release Testers

    Sounds like a good idea providing I knew such a thing existed, and how to do it :)

  10. Julian S

    Oct 22 Pre-Release Testers, Xojo Pro UK
    Edited 8 weeks ago

    Visit https://docs.microsoft.com/en-us/sql/ssms/download-sql-server-management-studio-ssms?view=sql-server-2017 download and install SQL Server Management Studio.

    Run SQL Server Profiler 17, File>New Trace>Connect>Run

    If you need more deeets see youtoobes, plenty of vids on there ranging in difficulty and features covered :)

  11. Neil B

    Oct 22 Pre-Release Testers

    I figured...

    ERROR:
    In order to run a trace against SQL Server you must be a member of sysadmin fixed server role or have the ALTER TRACE permission.

  12. Neil B

    Oct 22 Pre-Release Testers

    Unbelievable. I was able to get the list of queries that is executed. The reason the load times got exponentially longer is because several separate queries are created for each item to be loaded. No really good part (bad actually) is that each and every one of these queries included a where clause like this:

    WHERE (InventoryStore.Item IN ( list of 2000 items ) 

    That explains why a list of 50 items loaded instantly but 2000 items took forever!

  13. James D

    Oct 22 Pre-Release Testers Europe (Switzerland)
    Edited 8 weeks ago

    Your query is of historical interest only, it does not tell you the state of the statistics, which is very important in determining the execution plan for a query nor does it show the query was executed and at what cost.

    For instance if the statistics have not been properly updated you will most likely get a different exemption plan than in a case where they are correctly updated.

    Likewise 2000 items in a where clause is peanuts to SQL Server if it is executed in memory rather than from disk or if it is able to choose a good index. This something you can only find out from an execution plan. Furthermore since this is an update/insert query the issue may have nothing at all to do with the where clause.

    If you don’t have the rights to do this, ask a DBA to get you the information.

  14. 7 weeks ago

    Neil B

    Oct 23 Pre-Release Testers
    Edited 7 weeks ago

    @James D Your query is of historical interest only,

    And that happens to be exactly what I need in this case.

    1. Where talking strictly select statements in this case. No Insert or Update.
    2. My query above show all queries that were run against the DB giving full SQL text, as well as the elapsed time for each query.
    3. For the action in question I see 1754 SELECT queries there are really only 2 different select queries. Both the select queries have an in clause starting with 1076 items and increasing to 2056 items (the amount of items being loaded). The first items in the in clause are the same in all the selects with more items being appended to the list with each query.

    So this does give me some important information.

    1. There is a flaw in the logic (which I already knew).
    2. All the info obtained could have be gotten in a single query with proper joins. A properly formed single query would have gotten the same info in well under a second, as opposed to 26 minutes.
    3. The info from the last 2 queries contained all of the information from all the other queries. So it's a silly waste of resources.
  15. Jean-Yves P

    Oct 23 Pre-Release Testers, Xojo Pro Europe (France, Besançon)

    @James D Likewise 2000 items in a where clause is peanuts to SQL Server if it is executed in memory rather than from disk or if it is able to choose a good index. This something you can only find out from an execution plan. Furthermore since this is an update/insert query the issue may have nothing at all to do with the where clause.

    I can confirm this. I use the WHERE...IN statement with far more than 2000 items, and it's still fast response.
    problem should be elsewhere.

  16. Neil B

    Oct 23 Pre-Release Testers

    The problem is not so much the 'where in', as the shear waste of resources. The queries are returning 255 columns. That along with the 1752 totally unneeded queries is the bulk of the problem. My point about the 'IN' clause though is that it's totally unneeded. Those values are coming from another tables so a simple join would do the same thing!

    The reason the load time gets exponentially longer as the number of items increases is because currently the entire list (num_items X 255 columns) is being returned twice for every item to be loaded.

  17. James D

    Oct 23 Pre-Release Testers Europe (Switzerland)

    @Neil B The problem is not so much the 'where in', as the shear waste of resources. The queries are returning 255 columns. That along with the 1752 totally unneeded queries is the bulk of the problem. My point about the 'IN' clause though is that it's totally unneeded. Those values are coming from another tables so a simple join would do the same thing!

    The reason the load time gets exponentially longer as the number of items increases is because currently the entire list (num_items X 255 columns) is being returned twice for every item to be loaded.

    Unless you have an actually execution plan for the query, it is just guess work as to what the cause actually is. But that is your decision.

  18. Neil B

    Oct 23 Pre-Release Testers

    What exactly would an execution plan help me in this situation? I've actually never used them.

    Here they are though. Maybe you can tell by looking at them.

    https://www.dropbox.com/s/be74egi3ncxpsbq/SQL%20and%20Execution%20Plan.zip?raw=1

  19. Neil B

    Oct 23 Pre-Release Testers

    OK after checking out the query plan I see a Const Scan cost 0%. That must be the IN clause. So apparently the IN clause really isn't taking much time.

    Here is the same thing with a join. https://www.dropbox.com/s/03sop7wpdytb8sq/SQL%20and%20Execution%20Plan2.zip?raw=1

    The scan to the PriceUpdatesUnapplied is 2% which equates to about 1ms. Still seems more efficient than getting the items for the in clause in a separate query and processing the in clause in code. Especially so because the initial query to populate the in clause is a Select * taking 48ms. If the query would have been Select ItemNumber, returning only one field it wouldn't have been quite as bad.

or Sign Up to reply!