I will show you in this post two tricks you can do to enhance and add value to your nhibernate logs.
This is widely know trick, you can add a configuration setting to your hibernate.cfg.xml, app.config or web.config as follow:
<property name="hibernate.format_sql" value="true" />
or you can simply do it in code:
config.DataBaseIntegration(db => db.LogFormatedSql = true)
with this trick you will get nicely formated sql in your logs files.
All nice, we have a bunch of sql logs, but we don’t know which queries belongs to which sessions. This might be useful when you are debugging an application with multiples threads or requests.
I found this trick inside NHibernate, the easy way I found so far is to add a log4net appender like this one:
<appender name="NHibernateAppender" type="log4net.Appender.RollingFileAppender"> <appendToFile value="true"/> <datePattern value="yyyyMMdd"/> <file value="./logs/NHibernate.log"/> <layout type="log4net.Layout.PatternLayout"> <conversionPattern value="%date Session id: %property{sessionId} - %message%newline"/> </layout> <rollingStyle value="Date"/> </appender>
See the %property{sessionId} in the conversion pattern?
Well, in order to log something there you need to do two steps.
Add a class like this one:
public class SessionIdCapturer { public override string ToString() { return SessionIdLoggingContext.SessionId.ToString(); } }
Add the following code in some place at the application initialization:
ThreadContext.Properties["sessionId"] = new SessionIdCapturer();
That is all! I found this code inside a nhibernate test.. it is something not very known.
After doing so, your logs will look like:
2011-05-05 18:35:59,899 Session id: 5e172068-5064-44b6-bf96-99362ca05c46 - SELECT myFoo0_.AccountId as AccountId3_0_, myFoo0_.Name as Name3_0_, myFoo0_.Version as Version3_0_ FROM MyFoo myFoo0_ WHERE myFoo0_.AccountId=@p0; @p0 = 1 [Type: Int32 (0)]
Another way to have this information (and much more) is to use the nhprof tool.