how can I access (or Generate) the NHibernate Sql at Runtime

Question

I think the title is fairly self explanatory, but to give a little context.

I've been reading this question, but it doesn't quite meet my use case

Intercept-sql-statements-containing-parameter-values-generated-by-nhibernate

The issue that I have is that I want to log out the generated SQL only when an exception occurs (or a time period elapses). This is to enable us to troubleshoot some long running queries in a very complex application. I don't want to intercept and log all the queries as there would be a performance hit on this I believe.

At the point where I want to log it, I have the ICriteria object that NHibernate uses, so what I'm looking for is a kind of "dummy" NHibernate object that I can fire these ICriteria at and get back the SQL string (or even the SQL with placeholders for the parameters and a list of parameters).

So does something exist that does this (I'm thinking that it's either incredibly simple and I'm missing something, or it's very hard and nobody else needs it).

If it doesn't exist, what's the best way to go about creating something that achieves the goal, without manually building the SQL (I want to be as close to the executed SQL as possible). Is there a way to go straight to the NHibernate generator and get the string?

Adding to this to make it clearer.

I want to do this "After the fact", and not intercept every query (due to performance concerns). I also don't want to do this using Log4Net as I need it to be logged against the session.

I'm thinking that there must be a way to create a second NHibernate object that maybe uses a different driver (one that doesn't go to the database), this way I can implement a way to intercept that object, and not main object that is persisting to the database

Felice Pollano · Accepted Answer · 2012-03-20T10:41:03.383

1

If you need to know the query executed just in the case there is an exception, you can use check the "Data" additional elements on the exception:

yourexception.Data["actual-sql-query"]

that contain the query causing the exception. In ordinal operations you can use the logger named "NHibernate.SQL", that is the most reliable way to get the query text in order to me, because other "straight" method depends on the way you query NH ( ICriteria,Hql, QueryOver, LinqTONh, SOmeNewWayNotYetImplemented ...) so intercepting the logger is usually better.

edited Mar 20 '12 at 10:41

answered Mar 19 '12 at 13:36

Felice Pollano

32,832
9
75
115

Thanks, this is part of the answer however, I want to be able to do it where there has not been an exception (it just took a long time to run. – Martin Mar 20 '12 at 10:03
I'm going to wait to accept this, as I'm sure there must be a solution that allows for just running the queries with a dummy provider. – Martin Mar 20 '12 at 11:28
This is the closest to a solution, I may have a go at putting together a better approach at some point. – Martin Mar 22 '12 at 16:39

score 0 · Answer 2 · answered Mar 19 '12 at 13:48

By default NHibernate will log query if exception occurs by enabling following log4net config in app/web config

<log4net>
    <appender name="rollingFile" type="log4net.Appender.RollingFileAppender, log4net">
        <param name="File" value="Log\NHibernate\log.txt"/>
        <param name="AppendToFile" value="true"/>
        <param name="RollingStyle" value="Date"/>
        <param name="DatePattern" value="yyyy.MM.dd"/>
        <param name="StaticLogFileName" value="true"/>
        <layout type="log4net.Layout.PatternLayout, log4net">
            <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] &lt;%X{auth}&gt; - %m%n"/>
        </layout>
    </appender>
    <root>
        <priority value="ERROR"/>
        <appender-ref ref="rollingFile"/>
    </root>
</log4net>

And if want to get from interceptor assign to some global variable or expose a property in interceptor and log it if exception occurs as follows

public class SessionManagerSQLInterceptor : EmptyInterceptor, IInterceptor
{
    //public string your property{ get; set; }  

    NHibernate.SqlCommand.SqlString IInterceptor.OnPrepareStatement(NHibernate.SqlCommand.SqlString sql)
    {
        NHSessionManager.Instance.NHibernateSQL = sql.ToString();
        //property = sql.ToString();
        //Or
        //AsignSqlToSomeGlobalVariable(sql.ToString());
        return sql;
    }
}

Thanks for the response, however I'm looking for runtime, and only in certain circumstances "after the fact". I don't want to intercept every call as there would be a performance hit... — Martin, Mar 20 '12 at 09:49

score 0 · Answer 3 · answered Mar 19 '12 at 18:57

If you are using log4net you can use the BufferingForwardingAppender. This will allow you to log a configurable number of log events that happened before the error (including the sql statement).

This example shows how to deliver only significant events. A LevelEvaluator is specified with a threshold of WARN. This means that the events will only be delivered when a message with level of WARN or higher level is logged. Up to 512 (BufferSize) previous messages of any level will also be delivered to provide context information. Messages not sent will be discarded.

<appender name="BufferingForwardingAppender" type="log4net.Appender.BufferingForwardingAppender" >
    <bufferSize value="512" />
    <lossy value="true" />
    <evaluator type="log4net.Core.LevelEvaluator">
        <threshold value="WARN"/>
    </evaluator>
    <appender-ref ref="ConsoleAppender" />
</appender>

Also here is a blog post on this:

http://www.beefycode.com/post/Log4Net-Tutorial-pt-8-Lossy-Logging.aspx

This is a great idea, however, it's a multi-user web application, so this would fill up pretty fast and not provide much use as the queries wouldn't be linked to the session. — Martin, Mar 20 '12 at 10:05

how can I access (or Generate) the NHibernate Sql at Runtime

3 Answers3