13

One way to determine the executing stored procedure is to use "dynamic management" methods, like so:

SELECT 
    sqlText.Text, req.* 
FROM 
    sys.dm_exec_requests req
OUTER APPLY 
    sys.dm_exec_sql_text(req.sql_handle) AS sqltext

However, this only displays the text of the stored procedure's create statement. e.g.:

CREATE PROCEDURE IMaProcedure @id int AS SELECT * FROM AllTheThings Where id = @id

Ideally I'd like to see what the parameters were for the running procedure that are causing it to run so long for the particular set of offending parameters.

Is there a way to do that? (In this question Aaron Bertrand mentions DBCC InputBuffer, but I don't think that's appropriate for this problem.)

  • Really the only way to capture the input parameters or see what was passed in at run time is to log the values and the call to a log file. You can do this easily with RAISEERROR if you want to see it in the error log or with a little more effort, write it out to an external file somewhere. – Steve Mangiameli Jun 28 '16 at 17:39
16

This information -- run-time parameter values passed into a Stored Procedure (i.e. RPC call) or parameterized query -- is only available via a SQL Trace (and I assume the equivalent Extended Event in the newer versions of SQL Server). You can see this by running SQL Server Profiler (it comes with SQL Server) and selecting the various "Completed" events, such as: RPC:Completed, SP:Completed, and SQL:BatchCompleted. You also need to select the "TextData" field as the values will be in there.

The difference between my answer and @Kin's answer on this Question is that @Kin's answer (unless I am mistaken, in which case I will remove this) focuses on getting either:

  • your own query plan (in which case it can have the runtime parameter info in it, but not for other Sessions/SPIDs), or
  • plans from the DMVs (in which case they should only have the compiled parameter values, which are not runtime values).

My answer focuses on getting the parameter values for other sessions that are currently running. When relying on the DMVs, there is no way to know if the runtime parameter value is the same as the compiled parameter value. And the context of this question is tracking down the runtime value of queries being submitted via other Sessions/SPIDs (and in SQL Server 2005, whereas Extended Events were introduced in SQL Server 2008).

13

You can turn on the actual execution plan and then look at the execution plan XML.

enter image description here

Or you can use sql sentry's plan explorer tool and see the parameters tab that will list the compiled value and run time value for actual execution plan.

If you cannot turn on the actual plan then you can look into plan cache as described below.

-- borrowed from  Erland Sommarskog
-- Link : http://www.sommarskog.se/query-plan-mysteries.html#dmvgettingplans
-- Remember that you are looking at the estimated plan so the actual no. of rows and actual executions wont be there ! <-- Important why a particular plan is bad.

DECLARE @dbname    nvarchar(256),
        @procname  nvarchar(256)
SELECT @dbname = 'Northwind',  -- Your DB name
       @procname = 'dbo.List_orders_11' -- The SP that you want to get parameters for !

; WITH basedata AS (
   SELECT qs.statement_start_offset/2 AS stmt_start,
          qs.statement_end_offset/2 AS stmt_end,
          est.encrypted AS isencrypted, est.text AS sqltext,
          epa.value AS set_options, qp.query_plan,
          charindex('<ParameterList>', qp.query_plan) + len('<ParameterList>')
             AS paramstart,
          charindex('</ParameterList>', qp.query_plan) AS paramend
   FROM   sys.dm_exec_query_stats qs
   CROSS  APPLY sys.dm_exec_sql_text(qs.sql_handle) est
   CROSS  APPLY sys.dm_exec_text_query_plan(qs.plan_handle,
                                            qs.statement_start_offset,
                                            qs.statement_end_offset) qp
   CROSS  APPLY sys.dm_exec_plan_attributes(qs.plan_handle) epa
   WHERE  est.objectid  = object_id (@procname)
     AND  est.dbid      = db_id(@dbname)
     AND  epa.attribute = 'set_options'
), next_level AS (
   SELECT stmt_start, set_options, query_plan,
          CASE WHEN isencrypted = 1 THEN '-- ENCRYPTED'
               WHEN stmt_start >= 0
               THEN substring(sqltext, stmt_start + 1,
                              CASE stmt_end
                                   WHEN 0 THEN datalength(sqltext)
                                   ELSE stmt_end - stmt_start + 1
                              END)
          END AS Statement,
          CASE WHEN paramend > paramstart
               THEN CAST (substring(query_plan, paramstart,
                                   paramend - paramstart) AS xml)
          END AS params
   FROM   basedata
)
SELECT set_options AS [SET], n.stmt_start AS Pos, n.Statement,
       CR.c.value('@Column', 'nvarchar(128)') AS Parameter,
       CR.c.value('@ParameterCompiledValue', 'nvarchar(128)') AS [Sniffed Value],
       CAST (query_plan AS xml) AS [Query plan]
FROM   next_level n
CROSS  APPLY   n.params.nodes('ColumnReference') AS CR(c)
ORDER  BY n.set_options, n.stmt_start, Parameter
  • 5
    The plan cache only has the compiled values rather than the values for a specific run later. Could also use Showplan XML Statistics Profile event in Profiler to get the actual plan though if wheeling out Profiler there would be less intensive ways of getting this. – Martin Smith Jun 28 '16 at 19:08
1

@SolomonRutzky is right.
SQL Profiler Trace is the only way (without editing the Sproc).

Edit Your Sproc:

However, the next best thing is to slightly edit the Sproc in question.
Declare a DateTime variable at the beginning with the Current Time.
At the End of the Sproc, Log the Sproc_StartTime, Sproc_EndTime, and Parameter Values to a Table.

You could even add some conditional logic to use a DateDiff() for only logging when an extended amount of time was used in processing the Sproc.
This may Speed up your Sproc and reduce the Space Consumption of your Log Table for when the Sproc is running tip-top.

Then you have a Log File you may query and analyze over months (without a Trace running in Prod).
When you are done tuning your Sproc, just delete the few lines of Timer and Logger logic you added.

Cached-Plan Parameter Values:

I should mention that including the Current Cached-Plan Parameter Values in your Log Table may help you determine if they are compounding the performance issue.
I use OPTIMIZE FOR to set how to handle Parameters in my Sproc when I know it will be used for slicing and dicing data.
I find that using OPTIMIZE FOR yields consistent and fast results when using the same Sproc with Parameters as Optional Filters.
It's definitely one less variable to consider if you specify how to handle them.

Below is an example of what you might add to the bottom of your Select-Statement:

OPTION(OPTIMIZE FOR (@SiteID = 'ABC',
                     @LocationID = NULL, @DepartmentID = NULL,
                     @EmployeeID = NULL, @CustomerID = NULL,
                     @ProductID = NULL, @OrderID = NULL, @OrderStatusID = NULL,
                     @IncludedCancelledOrders = 1,
                     @StartDate UNKNOWN, @EndDate UNKNOWN))
0

I noticed when using Erland Sommarskog's query to shred plan XML and pull out ParameterCompiledValue that the first "basedata" CTE does not account for plans which have WARNINGS (e.g. implicit conversions) as the CHARINDEX (built-in function) looks for first expression matching string input (i.e. ) and such warnings use these same phrases/nodes.

I therefore propose replacing this section with the revised section below:

      CHARINDEX('<ParameterList>', qp.query_plan) + LEN('<ParameterList>') AS paramstart,
      CHARINDEX('</ParameterList>', qp.query_plan) AS paramend

Revised Section:

       CHARINDEX('<ParameterList><ColumnReference', qp.query_plan) + LEN('<ParameterList>') AS paramstart,
       CHARINDEX('</ParameterList></QueryPlan>', qp.query_plan) AS paramend
  • Disallowed implicit conversion from data type xml to data type varchar, table 'sys.dm_exec_query_plan', column 'query_plan'. Use the CONVERT function to run this query. – Matt Mar 26 '19 at 18:24
-1
SELECT DB_NAME(req.database_id),
sqltext.TEXT,
req.session_id,
req.status,
req.start_time,
req.command,
req.cpu_time,
req.total_elapsed_time ,   REPLACE(REPLACE(REPLACE(REPLACE(
CONVERT(VARCHAR(MAX), CONVERT(XML, REPLACE( query_plan, 'xmlns="','xmlns1="')).query('//        ParameterList/ColumnReference')),
'<ColumnReference Column="','declare '),
'" ParameterDataType="',' '),
'" ParameterCompiledValue="(',' = '),
')"/>', CONCAT(';', CHAR(10) , CHAR(13))) ParameterList
FROM sys.dm_exec_requests req
CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS sqltext 
 CROSS  APPLY sys.dm_exec_text_query_plan(plan_handle, statement_start_offset, statement_end_offset) qp
order by req.total_elapsed_time desc 
  • 2
    Code only answers are discouraged. Consider adding an explanation of why this code solves a problem. See How to Answer – Peter Vandivier Nov 29 '19 at 7:19

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.