NHibernate uses log4net, a highly customizable, open source logging framework. In this recipe, I'll show you a simple log4net configuration to log important NHibernate events to the Visual Studio debug output window.
- Add a reference to
log4net.dllfrom the NHibernate download. - Open your application configuration file.
- Inside the
configSectionselement, declare a section for the log4net configuration:<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>
- After the hibernate configuration element, add this log4net configuration:
<log4net> <appender name="trace" type="log4net.Appender.TraceAppender, log4net"> <layout type="log4net.Layout.PatternLayout, log4net"> <param name="ConversionPattern" value=" %date %level %message%newline" /> </layout> </appender> <root> <level value="ALL" /> <appender-ref ref="trace" /> </root> <logger name="NHibernate"> <level value="INFO" /> </logger> </log4net> - At the beginning of your
Mainfunction, insert the following code to configure log4net:log4net.Config.XmlConfigurator.Configure();
- Run your application.
- Watch Visual Studio's debug output window.
log4net uses appenders, layouts, and loggers to format and control log messages from our application, including log messages from NHibernate.
Appenders define destinations for log messages. In this recipe, we've defined a trace appender, which writes our log messages to System.Diagnostics.Trace. When we debug our application, Visual Studio listens to the trace and copies each message to the debug output window.
Loggers are the source of log messages. The root element defines values for all loggers, which can be overridden using the logger element. In our configuration, we've declared that all messages should be written to the appender named trace.
In log4net, log messages have priorities. In ascending order, they are DEBUG, INFO, WARN, ERROR, and FATAL. In our configuration, we can define a log level with one of these priorities, or with ALL or OFF. A level includes its priority and all the priorities above it. For example, a level of WARN will also log ERROR and FATAL messages. ALL is equivalent to DEBUG: all messages will be logged, and OFF suppresses all messages.
With our configuration, log4net will write messages from NHibernate with a priority of INFO, WARN, ERROR, and FATAL, and ALL messages from other sources.
We can use log4net in our own application. Here's a simple example of what some code might look like with log4net logging:
using System.IO;
using log4net;
namespace MyApp.Project.SomeNamespace
{
public class Foo
{
private static ILog log = LogManager.GetLogger(typeof(Foo));
public string DoSomething()
{
log.Debug("We're doing something.");
try
{
return File.ReadAllText("cheese.txt");
}
catch (FileNotFoundException)
{
log.Error("Somebody moved my cheese.txt");
throw;
}
}
}
}We've defined a simple class named Foo. In the DoSomething() method, we write the log message, "We're doing something.", with a priority of DEBUG. Then we return the contents of the file cheese.txt. If the file doesn't exist, we log an error and throw the exception.
Because we passed in typeof(Foo) when getting the logger, Foo's logger is named MyApp.Project.SomeNamespace.Foo, the same as the type. This is the typical naming convention when using log4net.
Suppose we were no longer concerned with debug level messages from Foo, but we still wanted to know about warnings and errors. We can redefine the log level with this simple addition to our configuration:
<logger name="MyApp.Project.SomeNamespace.Foo"> <level value="WARN" /> </logger>
Alternatively, we can set the log level for the entire namespace or even the entire project with this configuration.
<logger name="MyApp.Project"> <level value="WARN" /> </logger>
When we set NHibernate's show_sql configuration property to true, NHibernate will write all SQL statements to Console.Out. This is handy in some cases, but many applications don't use console output. With log4net, we can write the SQL statements to the trace instead.
NHibernate also writes every SQL statement to a logger named NHibernate.SQL. These log messages have DEBUG priority. When we add the following snippet to our configuration, we can redefine the log level for this specific logger. We will get every SQL statement in the trace output.
<logger name="NHibernate.SQL"> <level name="DEBUG" /> </logger>