Coloring a T-SQL Procedure Listing with Metric Values

First, I'll show you what this is about so you can decide if it's relevant to you.

We append the following metrics to the T-SQL procedure statements:

• Execution count (x)

• CPU time in milliseconds (c)

• Duration in microseconds (d)

• Number of reads (r)

• Number of writes (w)

• @@rowcount value (n)

You can display these as absolute values or percentages.

Data Collection

Run SQL Profiler and select a single event:

• SP:StmtCompleted

Choose the following columns:

• CPU

• Duration

• Reads

• Writes

• StartTime

• EndTime

• LineNumber

• ObjectName

• SPID

• RowCounts

Sometimes, RowCounts data is not collected if TextData is not included.

In the filters, specify ObjectName = [your procedure name]. Use just the procedure name without schema or brackets (e.g., for [dbo].[MyProc], enter MyProc). If profiling on dev and you know the SPID, filter by it. For Production, try to limit the trace to a single SPID (though the coloring tool itself doesn’t require this).

Why SQL Profiler and Not Extended Events?

I’ve been asked why I use SQL Profiler instead of Extended Events. You can use Extended Events, but for quick ad-hoc traces, SQL Profiler is often simpler and faster. Be cautious on Production—avoid runaway traces! After running the trace, collect enough data and save it to a table.

Environment Setup

Install Python and the Pygments package

pip install Pygments

This provides the pygmentize command. Download the sqlpig script from my repository: https://github.com/tzimie/sqlpig. Originally named SQLpyg (SQL + pygmentize), it later became SQLpig. At the very beginning of the sqlpig.py script, you’ll find a query that you’ll need:

select ObjectName+'.sql:'+convert(varchar,LineNumber)+':'+
  convert(varchar,cnt)+':'+
  convert(varchar,CPU)+':'+
  convert(varchar,Duration)+':'+
  convert(varchar,Reads)+':'+
  convert(varchar,Writes)+':'+
  convert(varchar,isnull(RowCounts,0))
from (
  select ObjectName,LineNumber, count(*) as cnt, sum(CPU) as CPU,sum(Duration) as Duration,
    sum(Reads) as Reads, sum(Writes) as Writes, sum(RowCounts) as RowCounts
  from {MyTrace} where EventClass=45 and ObjectName is not null
  group by ObjectName,LineNumber) Q 

Processing the Trace Data

Replace {MyTrace} with the name of the table where you saved the trace. Execute the script and save its output to a text file (.log). You can name this file the same as your procedure or add suffixes like short or long for different executions.

Next, you'll need the source code of the procedure. In SQL Server Management Studio, perform an ALTER on the procedure and copy the resulting text into a file named procedurename.sql.

Important: You must remove the header section from the procedure script:

The first meaningful line should be either ALTER or the first line of a comment.

You might ask - why can't the script simply read the procedure text and trace data automatically? The issue is that traces are typically captured in production environments where software installation is often restricted. That's why we transfer everything to local machines via copy/paste (when available).

Processing

Let's run sqlpig:

Applying Metrics to SQL Files

The metrics from myproc.log are applied to the myproc.sql file and output to myproc.html. You can specify different metrics:

• x - Execution count (not of the entire procedure, but of individual statements; if a statement is in a loop, this count may be much higher than the procedure's execution count)

• c - CPU time in milliseconds

• d - Duration in microseconds (more precise than CPU time)

• r - Reads

• w - Writes

• n - Row count from the RowCounts column (this isn't always accurate and deserves separate discussion)

Uppercase metrics (XCDRWN) represent the same metrics but displayed as percentages of the total.

You can combine both percentage and absolute metrics—for example, xcCdD is a valid combination.

The final parameter is the log file name. For a single procedure, you might have results from multiple executions (e.g., short/long runs).

Potential Issues

Sometimes, the metric annotations may appear misaligned with the corresponding lines of source code. I'm gradually working to eliminate edge cases, but for now, you can manually adjust the values in the source code.

shift = 1 # edit this value to readjust position if needed