Skip to main content
Ben Nadel at InVision In Real Life (IRL) 2019 (Phoenix, AZ) with: Eric Betts
Ben Nadel at InVision In Real Life (IRL) 2019 (Phoenix, AZ) with: Eric Betts

Putting DEBUG Comments In Your SQL Statements Makes FusionReactor Query Tracing More Effective

By
Published in ,

For years, I've been advocating that people put DEBUG comments in their SQL statements to help identify performance bottlenecks in their applications. I feel so strongly about this that I'm absolutely nonplussed whenever I see a SQL query show-up in the MySQL slow-log or the process-list without a DEBUG statement. Recently, we installed FusionReactor at work; and, I was thrilled to see that my DEBUG statements were showing up in the database profiling that FusionReactor provides.

To see what I mean, let's create a test ColdFusion page that executes a slow SQL query that will show up in FusionReactor's slow transaction list. For this simulation, we can use MySQL's SLEEP() command:

<cfscript>
	
	dump( getPost( 3 ) );

	// ------------------------------------------------------------------------------- //
	// ------------------------------------------------------------------------------- //

	public array function getPost( required numeric id ) {

		// NOTE: We're using MySQL's SLEEP() command to simulate a performance bottleneck
		// in order to get this page to show up in FusionReactor's slow transaction log.
		var result = queryExecute(
			sql = "
				/* DEBUG: fusionReactorTesting.getPosts(). */
				SELECT
					e.id,
					e.content,
					e.content_markdown,

					-- Simulating a slow query, sleep for 5-seconds.
					( SLEEP( 5 ) ) AS temp
				FROM
					blog_entry e
				WHERE
					e.id = :id
				;
			",
			params = {
				id: { value: id, sqlType: "integer" }
			},
			options = {
				returnType: "array"
			}
		);

		return( result );

	}

</cfscript>

As you can see, the very first line of my SQL statement is a comment:

/* DEBUG: fusionReactorTesting.getPosts(). */

This SQL comment is always formatted as component.method() so that when I see it in the logs, I know exactly which file in my application initiated the query.

Now, when we run the above ColdFusion page, we get this JDBC request showing up in the FusionReactor Cloud dashboard:

FusionReactor Cloud dashboard showing SQL DEBUG comments.

As well as in the FusionReactor Enterprise dashboard:

FusionReactor Enterprise dashboard showing SQL DEBUG comments.

As you can see, whenever the SQL statement shows up in FusionReactor, so does our SQL DEBUG comment. Now, when looking at my FusionReactor dashboards, I can immediately understand which SQL queries are causing performance bottlenecks. And, I don't have go through the code in order to reason about which template called which template or which requests map to which queries; I simply look at the slow-queries and I know exactly where in the code to find calling context.

But, I'm Using An ORM (Object-Relational Mapper) For My SQL Queries

It may be that you use an ORM instead of writing raw SQL queries. And, at first, it might appear that such an abstraction layer removes the ability to add DEBUG comments; but, that may not be true. I know that the Sequelize Node.js module allows for comments; and, I'd be surprised if other ORMs don't offer some means to either add comments directly; or, a way to extend the ORM with said functionality.

Want to use code from this post? Check out the license.

Reader Comments

I believe in love. I believe in compassion. I believe in human rights. I believe that we can afford to give more of these gifts to the world around us because it costs us nothing to be decent and kind and understanding. And, I want you to know that when you land on this site, you are accepted for who you are, no matter how you identify, what truths you live, or whatever kind of goofy shit makes you feel alive! Rock on with your bad self!
Ben Nadel