Can't get NHibernate and Log4Net to generates logging.

Question

I can't get any logging of NHibernate or my application. I tried EVERYTHING that I could think about, but nothing work!

Here is my code:

using System.Reflection;
using NHibernate.Cfg;

[assembly: log4net.Config.XmlConfigurator(ConfigFile = "Log4Net.config", Watch = true)]
namespace NHibernate_Log4Net
{
    class Program
    {
        static void Main(string[] args)
        {
            var cfg = new Configuration()
                    .Configure()
                    .AddAssembly(Assembly.GetCallingAssembly());
        }
    }
}



namespace NHibernate_Log4Net.Model
{
    public class Item
    {
        public int Id { get; set; }
        public int Title { get; set; }
        public int Alias { get; set; }
    }
}



Item.hbm.xml file: 

<?xml version="1.0" encoding="utf-8" ?>
<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" namespace="NHibernate_Log4Net.Model.Item" assembly="NHibernate_Log4Net" auto-import="false">
  <class name="User" table="Users">
    <id name="Id">
      <generator class="Native"/>
    </id>

    <property name="Title" length="255" not-null="true" />
    <property name="Alias" length="255" not-null="true" />
  </class>
</hibernate-mapping>





Log4Net.config file:


<?xml version="1.0" encoding="utf-8"?>
<log4net debug="false">

  <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="log4netLogger.log" />
    <appendToFile value="false" />
    <rollingStyle value="Size" />
    <maxSizeRollBackups value="10" />
    <maximumFileSize value="1000KB" />
    <staticLogFileName value="true" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%d [%t] %-5p %c - %m%n" />
    </layout>
  </appender>

  <appender name="OutputDebugStringAppender" type="log4net.Appender.OutputDebugStringAppender">
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%-5p %m - %c -%n" />
    </layout>
  </appender>
  <appender name="TraceAppender" type="log4net.Appender.TraceAppender">
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%d [%t] %-5p %c - %m%n" />
    </layout>
  </appender>

  <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date - %message%newline"/>
    </layout>
  </appender>

  <root>
    <level value="DEBUG" />
    <appender-ref ref="RollingFileAppender" />
    <appender-ref ref="OutputDebugStringAppender" />
    <appender-ref ref="TraceAppender" />
  </root>
  <logger name="NHibernate" additivity="false">
    <level value="FATAL"/>
    <appender-ref ref="RollingFileAppender" />
    <appender-ref ref="OutputDebugStringAppender" />
    <appender-ref ref="ConsoleAppender" />
    <appender-ref ref="TraceAppender" />
  </logger>
  <logger name="NHibernate.SQL" additivity="false">
    <level value="DEBUG" />
    <appender-ref ref="ConsoleAppender" />
    <appender-ref ref="RollingFileAppender" />
  </logger>
  <!-- 
      NHibernate.Loader.Loader logs diagnostic stuff and SELECTs. 
      You can use either logger, or both, depending on you needs.
    -->
  <logger name="NHibernate.Loader.Loader" additivity="false">
    <level value="INFO" />
    <appender-ref ref="ConsoleAppender" />
    <appender-ref ref="RollingFileAppender" />
  </logger>


</log4net>

NHibernate throw n error that "Users" class don't exist, this is expected, but why I don't see any logging from this, from NHibernate?

(I can log it myself, but the point that I can't see any log from NHibernate).

Answer 1

The config file needs to match the executable, is your executable named Log4Net.exe?

Answer 2

I have had trouble using the XmlConfigurator attribute in the past. Perhaps you should just call XmlConfigurator explicitly in your main like so:

namespace NHibernate_Log4Net
{
    class Program
    {
        static void Main(string[] args)
        {
            XmlConfigurator.ConfigureAndWatch(new FileInfo("log4net.config"));
            var cfg = new Configuration()
                    .Configure()
                    .AddAssembly(Assembly.GetCallingAssembly());
        }
    }
}

Answer 3

http://blogs.hibernatingrhinos.com/nhibernate/archive/2008/07/01/how-to-configure-log4net-for-use-with-nhibernate.aspx

I used the above link to set up logging. Try the following

[assembly: log4net.Config.XmlConfigurator(ConfigFile = "Log4Net.config", Watch = true)]
namespace NHibernate_Log4Net
{
    class Program
    {
        static void Main(string[] args)
        {
            log4net.Config.XmlConfigurator.Configure();
            var cfg = new Configuration()
                    .AddAssembly(Assembly.GetCallingAssembly());
                    .Configure()

        }
    }
}

The extra is this line

log4net.Config.XmlConfigurator.Configure();

It didnt work for me till I added that. I know this is somewhat similar to what Jeffery suggested, but... just my 2cents.

Also, shouldnt the Configure() call on the Nhibernate configuration object come last? After the Assembly is added?

Answer 4

If the logging levels set for the NHibernate loggers are too high (or off), you may not see any log messages from NHibernate. For example, what is the value of ((log4net.Repository.Hierarchy.Logger)LogManager.GetLogger("NHibernate").Logger).Level?

You should have a section in your config file like this:

<log4net>
        <appender name="NHLog" type="log4net.Appender.FileAppender">
                <file value="logs/nhibernate.log" />
                <appendToFile value="false" />
                <layout type="log4net.Layout.PatternLayout">
                        <conversionPattern value="%d{HH:mm:ss.fff} [%t] %-5p %c - %m%n"  />
                </layout>
        </appender>
        <logger name="NHibernate" additivity="false">
                <level value="DEBUG"/>
                <appender-ref ref="NHLog"/>
        </logger>
</log4net>

Update: If the log file is always created (when non-existent before a run) but is always empty, this points to an exception during appending. To minimise the possibility of an exception, have a very simple conversionPattern (perhaps just "%m%n") and see if any output is generated. If there is, add back elements of the conversion pattern until you find where the problem is. If no output is generated, log something to the NHibernate logger from your own code (this is perfectly OK) and step through it in the debugger.

ILog log = LogManager.GetLogger("NHibernate");

log.Info("Application starting");

If still no joy, you may have to post some of your code/configuration.