How to debug query

  • I have a query that used to work fine (last week), but now runs forever. It is a massive query with many sub-queries, but it was running in a few seconds. I know I could run each subquery one at a time to identify the bad one, but is there a way to use SSMS to tell me where the query is running so long? I popped up the execution plan. It's large and difficult to understand for me. It does show me a line as follows. Is it possible this is my problem? Is there a way to do further investigation?

    I would post the query, but it's 50 lines long, using 20+ tables and views. It basically summarizes the whole system into a flat row for reporting purposes.

    /*

    Missing Index Details from SQLQuery9.sql - MTXXXXXXXX(xxxx)

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

    */

    /*

    USE [CPAS]

    GO

    CREATE NONCLUSTERED INDEX [<Name of Missing Index, sysname,>]

    ON [dbo].[AllLaborInput] ([VENDOR NAME])

    INCLUDE ([SITE],[PROJ #],[START DATE],[WORKER NO],[REG HRS],[OT HRS],[LINE COST])

    GO

    */

    Jim

  • You could try adding that index but often the suggestions for missing indexes are actually worse. I have very often seen that adding the suggested indexes actually slows down the query.

    There could be any number of things that are causing it slow down now when it didn't in the past. Stale statistics, parameter sniffing, fragmented indexes, etc etc etc....

    If you could post the actual execution plan we can take a look and see what is going on there.

    _______________________________________________________________

    Need help? Help us help you.

    Read the article at http://www.sqlservercentral.com/articles/Best+Practices/61537/ for best practices on asking questions.

    Need to split a string? Try Jeff Modens splitter http://www.sqlservercentral.com/articles/Tally+Table/72993/.

    Cross Tabs and Pivots, Part 1 – Converting Rows to Columns - http://www.sqlservercentral.com/articles/T-SQL/63681/
    Cross Tabs and Pivots, Part 2 - Dynamic Cross Tabs - http://www.sqlservercentral.com/articles/Crosstab/65048/
    Understanding and Using APPLY (Part 1) - http://www.sqlservercentral.com/articles/APPLY/69953/
    Understanding and Using APPLY (Part 2) - http://www.sqlservercentral.com/articles/APPLY/69954/

  • OK, here's the query:

    SELECT

    PR.ProjectNbr

    , PR.ProjectDescription

    , PR.CapitalExpense

    , PR.ProjectCoord

    , PR.ProjectEngineer

    , PR.ProjectSuper

    , PR.ToolOwner

    , PR.CERID

    , PR.ProjectStatus

    , PR.ProjectScope

    , PR.ProjectBudget

    , PR.ProjectForecast

    , PR.MICAPID

    , PR.ProjectPercentComplete

    , PR.ProjectPerceontCompleteDate

    , PR.ProjectNotes

    , PR.ProjectCostCenter

    , PR.ProjectCreationDate

    , PR.ProjectScenarioID

    , dbo.tblProjectStatus.StatusDescription

    , dbo.tblScope.ScopeDescription

    , SA.RegHrs

    , SA.OTHrs

    , SA.PremHrs

    , SA.SAMiscCosts

    , SA.StaffAugSpend

    , SA.FirstWork

    , SA.LatestWork

    , dbo.qryPOSpendbyProjectID.POCommittedAmt

    , dbo.qryPOSpendbyProjectID.POPaidAmt

    , dbo.qryMatReqIssuesPCardbyProjectID.MATREQIssues

    , dbo.qryMatReqIssuesPCardbyProjectID.PCardAmt

    , dbo.qryIntLaborSpendbyProjectID.ILStdHrs

    , dbo.qryIntLaborSpendbyProjectID.ILOvtHrs

    , dbo.qryIntLaborSpendbyProjectID.InternalLaborCost

    , dbo.qryIntLaborSpendbyProjectID.ILRecordCount

    , dbo.qryCPBudgetSumProject.SumOfCPTransAmount

    , dbo.qryInventorySpendbyProject.[Inventory Used]

    ,

    ISNULL(SA.SAMiscCosts, 0)

    + ISNULL(dbo.qryInventorySpendbyProject.[Inventory Used], 0)

    + ISNULL(SA.StaffAugSpend, 0)

    + ISNULL(dbo.qryPOSpendbyProjectID.POCommittedAmt, 0)

    + ISNULL(dbo.qryMatReqIssuesPCardbyProjectID.MATREQIssues, 0)

    + ISNULL(dbo.qryMatReqIssuesPCardbyProjectID.PCardAmt, 0)

    + ISNULL(dbo.qryIntLaborSpendbyProjectID.InternalLaborCost, 0)AS

    TotalSpend

    , PR.ID AS ProjectID

    , dbo.tblCER.CERNbr

    , dbo.qrySumSCRbyProject.SCRTotSpend

    , dbo.qryRFICostbyProject.ProjRFICost

    ,

    PR.ProjectBudget

    - (

    ISNULL(SA.SAMiscCosts, 0)

    + ISNULL(dbo.qryInventorySpendbyProject.[Inventory Used], 0)

    + ISNULL(SA.StaffAugSpend, 0)

    + ISNULL(dbo.qryPOSpendbyProjectID.POCommittedAmt, 0)

    + ISNULL(dbo.qryMatReqIssuesPCardbyProjectID.MATREQIssues, 0)

    + ISNULL(dbo.qryMatReqIssuesPCardbyProjectID.PCardAmt, 0)

    + ISNULL(dbo.qryIntLaborSpendbyProjectID.InternalLaborCost, 0))AS

    BudgetVariance

    ,

    PR.ProjectForecast

    - (

    ISNULL(SA.SAMiscCosts, 0)

    + ISNULL(dbo.qryInventorySpendbyProject.[Inventory Used], 0)

    + ISNULL(SA.StaffAugSpend, 0)

    + ISNULL(dbo.qryPOSpendbyProjectID.POCommittedAmt, 0)

    + ISNULL(dbo.qryMatReqIssuesPCardbyProjectID.MATREQIssues, 0)

    + ISNULL(dbo.qryMatReqIssuesPCardbyProjectID.PCardAmt, 0)

    + ISNULL(dbo.qryIntLaborSpendbyProjectID.InternalLaborCost, 0))AS

    ForecastVariance

    , dbo.fnNumericProjectNbr(projectnbr)AS NumericProject

    , dbo.qryBAMaxODD.MaxOfODD AS ODD

    , dbo.qryBAMaxODD.MaxOfCCD AS CCD

    , dbo.qryOrigBudgetbyProjectID.OriginalBudget

    FROM

    dbo.tblScope INNER JOIN

    dbo.tblProjectStatus INNER JOIN

    dbo.tblCER RIGHT OUTER JOIN

    dbo.tblProjects PR LEFT OUTER JOIN dbo.

    qryStaffAugAllHrsSpendbyProjectID SA

    ON PR.ID = SA.ProjectID

    LEFT OUTER JOIN dbo.qryPOSpendbyProjectID

    ON PR.ID = dbo.qryPOSpendbyProjectID.

    ProjectID

    LEFT OUTER JOIN dbo.qryMatReqIssuesPCardbyProjectID

    ON PR.ID = dbo.

    qryMatReqIssuesPCardbyProjectID.ProjectID

    LEFT OUTER JOIN dbo.qryIntLaborSpendbyProjectID

    ON PR.ID = dbo.

    qryIntLaborSpendbyProjectID.ProjectID

    LEFT OUTER JOIN dbo.qryCPBudgetSumProject

    ON PR.ID = dbo.qryCPBudgetSumProject.

    CPProjectID

    LEFT OUTER JOIN dbo.qryInventorySpendbyProject

    ON PR.ID = dbo.

    qryInventorySpendbyProject.ProjectID

    LEFT OUTER JOIN dbo.qryRFICostbyProject

    ON PR.ID = dbo.qryRFICostbyProject.

    ProjectID

    LEFT OUTER JOIN dbo.qrySumSCRbyProject

    ON PR.ID = dbo.qrySumSCRbyProject.

    SCRProjectID

    LEFT OUTER JOIN dbo.qryBAMaxODD

    ON PR.ID = dbo.qryBAMaxODD.MaxOfODD

    ON dbo.tblCER.CERID = PR.CERID

    ON dbo.tblProjectStatus.StatusID = PR.ProjectStatus

    ON dbo.tblScope.ScopeID = PR.ProjectScope

    LEFT OUTER JOIN dbo.qryOrigBudgetbyProjectID

    ON PR.ID = dbo.qryOrigBudgetbyProjectID.

    CPProjectID

    WHERE PR.ProjectStatus = 1;

    Attached is the execution plan.

    Jim

  • OK, I ran the query on a "shadow" database (to avoid impacting my online users...) and it ran correctly and in five seconds. So, there must be some other issue. My users are live now, and seem to be having few issues. Assuming I've got a corrupted index or something, what should I try first (after kicking them off for the day...)? I keep 20 daily backuips, and I reorganize and truncate each night. It's a small standalone DB, and not used at night.

    What's the strategy?

    (PS...shadow db is a "detach and copy" of the main db. I made it yesterday...)

    Jim

  • Run against your shadow copy, not production:

    DBCC CHECKDB database_name WITH ALL_ERRORMSGS, NO_INFOMSGS

    If it returns errors, post all of it (you can put it in a text file and attach that).

  • My backup failed last night. I can't decipher the log message. Can you help? Seems to be the Master DB.

    essage

    Executed as user: WINNTDOM\sqlserveragent. ...2100.60 for 32-bit Copyright (C) Microsoft Corporation. All rights reserved. Started: 4:00:00 AM Progress: 2013-05-09 04:00:10.36 Source: {40948405-70AB-443C-A4F9-54C9B71A0BAE} Executing query "DECLARE @GUID UNIQUEIDENTIFIER EXECUTE msdb..sp...".: 100% complete End Progress Progress: 2013-05-09 04:00:12.71 Source: Back Up Database (Transaction Log) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 25% complete End Progress Progress: 2013-05-09 04:00:12.71 Source: Back Up Database (Transaction Log) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 50% complete End Progress Progress: 2013-05-09 04:00:12.72 Source: Back Up Database (Transaction Log) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 75% complete End Progress Progress: 2013-05-09 04:00:12.73 Source: Back Up Database (Transaction Log) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 100% complete End Progress Progress: 2013-05-09 04:00:49.90 Source: Back Up Database (Transaction Log) Executing query "BACKUP LOG [CPASD] TO DISK = N'D:\Data\MSSQL.1\MS...".: 50% complete End Progress Progress: 2013-05-09 04:01:03.00 Source: Back Up Database (Transaction Log) Executing query "declare @backupSetId as int select @backupSetId =...".: 100% complete End Progress Progress: 2013-05-09 04:01:03.13 Source: Back Up Database (Transaction Log) Executing query "BACKUP LOG [AssetLending] TO DISK = N'D:\Data\MSS...".: 50% complete End Progress Progress: 2013-05-09 04:01:03.17 Source: Back Up Database (Transaction Log) Executing query "declare @backupSetId as int select @backupSetId =...".: 100% complete End Progress Progress: 2013-05-09 04:01:03.29 Source: Back Up Database (Transaction Log) Executing query "BACKUP LOG [Sharp] TO DISK = N'D:\Data\MSSQL.1\MS...".: 50% complete End Progress Progress: 2013-05-09 04:01:03.33 Source: Back Up Database (Transaction Log) Executing query "declare @backupSetId as int select @backupSetId =...".: 100% complete End Progress Progress: 2013-05-09 04:01:31.85 Source: Back Up Database (Transaction Log) Executing query "BACKUP LOG [CPAS] TO DISK = N'D:\Data\MSSQL.1\MSS...".: 50% complete End Progress Progress: 2013-05-09 04:01:43.48 Source: Back Up Database (Transaction Log) Executing query "declare @backupSetId as int select @backupSetId =...".: 100% complete End Progress Progress: 2013-05-09 04:01:43.60 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 14% complete End Progress Progress: 2013-05-09 04:01:43.60 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 28% complete End Progress Progress: 2013-05-09 04:01:43.60 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 42% complete End Progress Progress: 2013-05-09 04:01:43.61 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 57% complete End Progress Progress: 2013-05-09 04:01:43.61 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 71% complete End Progress Progress: 2013-05-09 04:01:43.61 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 85% complete End Progress Progress: 2013-05-09 04:01:43.61 Source: Back Up Database (Full) Executing query "EXECUTE master.dbo.xp_create_subdir N'D:\Data\MSSQ...".: 100% complete End Progress Progress: 2013-05-09 04:01:44.41 Source: Back Up Database (Full) Executing query "BACKUP DATABASE [master] TO DIS... The package execution fa... The step failed.

    Jim

  • No useful information in that.

    Edit the job, go to the job step, the advanced tab and configure an output file. If the job fails again, look in the output file for the complete output, the error will likely be at the end of the complete output (which is truncated in the job history and hence useless)

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • As for your performance problem (and please in future post different questions in different threads), can you please post the actual execution plan. What you posted was an estimated and that's missing critical information

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Capture.png shows the failed Backup plan.

    DBCC Checkdb, etc fails "Incorrect Syntax near " my database name (I substituted the name...CPASD)

    "Incorrect syntax near the keyword 'with'. If this statement is a common table expression, an xmlnamespaces clause or a change tracking context clause, the previous statement must be terminated with a semicolon."

    I'm working on the rest.

    Here's the log file from the failed package:

    Microsoft (R) SQL Server Execute Package Utility

    Version 11.0.2100.60 for 32-bit

    Copyright (C) Microsoft Corporation. All rights reserved.

    Started: 2:48:16 PM

    Error: 2013-05-09 14:48:30.59

    Code: 0xC002F210

    Source: Back Up Database (Transaction Log) Execute SQL Task

    Description: Executing the query "BACKUP LOG [CPAS] TO DISK = N'D:\Data\MSSQL.1\MSS..." failed with the following error: "Database 'CPAS' is already open and can only have one user at a time.

    BACKUP LOG is terminating abnormally.". Possible failure reasons: Problems with the query, "ResultSet" property not set correctly, parameters not set correctly, or connection not established correctly.

    End Error

    Error: 2013-05-09 14:50:31.92

    Code: 0xC002F210

    Source: Back Up Database (Full) Execute SQL Task

    Description: Executing the query "BACKUP DATABASE [CPAS] TO DISK = N'D:\Data\MSSQL...." failed with the following error: "Database 'CPAS' is already open and can only have one user at a time.

    BACKUP DATABASE is terminating abnormally.". Possible failure reasons: Problems with the query, "ResultSet" property not set correctly, parameters not set correctly, or connection not established correctly.

    End Error

    Error: 2013-05-09 14:50:40.63

    Code: 0xC0024104

    Source: Reorganize Index

    Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter.

    End Error

    Error: 2013-05-09 14:50:53.03

    Code: 0xC0024104

    Source: Update Statistics

    Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter.

    End Error

    DTExec: The package execution returned DTSER_FAILURE (1).

    Started: 2:48:16 PM

    Finished: 2:50:53 PM

    Elapsed: 156.157 seconds

    OK, I'm an idiot. I'll reset it to multi-user and try again. Sorry

    Jim

  • Description: Executing the query "BACKUP DATABASE [CPAS] TO DISK = N'D:\Data\MSSQL...." failed with the following error: "Database 'CPAS' is already open and can only have one user at a time.

    The database CPAS is in single user mode. Switch it back to multi-user unless there's some specific reason it should be in single user. If it should be in single user mode then you must expect that backups will fail if there's already someone using that database.

    What was the exact checkDB command that you ran?

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • I apologize to all for my poor forum etiquette. I thought my problem was T-SQL related. I was wrong, and my query's poor performance seems to have a DB issue.

    ...I put CPAS into single-user mode to lock out users. I've put it back in multi-user mode and rerun the backup. It's running now.

    ...Even though CPAS could not back up, the error file does seem to show problems with indexes. How do I rebuild all the indexes?

    ...The backup job just finished normally, and the "long-running query" ran in 4 seconds. Back to normal.

    ...My backup job does reorganize the indexes, so maybe that fixed it. I dunno.

    I really appreciate everyone's time and attention. Again, I apologize for the "dual-threaded" post. It was not meant to be that way.

    Jim

  • I apologize for my "dual-threaded" post. What I thought was a T-SQL error appears to have been corrupted indices or some other odd corruption.

    ...I ran the backup plan once again (with the db back in multi-user mode...) and it worked. I'm not sure why. In any case, the offending query now runs in 4 seconds (has to go through a couple million rows...) and the users' report pops up even faster. So, problem solved.

    I want to thank all of you for helping me. I admit to some panic, but I do have lots of backups, so it wouldn't have been too bad, and I learned something.

    If anyone wants to review my backup plan (capture.png) and criticize it, I'd be grateful. If not, thanks anyway!

    Again, thank you all for the help. Oops....didn't realize I'd posted twice. Sorry

    Jim

  • JimS-Indy (5/9/2013)


    ...Even though CPAS could not back up, the error file does seem to show problems with indexes. How do I rebuild all the indexes?

    What error shows problems with the indexes?

    If you mean

    Source: Reorganize Index

    Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter.

    that would be the same cause as the backups failing, specifically that the DB was in single user mode and there was already an open connection to the database, hence the rebuild failed because it could not connect to the database.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Gail, I don't know what the problem was. It seems to have gone away when I ran the backup successfully. As I said, that step includes a "reorganize index" step, so maybe that fixed the indexes. The error file had:

    Error: 2013-05-09 14:50:40.63

    Code: 0xC0024104

    Source: Reorganize Index

    Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter.

    End Error

    Which I (not knowing what I'm looking at...) interpreted as a separate error.

    Jim

  • That would have been caused by exactly the same thing that caused the backups to fail, the database being in single-user mode and an existing connection to the database, hence the reorganise would not have been able to connect and would have failed.

    Once you switched out of single-user mode, the backups and reorganise could run successfully.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass

Viewing 15 posts - 1 through 14 (of 14 total)

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