In some unit/integration tests of the code we wish to check that correct usage of the second level cache is being employed by our code.

Based on the code presented by Ayende here:

http://ayende.com/Blog/archive/2006/09/07/MeasuringNHibernatesQueriesPerPage.aspx

I wrote a simple class for doing just that:

public class QueryCounter : IDisposable
{
    CountToContextItemsAppender _appender;

    public int QueryCount
    {
      get { return _appender.Count; }
    }

    public void Dispose()
    {
      var logger = (Logger) LogManager.GetLogger("NHibernate.SQL").Logger;
      logger.RemoveAppender(_appender);
    }

    public static QueryCounter Start()
    {
      var logger = (Logger) LogManager.GetLogger("NHibernate.SQL").Logger;

      lock (logger)
      {
        foreach (IAppender existingAppender in logger.Appenders)
        {
          if (existingAppender is CountToContextItemsAppender)
          {
            var countAppender = (CountToContextItemsAppender) existingAppender;

            countAppender.Reset();

            return new QueryCounter {_appender = (CountToContextItemsAppender) existingAppender};
          }
        }

        var newAppender = new CountToContextItemsAppender();
        logger.AddAppender(newAppender);
        logger.Level = Level.Debug;
        logger.Additivity = false;

        return new QueryCounter {_appender = newAppender};
      }
    }

    public class CountToContextItemsAppender : IAppender
    {
      int _count;

      public int Count
      {
        get { return _count; }
      }

      public void Close()
      {
      }

      public void DoAppend(LoggingEvent loggingEvent)
      {
        if (string.Empty.Equals(loggingEvent.MessageObject)) return;
        _count++;
      }

      public string Name { get; set; }

      public void Reset()
      {
        _count = 0;
      }
    }
}

With intended usage:

using (var counter = QueryCounter.Start())
{
  // ... do something 
  Assert.Equal(1, counter.QueryCount); // check the query count matches our expectations
}

But it always returns 0 for Query count. No sql statements are being logged.

However if I make use of Nhibernate Profiler and invoke this in my test case:

NHibernateProfiler.Intialize()

Where NHProf uses a similar approach to capture logging output from NHibernate for analysis via log4net etc. then my QueryCounter starts working.

It looks like I'm missing something in my code to get log4net configured correctly for logging nhibernate sql ... does anyone have any pointers on what else I need to do to get sql logging output from Nhibernate?