I am sure everyone else has already figured this out but thought I’d jot it down here.
I wanted to isolate all messages being sent from NHibernate to its own logging file. NHibernate has lots to say during its operations and often the messages it delivers are the only way of tracking down some obsure error since sometimes the exception messages in NHibernate are…well, wanting. After poking around the forums and trying out a few methods, here is how I finally split my NHibernate logs from the rest of my application logs.
The Configuration
For simplicity, say I want just two log text files produced, system.log and nhibernatelog.log. Look over the log4net configuration and Ignore the Console and AspNetTraceAppenders below:
<log4net>
<appender name="Console" type="log4net.Appender.ConsoleAppender">
<layout type="log4net.Layout.PatternLayout">
<!-- Pattern to output the caller's file name and line number -->
<conversionPattern value="%5level [%thread] (%file:%line) - %message%newline"/>
</layout>
</appender>
<appender name="AspNetTraceAppender" type="log4net.Appender.AspNetTraceAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline"/>
</layout>
</appender>
<appender name="NHibernateAppender" type="log4net.Appender.RollingFileAppender">
<file value="../../../log/nhibernatelog.log"/>
<appendToFile value="true"/>
<maximumFileSize value="1000KB"/>
<maxSizeRollBackups value="2"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %level %thread %logger - %message%newline"/>
</layout>
</appender>
<appender name="SystemAppender" type="log4net.Appender.RollingFileAppender">
<file value="../../../log/system.log"/>
<appendToFile value="true"/>
<maximumFileSize value="1000KB"/>
<maxSizeRollBackups value="2"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %level %thread %logger - %message%newline"/>
</layout>
</appender>
<root>
<level value="ALL"/>
<appender-ref ref="AspNetTraceAppender"/>
<appender-ref ref="Console"/>
</root>
<logger name="NHibernate">
<level value="ERROR" />
<appender-ref ref="NHibernateAppender"/>
</logger>
<logger name="NHibernate.Loader.Loader">
<level value="INFO" />
<appender-ref ref="NHibernateAppender"/>
</logger>
<logger name="System">
<level value="ALL" />
<appender-ref ref="SystemAppender"/>
</logger>
</log4net>The primary points of interest are:
- I do not have my SystemAppender or my NHibernateAppender inside the <root /> element. Doing so resulted in duplicate entries
- The ‘name’ attribute on the <logger/> element is important. Take note.
Start ‘er up
To get things wired up when the application starts, add this to your global.asax in the Application_Start section:
log4net.Config.XmlConfigurator.Configure();
Logging to ‘system.log’
To get a reference to my ‘system’ logger, i just have to use the following:
static ILog logger = LogManager.GetLogger("System");Notice that I am referencing the logger by its name (“System”) in the <logger/> section above. Then to write out to the file, just this:
logger.Debug("Writing Debug Message");
Logging to ‘nhibernate.log’
The important thing to understand about controlling logging for NHibernate is that it writes using the following call:
LogManager.GetLogger( Type or string )
Check out this forum post for an explanation of the implications. I snagged the ‘logger’ setup from this post.
What this means is that the <logger/> element in the configuration will need to have its ‘name’ set to ‘NHibernate’ since that is how it is called…any other name NHibernate just won’t recognize and logging won’t happen.
Note, too , that the configuration above is only logging the SQL (NHibernate.Loader.Loader) sent to the DB and error messages. This helps sift out the rif-raf that I am not real interested in usually.
Once these have been all set up I was successfully logging to the right file. Here are the posts that helped me:
- General log4net configuration with NHibernate
- Seperating loggers and how NHibernate logs
