Finding long-running stored procedures

This section describes how to identify long-running stored procedures using sysquerymetrics to track statement-level statistics for each line and statement within a procedure, including subprocedures. This may be useful for capturing the parameters that may be driving the optimization within the procedure. This section describes how to use sysquerymetrics to identify long-running stored procedures.

This feature is new in Adaptive Server 15.0, so you cannot use the steps below to compare queries from previous releases. Often a query runs slowly because of a query plan that changed during migration.

Before you use this method, consider the following:

• The result set may skip or repeat LineNumbers because of looping or if ...else statements in the query, so subprocedures that are inside loops that are inside procedures may have the same ContextIDs, but different StartTimes.

• If you performed the upgrade in place using dump and load or mount database, the objectIDs of the user objects within the database are identical but the DBIDs differ.

• You must aggregate values to get procedure-level statistics:

  The following is a single script, but has been divided into sections to describe the individual steps.

  1. Issue the following to aggregate to the individual procedure level for Adaptive Server 12.5:

     select DBID, ProcedureID, StartTime, EndTime=max(EndTime),
        ElapsedTime=datediff(ms,StartTime,max(EndTime))/1000.00,
        CPUTime=sum(CPUTime), WaitTime=sum(WaitTime),
        LogicalReads=sum(LogicalReads),PhysicalReads=sum(PhysicalReads),   PagesModified=sum(PagesModified)
     into #procExecs125
     from monSysStmt125
     group by DBID, ProcedureID, Starttime
     

  2. Issue the following to aggregate to the individual procedure level for Adaptive Server 15.0:

     select DBID, ProcedureID, StartTime, EndTime=max(EndTime),
        ElapsedTime=datediff(ms,StartTime,max(EndTime))/1000.00,
        CPUTime=sum(CPUTime), WaitTime=sum(WaitTime),
        LogicalReads=sum(LogicalReads), PhysicalReads=sum(PhysicalReads),
        PagesModified=sum(PagesModified)
     into #procExecs150
     from monSysStmt150
     group by DBID, ProcedureID, Starttime
     

  3. Because both of these queries occur at individual procedure execution level, issue the following to average the result set if you run these queries more than once:

     select DBID, ProcedureID, ExecCnt=count(*), ElapsedTime=avg(ElapsedTime),
        CPUTime=avg(CPUTime), WaitTime=avg(WaitTime),
        LogicalReads=avg(LogicalReads), PhysicalReads=avg(PhysicalReads),
        PagesModified=avg(PagesModified)
     into #procExecAvgs125
     from procExecs125
     group by DBID, ProcedureID
     

  4. To find the stored procedures that ran more slowly in the 15.0 server, issue:

     select o.name as 'ProcName', o.type, ExecCnt=t.ExecCnt,
     CPU_125=t.CPUTime, CPU_150=f.CPUTime, 
        WaitTime_125=t.WaitTime, WaitTime_150=f.WaitTime,
        LogicalIO_125=t.LogicalReads, LogicalIO_150=f.LogicalReads,
        PhysReads_125=t.PhysicalReads, PhysReads_150=f.PhysicalReads,
        Writes_125=t.PagesModified, Writes_150=f.PagesModified,
        Elapsed_125=t.ElapsedTime, Elapsed_150=f.ElapsedTime
     from #procExecAvgs125 t, #procExecAvgs150, <db>..sysobjects o
     where t.ProcedureID=o.id
     and t.ProcedureID=f.ProcedureID
     and t.ElapsedTime < f.ElapsedTime
     

     You can view the SQL text for the stored procedures that executed slowly by joining the result set from this query with monSysSQLText.

     Because a parameter set may skew the average of one of the executions, you can join the first aggregated table (#procExecs) with monSysSQLText and view the respective execution metrics for each version.

  5. Issue this query to find the stored procedures that ran faster on the 15.0 server:

     select o.name as 'ProcName', o.type, ExecCnt=t.ExecCnt,
        CPU_125=t.CPUTime, CPU_150=f.CPUTime, 
        WaitTime_125=t.WaitTime, WaitTime_150=f.WaitTime,
        LogicalIO_125=t.LogicalReads, LogicalIO_150=f.LogicalReads,
        PhysReads_125=t.PhysicalReads, PhysReads_150=f.PhysicalReads,
        Writes_125=t.PagesModified, Writes_150=f.PagesModified,
        Elapsed_125=t.ElapsedTime, Elapsed_150=f.ElapsedTime
     from #procExecs125 t, #procExecs150, <db>..sysobjects o
     where t.ProcedureID=o.id
       and t.ProcedureID=f.ProcedureID
       and t.ElapsedTime > f.ElapsedTime
     

The steps for finding long-running queries using sysquerymetrics are:

1. Configure statement pipe active, sql text pipe active, and statement plan text pipe for the 12.5 server.

2. Create a temporary table in tempdb for monSysStatement, monSysSQLtext and monSysPlanText by issuing something similar to:

   select * into tempdb..monSysStatement from master..monSysStatement where 1=2
   

3. Create a monitoring process that queries the monSysStatment, monSysSQLtext, and monSysPlanText tables once every minute and inserts the result set into the temporary tables you created in step 2. For example:

   insert into tempdb..monSysStatement (select * from master..monSysStatement)
   

   To run this once every minute, you can place the query in a loop with waitfor delay "00:01:00".

4. On the 12.5 server, execute one module of the application to be tested.

5. Stop the application and halt the monitoring.

6. Bulk-copy out the monitoring table information you collected data from tempdb.

7. Repeat steps 1 – 5 for the 15.0 server.

8. Create a set of tables in the test database named after the monitoring tables but include version information in their names. For example: monSysStmt125, monSysStmt150, and so on.

9. Load the tables you created in step 8 with the information you collected in step 3 (use either bcp or insert...select statements).

10. Create an index on the monSysStThree3Ducksmt125 and monSysStmt15 tables on the SPID, KPID, DBID, ProcedureID, BatchID, ContextID, LineNumber columns.

---

Copyright © 2006. Sybase Inc. All rights reserved.

View this book as PDF