%3CLINGO-SUB%20id%3D%22lingo-sub-1111086%22%20slang%3D%22en-US%22%3ELesson%20Learned%20%23119%3A%20What%20is%20the%20query%20that%20my%20stored%20procedure%20is%20running%20now%3F%3C%2FLINGO-SUB%3E%3CLINGO-BODY%20id%3D%22lingo-body-1111086%22%20slang%3D%22en-US%22%3E%3CP%3EToday%2C%20we%20have%20been%20working%20on%20a%20performance%20issue%20where%20our%20customer%20is%20running%20a%20stored%20procedure%20but%20we%20don't%20know%20exactly%20what%20is%20the%20part%20of%20this%20that%20is%20running.%26nbsp%3B%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%3ELet%20me%20show%20you%20an%20example%20how%20to%20obtain%20this%20information%3A%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CUL%3E%0A%3CLI%3E%3CSTRONG%3EWe%20have%20the%20following%20stored%20procedure%20definition%3A%26nbsp%3B%3C%2FSTRONG%3E%3C%2FLI%3E%0A%3C%2FUL%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%20style%3D%22padding-left%3A%2030px%3B%22%3ECREATE%20PROCEDURE%20WhereIsTheQueryIsRunningNow%3CBR%20%2F%3EAS%3CBR%20%2F%3EBEGIN%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BSELECT%201%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BSELECT%202%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3B%20%26nbsp%3B%20WAITFOR%20DELAY%20'00%3A00%3A03'%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BSELECT%203%3CBR%20%2F%3E%26nbsp%3B%20%26nbsp%3BSELECT%204%3CBR%20%2F%3EEND%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CUL%3E%0A%3CLI%3E%3CSTRONG%3EWe%20run%20this%20stored%20procedure%26nbsp%3BEXEC%20WhereIsTheQueryIsRunningNow%3C%2FSTRONG%3E%3C%2FLI%3E%0A%3C%2FUL%3E%0A%3CUL%3E%0A%3CLI%3E%3CSTRONG%3EEvery%20time%20that%20we%20run%20the%20following%20query%20we%20obtain%20that%20the%20stored%20procedure%20is%20running%20but%20we%20don't%20know%20what%20is%20the%20exact%20line%3A%26nbsp%3B%3C%2FSTRONG%3E%3C%2FLI%3E%0A%3C%2FUL%3E%0A%3CP%20style%3D%22padding-left%3A%2060px%3B%22%3ESELECT%20%3CBR%20%2F%3Ereq.session_id%3CBR%20%2F%3E%2C%20req.start_time%3CBR%20%2F%3E%2C%20cpu_time%20'cpu_time_ms'%3CBR%20%2F%3E%2C%20object_name(st.objectid%2Cst.dbid)%20'ObjectName'%20%3CBR%20%2F%3E%2C%20ST.text%3CBR%20%2F%3EFROM%20sys.dm_exec_requests%20AS%20req%20%3CBR%20%2F%3ECROSS%20APPLY%20sys.dm_exec_sql_text(req.sql_handle)%20as%20ST%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%20style%3D%22padding-left%3A%2060px%3B%22%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20style%3D%22width%3A%20602px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Fgxcuf89792.i.lithium.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F165533i3F6F475C661ADA4E%2Fimage-dimensions%2F602x98%3Fv%3D1.0%22%20width%3D%22602%22%20height%3D%2298%22%20alt%3D%22clipboard_image_0.png%22%20title%3D%22clipboard_image_0.png%22%20%2F%3E%3C%2FSPAN%3E%3C%2FP%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CUL%3E%0A%3CLI%3E%3CSTRONG%3EIf%20we%20modify%20the%20query%20and%20we%20use%20the%20statement%20start%20and%20end%20offset%20we%20could%20find%20the%20exact%20query%20that%20our%20stored%20procedure%20is%20running%20at%20this%20time.%26nbsp%3B%3C%2FSTRONG%3E%3C%2FLI%3E%0A%3C%2FUL%3E%0A%3CP%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%20style%3D%22padding-left%3A%2060px%3B%22%3ESELECT%20%3CBR%20%2F%3Ereq.session_id%3CBR%20%2F%3E%2C%20req.start_time%3CBR%20%2F%3E%2C%20cpu_time%20'cpu_time_ms'%3CBR%20%2F%3E%2C%20object_name(st.objectid%2Cst.dbid)%20'ObjectName'%20%3CBR%20%2F%3E%2C%20substring%3CBR%20%2F%3E(REPLACE%3CBR%20%2F%3E(REPLACE%3CBR%20%2F%3E(SUBSTRING%3CBR%20%2F%3E(ST.text%3CBR%20%2F%3E%2C%20(req.statement_start_offset%2F2)%20%2B%201%3CBR%20%2F%3E%2C%20(%3CBR%20%2F%3E(CASE%20statement_end_offset%3CBR%20%2F%3EWHEN%20-1%3CBR%20%2F%3ETHEN%20DATALENGTH(ST.text)%20%3CBR%20%2F%3EELSE%20req.statement_end_offset%3CBR%20%2F%3EEND%3CBR%20%2F%3E-%20req.statement_start_offset)%2F2)%20%2B%201)%3CBR%20%2F%3E%2C%20CHAR(10)%2C%20'%20')%2C%20CHAR(13)%2C%20'%20')%2C%201%2C%20512)%20AS%20statement_text%20%3CBR%20%2F%3EFROM%20sys.dm_exec_requests%20AS%20req%20%3CBR%20%2F%3ECROSS%20APPLY%20sys.dm_exec_sql_text(req.sql_handle)%20as%20ST%3C%2FP%3E%0A%3CP%20style%3D%22padding-left%3A%2060px%3B%22%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%20style%3D%22padding-left%3A%2030px%3B%22%3E%3CSPAN%20class%3D%22lia-inline-image-display-wrapper%20lia-image-align-inline%22%20style%3D%22width%3A%20645px%3B%22%3E%3CIMG%20src%3D%22https%3A%2F%2Fgxcuf89792.i.lithium.com%2Ft5%2Fimage%2Fserverpage%2Fimage-id%2F165534i1849301082107148%2Fimage-dimensions%2F645x100%3Fv%3D1.0%22%20width%3D%22645%22%20height%3D%22100%22%20alt%3D%22clipboard_image_1.png%22%20title%3D%22clipboard_image_1.png%22%20%2F%3E%3C%2FSPAN%3E%3C%2FP%3E%0A%3CP%20style%3D%22padding-left%3A%2060px%3B%22%3E%26nbsp%3B%3C%2FP%3E%0A%3CP%3EEnjoy!%3C%2FP%3E%3C%2FLINGO-BODY%3E%3CLINGO-TEASER%20id%3D%22lingo-teaser-1111086%22%20slang%3D%22en-US%22%3E%3CP%3EToday%2C%20we%20have%20been%20working%20on%20a%20performance%20issue%20where%20our%20customer%20is%20running%20a%20stored%20procedure%20but%20we%20don't%20know%20exacty%20what%20is%20the%20part%20of%20this%20that%20is%20running.%26nbsp%3B%3C%2FP%3E%3C%2FLINGO-TEASER%3E%3CLINGO-SUB%20id%3D%22lingo-sub-1112292%22%20slang%3D%22en-US%22%3ERe%3A%20Lesson%20Learned%20%23119%3A%20What%20is%20the%20query%20that%20my%20stored%20procedure%20is%20running%20now%3F%3C%2FLINGO-SUB%3E%3CLINGO-BODY%20id%3D%22lingo-body-1112292%22%20slang%3D%22en-US%22%3E%3CP%3EThis%20was%20very%20helpful%20while%20working%20on%20a%20query%20performance%20case.%20Good%20share!!%3C%2FP%3E%3C%2FLINGO-BODY%3E

Today, we have been working on a performance issue where our customer is running a stored procedure but we don't know exactly what is the part of this that is running. 

 

Let me show you an example how to obtain this information:

 

  • We have the following stored procedure definition: 

 

CREATE PROCEDURE WhereIsTheQueryIsRunningNow
AS
BEGIN
   SELECT 1
   SELECT 2
      WAITFOR DELAY '00:00:03'
   SELECT 3
   SELECT 4
END

 

  • We run this stored procedure EXEC WhereIsTheQueryIsRunningNow
  • Every time that we run the following query we obtain that the stored procedure is running but we don't know what is the exact line: 

SELECT
req.session_id
, req.start_time
, cpu_time 'cpu_time_ms'
, object_name(st.objectid,st.dbid) 'ObjectName'
, ST.text
FROM sys.dm_exec_requests AS req
CROSS APPLY sys.dm_exec_sql_text(req.sql_handle) as ST

 

clipboard_image_0.png

 

  • If we modify the query and we use the statement start and end offset we could find the exact query that our stored procedure is running at this time. 

 

SELECT
req.session_id
, req.start_time
, cpu_time 'cpu_time_ms'
, object_name(st.objectid,st.dbid) 'ObjectName'
, substring
(REPLACE
(REPLACE
(SUBSTRING
(ST.text
, (req.statement_start_offset/2) + 1
, (
(CASE statement_end_offset
WHEN -1
THEN DATALENGTH(ST.text)
ELSE req.statement_end_offset
END
- req.statement_start_offset)/2) + 1)
, CHAR(10), ' '), CHAR(13), ' '), 1, 512) AS statement_text
FROM sys.dm_exec_requests AS req
CROSS APPLY sys.dm_exec_sql_text(req.sql_handle) as ST

 

clipboard_image_1.png

 

Enjoy!

1 Comment
Microsoft

This was very helpful while working on a query performance case. Good share!!