Contar el número de consultas ejecutadas por NHibernate en una prueba de unidad

Question

En algunas pruebas de unidad/integración del código que deseen comprobar que el uso correcto del segundo nivel de caché está siendo empleada por nuestro código.

Basado en el código presentado por Ayende aquí:

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

escribí una clase simple para hacer precisamente eso:

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; 
     } 
    } 
} 

Con intención de uso:

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

Pero siempre devuelve 0 para el recuento de consultas. No se registran sentencias sql.

Sin embargo si hago uso de Nhibernate Profiler e invocan esto en mi caso de prueba:

NHibernateProfiler.Intialize() 

Dónde NHProf utiliza un enfoque similar para capturar salida de registro de NHibernate para el análisis a través de log4net etc. entonces mi QueryCounter comienza a trabajar .

Parece que me falta algo en mi código para que log4net esté configurado correctamente para registrar nhibernate sql ... ¿Alguien tiene alguna sugerencia sobre qué más debo hacer para obtener la salida de registro sql de Nhibernate?

Otros detalles:

Logging.config:

<log4net> 

    <appender name="trace" type="log4net.Appender.TraceAppender, log4net"> 
    <layout type="log4net.Layout.PatternLayout,log4net"> 
     <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] &amp;lt;%P{user}&amp;gt; - %m%n" /> 
    </layout> 
    </appender> 

    <appender name="console" type="log4net.Appender.ConsoleAppender, log4net"> 
    <layout type="log4net.Layout.PatternLayout,log4net"> 
     <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] &amp;lt;%P{user}&amp;gt; - %m%n" /> 
    </layout> 
    </appender> 

    <appender name="debug" type="log4net.Appender.DebugAppender, log4net"> 
    <layout type="log4net.Layout.PatternLayout,log4net"> 
     <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] &amp;lt;%P{user}&amp;gt; - %m%n" /> 
    </layout> 
    </appender> 

    <logger name="NHibernate.SQL" additivity="false"> 
    <level value="DEBUG" /> 
    <appender-ref ref="ConsoleAppender" /> 
    </logger> 

    <root> 
    <priority value="DEBUG" /> 
    <appender-ref ref="trace" /> 
    <appender-ref ref="console" /> 
    <appender-ref ref="debug" /> 
    </root> 

</log4net> 

show_sql: verdadera

Basado en jfneis respuesta, me escribió una clase mucho más simple, que sólo utiliza las estadísticas de fábrica de NHibernate:

public class QueryCounter 
{ 
    long _startCount; 

    QueryCounter() 
    { 
    } 

    public int QueryCount 
    { 
    get { return (int) (UnitOfWork.CurrentSession.SessionFactory.Statistics.QueryExecutionCount - _startCount); } 
    } 

    public static QueryCounter Start() 
    { 
    return new QueryCounter {_startCount = UnitOfWork.CurrentSession.SessionFactory.Statistics.QueryExecutionCount}; 
    } 
} 

Que funciona bien una vez que las estadísticas están habilitadas.

Answer 1

Hay otra manera (más simple, la OMI) para afirmar si la caché está siendo golpeado o si se están ejecutando consultas: Uso de la estadística.

En primer lugar, tiene que habilitar las estadísticas en su archivo de configuración NH:

<property name="generate_statistics">true</property> 

Después de eso, puede preguntar a su fábrica de sesiones siempre que lo desee cómo van las cosas. Usted ha hablado de las pruebas de caché L2, lo que podría tener algo así:

 // act 
     MappedEntity retrievedEntity = session.FindById(entity.Id); 
     long preCacheCount = sessionFactory.Statistics.SecondLevelCacheHitCount; 
     retrievedEntity = session.FindById(entity.Id); 
     long postCacheCount = sessionFactory.Statistics.SecondLevelCacheHitCount; 
     // assert 
     Assert.AreEqual(preCacheCount + 1, postCacheCount); 

Pero, si lo que realmente quiere es el recuento de consulta, hay muchas otras opciones en la interfaz Estadísticas:

 sessionFactory.Statistics.QueryExecutionCount; 
     sessionFactory.Statistics.TransactionCount; 

Bueno, eso es todo. Espero que esto te ayude como me ayudó.

Saludos,

Filipe