How to get SQL with parameter values on an exception

Question

Hard to believe, but I can't seem to find a straight answer for this: How can I get the SQL statement including the parameter values when the statement generates an exception and only when it generates an exception. I know how to log the statement+parameters for every SQL generated, but that's way too much. When there's a System.Data.SqlClient.SqlException, though, it only provides the SQL, not the parameter values. How can I catch that at a point where I have access to the that data so that I can log it?

Answer 1

Based on a number of responses to various questions (not just mine), I've cobbled something together that does the trick. I think it could be useful to others as well, so I'm including a good deal of it here:

The basic idea is to

1. Have NH log all queries, pretty-printed and with the parameter values in situ
2. Throw all those logs out except the one just prior to the exception.

I use Log4Net, and the setup is like this:

<?xml version="1.0"?>

<log4net>
  <appender name="RockAndRoll" type="Util.PrettySqlRollingFileAppender, Util">
    <file type="log4net.Util.PatternString" >
      <conversionPattern value="%env{Temp}\\%property{LogDir}\\MyApp.log" />
    </file>
    <DatePattern value="MM-dd-yyyy" />
    <appendToFile value="true" />
    <immediateFlush value="true" />
    <rollingStyle value="Composite" />
    <maxSizeRollBackups value="10" />
    <maximumFileSize value="100MB" />
    <staticLogFileName value="true" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date %-5level %logger - %message%newline" />
    </layout>
  </appender>

  <appender name="ErrorBufferingAppender" type="log4net.Appender.BufferingForwardingAppender">
    <bufferSize value="2" />
    <lossy value="true" />
    <evaluator type="log4net.Core.LevelEvaluator">
      <threshold value="ERROR" />
    </evaluator>
    <appender-ref ref="RockAndRoll" />
    <Fix value="0" />
  </appender>

  <logger name="NHibernate.SQL">
    <additivity>false</additivity>
    <appender-ref ref="ErrorBufferingAppender" />
    <level value="debug" />
  </logger>

  <logger name="error-buffer">
    <additivity>false</additivity>
    <appender-ref ref="ErrorBufferingAppender" />
    <level value="debug" />
  </logger>

  <root>
    <level value="info" />
    <appender-ref ref="RockAndRoll" />
  </root>

</log4net>

The NHibernate.SQL logger logs all queries to the ErrorBufferingAppender, which keeps throwing them out and saves only the last one in its buffer. When I catch an exception I log one line at ERROR level to logger error-buffer, which passes it to ErrorBufferingAppender which -- because it's at ERROR level -- pushes it, along with the last query, out to RockAndRoll, my RollingFileAppender.

I implemented a subclass of RollingFileAppender called PrettySqlRollingFileAppender (which I'm happy to provide if anyone's interested) that takes the parameters from the end of the query and substitutes them inside the query itself, making it much more readable.

Answer 2

If you are using nhibernate for querying the db (as the tag presence on your question suggests), and your SQL dialect/driver relies on ADO, you should get a GenericADOException from the failing query.

Its Message property normally already include parameters values.

For example, executing the following failing query (provided you have at least one row in DB):

var result = session.Query<Entity>()
    .Where(e => e.Name.Length / 0 == 1);

Yields a GenericADOException with message:

could not execute query  
[ select entity0_.Id as Id1_0_, entity0_.Name as Name2_0_ from Entity entity0_ where len(entity0_.Name)/@p0=@p1 ]  
  Name:p1 - Value:0  Name:p2 - Value:1

The two literals, 0 and 1, of the query have been parameterized and their values are included in the message (with an index base mismatch: on hibernate queries, they are 1 based, while on the SQL query with my setup, they end up 0 based).

So there is nothing special to do to have them. Just log the exception message.

Have you just missed it, or were you asking something else indeed?
Your question was not explicit enough in my opinion. You should include a MVCE. It would have show me more precisely in which case you were not able of getting those parameters values.