Logging NHibernate queries with parameters

NHibernate lets you log the SQL statements it constructs using log4net. I’m not going to explain how to do it, because it is already well explained. It gives you flexibility on where you want to log: console, text file, xml file etc. The output that you get looks something like this:

12:33:54,464 DEBUG SQL:56 - 
SELECT
    count(CategoryId) 
FROM
    ProductCategories 
WHERE
    ProductId=@p0;
 @p0 = 65536 [Type: Int32 (0)]

Notice, that the query contains parameter name, not value – values are listed on the bottom.

Sometimes you want to run this query using a tool other than NHibernate, Sql Server Management Studio, for example. Then you’ll have to copy the appropriate parameter values and replace it in a query. Doing it by hand is a waste of time, so I wrote a custom log4net appender, that does it for us. Here’s the source code:

public class NHAppender: ForwardingAppender
{
	protected override void Append(LoggingEvent loggingEvent)
	{
		var loggingEventData = loggingEvent.GetLoggingEventData();

		if(loggingEventData.Message.Contains("@p"))
		{
			StringBuilder messageBuilder = new StringBuilder();

			string message = loggingEventData.Message;
			var queries = Regex.Split(message, @"command\s\d+:");

			foreach (var query in queries)
				messageBuilder.Append(ReplaceQueryParametersWithValues(query));

			loggingEventData.Message = messageBuilder.ToString();
		}

		base.Append(new LoggingEvent(loggingEventData));
	}

	private static string ReplaceQueryParametersWithValues(string query)
	{
		return Regex.Replace(query, @"@p\d(?=[,);\s])(?!\s*=)", match =>
		{
			Regex parameterValueRegex = new Regex(string.Format(@".*{0}\s*=\s*(.*?)\s*[\[].*", match));
			return parameterValueRegex.Match(query).Groups[1].ToString();
		});
	}
}

What I’ve done here, is derive from a ForwardingAppender, that let’s you transform the output logged and forward it to another appender. The NHAppender replaces the parameter names in query (@p0, @p1 and so on) with appropriate values, taking batch commands into account (notice the usage of Regex.Split).

You can use this appender to forward fully executable SQL queries to the console like this in your configuration:

<appender name="NHAppender" type="NHibernatePlayground.Custom.NHAppender, NHibernatePlayground">
	<appender-ref ref="console" />
</appender>

<root>
	<appender-ref ref="NHAppender" />
</root>

This way, you can copy the queries from console output and execute it immediately.

About these ads

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Follow

Get every new post delivered to your Inbox.

%d bloggers like this: