Cómo realizar una prueba unitaria con ILogger en ASP.NET Core

128

Este es mi controlador:

public class BlogController : Controller
{
    private IDAO<Blog> _blogDAO;
    private readonly ILogger<BlogController> _logger;

    public BlogController(ILogger<BlogController> logger, IDAO<Blog> blogDAO)
    {
        this._blogDAO = blogDAO;
        this._logger = logger;
    }
    public IActionResult Index()
    {
        var blogs = this._blogDAO.GetMany();
        this._logger.LogInformation("Index page say hello", new object[0]);
        return View(blogs);
    }
}

Como puede ver, tengo 2 dependencias, una IDAOy unaILogger

Y esta es mi clase de prueba, uso xUnit para probar y Moq para crear simulacros y stub, puedo simular DAOfácilmente, pero con el ILoggerno sé qué hacer, así que simplemente paso nulo y comento la llamada para iniciar sesión en el controlador cuando se ejecuta la prueba. ¿Hay alguna forma de probar pero aún mantener el registrador de alguna manera?

public class BlogControllerTest
{
    [Fact]
    public void Index_ReturnAViewResult_WithAListOfBlog()
    {
        var mockRepo = new Mock<IDAO<Blog>>();
        mockRepo.Setup(repo => repo.GetMany(null)).Returns(GetListBlog());
        var controller = new BlogController(null,mockRepo.Object);

        var result = controller.Index();

        var viewResult = Assert.IsType<ViewResult>(result);
        var model = Assert.IsAssignableFrom<IEnumerable<Blog>>(viewResult.ViewData.Model);
        Assert.Equal(2, model.Count());
    }
}
duc
fuente
1
Puede usar un simulacro como código auxiliar, como sugiere Ilya, si en realidad no está tratando de probar que se llamó al método de registro. Si ese es el caso, burlarse del registrador no funciona y puede probar algunos enfoques diferentes. He escrito un artículo breve que muestra una variedad de enfoques. El artículo incluye un repositorio completo de GitHub con cada una de las diferentes opciones . Al final, mi recomendación es usar su propio adaptador en lugar de trabajar directamente con el tipo ILogger <T>, si es necesario
ssmith
Como mencionó @ssmith, existen algunos problemas al verificar las llamadas reales de ILogger. Tiene algunas buenas sugerencias en su entrada de blog y he venido con mi solución que parece resolver la mayoría de los problemas en la respuesta a continuación .
Ilya Chernomordik

Respuestas:

139

Simplemente burlarse de él, así como de cualquier otra dependencia:

var mock = new Mock<ILogger<BlogController>>();
ILogger<BlogController> logger = mock.Object;

//or use this short equivalent 
logger = Mock.Of<ILogger<BlogController>>()

var controller = new BlogController(logger);

Probablemente necesite instalar el Microsoft.Extensions.Logging.Abstractionspaquete para usarlo ILogger<T>.

Además, puede crear un registrador real:

var serviceProvider = new ServiceCollection()
    .AddLogging()
    .BuildServiceProvider();

var factory = serviceProvider.GetService<ILoggerFactory>();

var logger = factory.CreateLogger<BlogController>();
Ilya Chumakov
fuente
5
para iniciar sesión en la ventana de salida de depuración, llame a AddDebug () en la fábrica: var factory = serviceProvider.GetService <ILoggerFactory> () .AddDebug ();
spottedmahn
3
¡Encontré el enfoque del "registrador real" más efectivo!
DanielV
1
La parte del registrador real también funciona muy bien para probar LogConfiguration y LogLevel en escenarios específicos.
Martin Lottering
Este enfoque solo permitirá el talón, pero no la verificación de llamadas. He venido con mi solución que parece resolver la mayoría de los problemas con la verificación en la respuesta a continuación .
Ilya Chernomordik
102

De hecho, he encontrado la Microsoft.Extensions.Logging.Abstractions.NullLogger<>que parece una solución perfecta. Instale el paquete Microsoft.Extensions.Logging.Abstractions, luego siga el ejemplo para configurarlo y usarlo:

using Microsoft.Extensions.Logging;

public void ConfigureServices(IServiceCollection services)
{
    ...

    services.AddSingleton<ILoggerFactory, NullLoggerFactory>();

    ...
}
using Microsoft.Extensions.Logging;

public class MyClass : IMyClass
{
    public const string ErrorMessageILoggerFactoryIsNull = "ILoggerFactory is null";

    private readonly ILogger<MyClass> logger;

    public MyClass(ILoggerFactory loggerFactory)
    {
        if (null == loggerFactory)
        {
            throw new ArgumentNullException(ErrorMessageILoggerFactoryIsNull, (Exception)null);
        }

        this.logger = loggerFactory.CreateLogger<MyClass>();
    }
}

y prueba unitaria

//using Microsoft.VisualStudio.TestTools.UnitTesting;
//using Microsoft.Extensions.Logging;

[TestMethod]
public void SampleTest()
{
    ILoggerFactory doesntDoMuch = new Microsoft.Extensions.Logging.Abstractions.NullLoggerFactory();
    IMyClass testItem = new MyClass(doesntDoMuch);
    Assert.IsNotNull(testItem);
}   
Amir Shitrit
fuente
Esto parece funcionar solo para .NET Core 2.0, no para .NET Core 1.1.
Thorkil Værge
3
@adospace, su comentario es mucho más útil que la respuesta
johnny 5
¿Puede dar un ejemplo de cómo funcionaría esto? Al realizar pruebas unitarias, me gustaría que aparecieran registros en la ventana de salida, no estoy seguro de si esto hace eso.
J86
@adospace ¿Se supone que debe ir en startup.cs?
raklos
1
@raklos hum, no, se supone que debe usarse en un método de inicio dentro de la prueba donde se
crea una
32

Utilice un registrador personalizado que utilice ITestOutputHelper(de xunit) para capturar la salida y los registros. La siguiente es una pequeña muestra que solo escribe stateen la salida.

public class XunitLogger<T> : ILogger<T>, IDisposable
{
    private ITestOutputHelper _output;

    public XunitLogger(ITestOutputHelper output)
    {
        _output = output;
    }
    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
    {
        _output.WriteLine(state.ToString());
    }

    public bool IsEnabled(LogLevel logLevel)
    {
        return true;
    }

    public IDisposable BeginScope<TState>(TState state)
    {
        return this;
    }

    public void Dispose()
    {
    }
}

Úselo en sus pruebas unitarias como

public class BlogControllerTest
{
  private XunitLogger<BlogController> _logger;

  public BlogControllerTest(ITestOutputHelper output){
    _logger = new XunitLogger<BlogController>(output);
  }

  [Fact]
  public void Index_ReturnAViewResult_WithAListOfBlog()
  {
    var mockRepo = new Mock<IDAO<Blog>>();
    mockRepo.Setup(repo => repo.GetMany(null)).Returns(GetListBlog());
    var controller = new BlogController(_logger,mockRepo.Object);
    // rest
  }
}
Jehof
fuente
1
Hola. esto funciona bien para mí. ahora, ¿cómo puedo verificar o ver la información de mi registro?
Malik Saifullah
Estoy ejecutando los casos de prueba unitarios directamente desde VS. no tengo consola para eso
malik saifullah
1
@maliksaifullah estoy usando resharper. déjame comprobarlo con vs
Jehof
1
@maliksaifullah el TestExplorer de VS proporciona un enlace para abrir la salida de una prueba. seleccione su prueba en TestExplorer y en la parte inferior hay un enlace
Jehof
1
¡Esto es genial, gracias! Un par de sugerencias: 1) esto no necesita ser genérico, ya que no se usa el parámetro de tipo. La implementación solo ILoggerhará que sea más utilizable. 2) El BeginScopeno debe regresar por sí mismo, ya que eso significa que cualquier método probado que comience y termine un alcance durante la ejecución eliminará el registrador. En su lugar, cree una clase anidada "ficticia" privada que implemente IDisposabley devuelva una instancia de eso (luego elimine IDisposablede XunitLogger).
Tobias J
27

Para .net core 3 respuestas que usan Moq

Afortunadamente, stakx proporcionó una buena solución . Así que lo publico con la esperanza de que pueda ahorrar tiempo a otros (tomó un tiempo resolver las cosas):

 loggerMock.Verify(
                x => x.Log(
                    LogLevel.Information,
                    It.IsAny<EventId>(),
                    It.Is<It.IsAnyType>((o, t) => string.Equals("Index page say hello", o.ToString(), StringComparison.InvariantCultureIgnoreCase)),
                    It.IsAny<Exception>(),
                    (Func<It.IsAnyType, Exception, string>) It.IsAny<object>()),
                Times.Once);
Ivan Samygin
fuente
Me salvaste el día ... Gracias.
KiddoDeveloper
15

Agregando mis 2 centavos, este es un método de extensión auxiliar que generalmente se coloca en una clase auxiliar estática:

static class MockHelper
{
    public static ISetup<ILogger<T>> MockLog<T>(this Mock<ILogger<T>> logger, LogLevel level)
    {
        return logger.Setup(x => x.Log(level, It.IsAny<EventId>(), It.IsAny<object>(), It.IsAny<Exception>(), It.IsAny<Func<object, Exception, string>>()));
    }

    private static Expression<Action<ILogger<T>>> Verify<T>(LogLevel level)
    {
        return x => x.Log(level, 0, It.IsAny<object>(), It.IsAny<Exception>(), It.IsAny<Func<object, Exception, string>>());
    }

    public static void Verify<T>(this Mock<ILogger<T>> mock, LogLevel level, Times times)
    {
        mock.Verify(Verify<T>(level), times);
    }
}

Entonces, lo usas así:

//Arrange
var logger = new Mock<ILogger<YourClass>>();
logger.MockLog(LogLevel.Warning)

//Act

//Assert
logger.Verify(LogLevel.Warning, Times.Once());

Y, por supuesto, puede ampliarlo fácilmente para simular cualquier expectativa (es decir, expectativa, mensaje, etc.)

Mahmoud Hanafy
fuente
Esta es una solución muy elegante.
MichaelDotKnox
Estoy de acuerdo, esta respuesta fue muy buena. No entiendo por qué no tiene tantos votos
Farzad
1
Fabuloso Aquí hay una versión para el no genérico ILogger: gist.github.com/timabell/d71ae82c6f3eaa5df26b147f9d3842eb
Tim Abell
¿Sería posible crear un simulacro para verificar la cadena que pasamos en LogWarning? Por ejemplo:It.Is<string>(s => s.Equals("A parameter is empty!"))
Serhat
Esto ayuda mucho. La única pieza que me falta es ¿cómo puedo configurar una devolución de llamada en el simulacro que escribe en la salida de XUnit? Nunca me devuelve la llamada.
flipdoubt
6

Es fácil, como sugieren otras respuestas, aprobar el simulacro ILogger, pero de repente se vuelve mucho más problemático verificar que las llamadas se hicieron realmente al registrador. La razón es que la mayoría de las llamadas no pertenecen a laILogger propia interfaz.

Por tanto, la mayoría de las llamadas son métodos de extensión que llaman al único Log método de la interfaz. La razón por la que parece es que es mucho más fácil implementar la interfaz si solo tiene una y no muchas sobrecargas que se reducen al mismo método.

El inconveniente es, por supuesto, que de repente es mucho más difícil verificar que se ha realizado una llamada, ya que la llamada que debe verificar es muy diferente de la llamada que realizó. Hay algunos enfoques diferentes para solucionar este problema, y ​​he descubierto que los métodos de extensión personalizados para burlarse del marco harán que sea más fácil de escribir.

Aquí hay un ejemplo de un método que he creado para trabajar NSubstitute:

public static class LoggerTestingExtensions
{
    public static void LogError(this ILogger logger, string message)
    {
        logger.Log(
            LogLevel.Error,
            0,
            Arg.Is<FormattedLogValues>(v => v.ToString() == message),
            Arg.Any<Exception>(),
            Arg.Any<Func<object, Exception, string>>());
    }

}

Y así es como se puede utilizar:

_logger.Received(1).LogError("Something bad happened");   

Se ve exactamente como si hubiera usado el método directamente, el truco aquí es que nuestro método de extensión tiene prioridad porque está "más cerca" en los espacios de nombres que el original, por lo que se usará en su lugar.

Desafortunadamente, no da el 100% de lo que queremos, es decir, los mensajes de error no serán tan buenos, ya que no verificamos directamente en una cadena sino en una lambda que involucre la cadena, pero el 95% es mejor que nada :) Además este enfoque hará que el código de prueba

PD Para Moq, uno puede usar el enfoque de escribir un método de extensión para el Mock<ILogger<T>>que noVerify logre resultados similares.

PPS Esto ya no funciona en .Net Core 3, consulte este hilo para obtener más detalles: https://github.com/nsubstitute/NSubstitute/issues/597#issuecomment-573742574

Ilya Chernomordik
fuente
¿Por qué verifica las llamadas del registrador? No forman parte de la lógica empresarial. Si sucediera algo malo, prefiero verificar el comportamiento real del programa (como llamar a un controlador de errores o lanzar una excepción) que registrar un mensaje.
Ilya Chumakov
1
Bueno, creo que es muy importante probar eso también, al menos en algunos casos. He visto demasiadas veces que un programa falla silenciosamente, así que creo que tiene sentido verificar que el registro ocurrió cuando ocurrió una excepción, por ejemplo, y no es como "una o la otra", sino probando tanto el comportamiento real del programa como el registro.
Ilya Chernomordik
5

Ya se mencionó que puede simularlo como cualquier otra interfaz.

var logger = new Mock<ILogger<QueuedHostedService>>();

Hasta aquí todo bien.

Lo bueno es que puede usarlo Moqpara verificar que se hayan realizado ciertas llamadas . Por ejemplo, aquí verifico que se haya llamado al registro con un archivo Exception.

logger.Verify(m => m.Log(It.Is<LogLevel>(l => l == LogLevel.Information), 0,
            It.IsAny<object>(), It.IsAny<TaskCanceledException>(), It.IsAny<Func<object, Exception, string>>()));

Cuando se usa Verifyel punto es hacerlo contra el Logmétodo real de la ILoogerinterfaz y no los métodos de extensión.

Guillem
fuente
5

Basándose aún más en el trabajo de @ ivan-samygin y @stakx, aquí hay métodos de extensión que también pueden coincidir en la excepción y todos los valores de registro (KeyValuePairs).

Estos funcionan (en mi máquina;)) con .Net Core 3, Moq 4.13.0 y Microsoft.Extensions.Logging.Abstractions 3.1.0.

/// <summary>
/// Verifies that a Log call has been made, with the given LogLevel, Message and optional KeyValuePairs.
/// </summary>
/// <typeparam name="T">Type of the class for the logger.</typeparam>
/// <param name="loggerMock">The mocked logger class.</param>
/// <param name="expectedLogLevel">The LogLevel to verify.</param>
/// <param name="expectedMessage">The Message to verify.</param>
/// <param name="expectedValues">Zero or more KeyValuePairs to verify.</param>
public static void VerifyLog<T>(this Mock<ILogger<T>> loggerMock, LogLevel expectedLogLevel, string expectedMessage, params KeyValuePair<string, object>[] expectedValues)
{
    loggerMock.Verify(mock => mock.Log(
        expectedLogLevel,
        It.IsAny<EventId>(),
        It.Is<It.IsAnyType>((o, t) => MatchesLogValues(o, expectedMessage, expectedValues)),
        It.IsAny<Exception>(),
        It.IsAny<Func<object, Exception, string>>()
        )
    );
}

/// <summary>
/// Verifies that a Log call has been made, with LogLevel.Error, Message, given Exception and optional KeyValuePairs.
/// </summary>
/// <typeparam name="T">Type of the class for the logger.</typeparam>
/// <param name="loggerMock">The mocked logger class.</param>
/// <param name="expectedMessage">The Message to verify.</param>
/// <param name="expectedException">The Exception to verify.</param>
/// <param name="expectedValues">Zero or more KeyValuePairs to verify.</param>
public static void VerifyLog<T>(this Mock<ILogger<T>> loggerMock, string expectedMessage, Exception expectedException, params KeyValuePair<string, object>[] expectedValues)
{
    loggerMock.Verify(logger => logger.Log(
        LogLevel.Error,
        It.IsAny<EventId>(),
        It.Is<It.IsAnyType>((o, t) => MatchesLogValues(o, expectedMessage, expectedValues)),
        It.Is<Exception>(e => e == expectedException),
        It.Is<Func<It.IsAnyType, Exception, string>>((o, t) => true)
    ));
}

private static bool MatchesLogValues(object state, string expectedMessage, params KeyValuePair<string, object>[] expectedValues)
{
    const string messageKeyName = "{OriginalFormat}";

    var loggedValues = (IReadOnlyList<KeyValuePair<string, object>>)state;

    return loggedValues.Any(loggedValue => loggedValue.Key == messageKeyName && loggedValue.Value.ToString() == expectedMessage) &&
           expectedValues.All(expectedValue => loggedValues.Any(loggedValue => loggedValue.Key == expectedValue.Key && loggedValue.Value == expectedValue.Value));
}
Mathias R
fuente
1

La mera creación de una simulación ILoggerno es muy valiosa para las pruebas unitarias. También debe verificar que se hayan realizado las llamadas de registro. Puede inyectar un simulacro ILoggercon Moq, pero verificar la llamada puede ser un poco complicado. Este artículo profundiza en la verificación con Moq.

Aquí hay un ejemplo muy simple del artículo:

_loggerMock.Verify(l => l.Log(
LogLevel.Information,
It.IsAny<EventId>(),
It.IsAny<It.IsAnyType>(),
It.IsAny<Exception>(),
(Func<It.IsAnyType, Exception, string>)It.IsAny<object>()), Times.Exactly(1));

Verifica que se haya registrado un mensaje de información. Pero, si queremos verificar información más compleja sobre el mensaje como la plantilla del mensaje y las propiedades nombradas, se vuelve más complicado:

_loggerMock.Verify
(
    l => l.Log
    (
        //Check the severity level
        LogLevel.Error,
        //This may or may not be relevant to your scenario
        It.IsAny<EventId>(),
        //This is the magical Moq code that exposes internal log processing from the extension methods
        It.Is<It.IsAnyType>((state, t) =>
            //This confirms that the correct log message was sent to the logger. {OriginalFormat} should match the value passed to the logger
            //Note: messages should be retrieved from a service that will probably store the strings in a resource file
            CheckValue(state, LogTest.ErrorMessage, "{OriginalFormat}") &&
            //This confirms that an argument with a key of "recordId" was sent with the correct value
            //In Application Insights, this will turn up in Custom Dimensions
            CheckValue(state, recordId, nameof(recordId))
    ),
    //Confirm the exception type
    It.IsAny<NotImplementedException>(),
    //Accept any valid Func here. The Func is specified by the extension methods
    (Func<It.IsAnyType, Exception, string>)It.IsAny<object>()),
    //Make sure the message was logged the correct number of times
    Times.Exactly(1)
);

Estoy seguro de que podrías hacer lo mismo con otros frameworks de burla, pero la ILoggerinterfaz asegura que es difícil.

Christian Findlay
fuente
1
Estoy de acuerdo con el sentimiento y, como dices, puede resultar un poco difícil construir la expresión. Tuve el mismo problema, a menudo, así que recientemente armé Moq.Contrib.ExpressionBuilders.Logging para proporcionar una interfaz fluida que lo hace mucho más agradable.
rgvlee
1

Si todavía es real. Manera simple de registrar la salida en pruebas para .net core> = 3

[Fact]
public void SomeTest()
{
    using var logFactory = LoggerFactory.Create(builder => builder.AddConsole());
    var logger = logFactory.CreateLogger<AccountController>();
    
    var controller = new SomeController(logger);

    var result = controller.SomeActionAsync(new Dto{ ... }).GetAwaiter().GetResult();
}
fotoscar
fuente
0

Utilice Telerik Just Mock para crear una instancia simulada del registrador:

using Telerik.JustMock;
...
context = new XDbContext(Mock.Create<ILogger<XDbContext>>());
bigpony
fuente
0

Intenté burlarme de esa interfaz de Logger usando NSubstitute (y fallé porque Arg.Any<T>()requirió un parámetro de tipo, que no puedo proporcionar), pero terminé creando un registrador de prueba (similar a la respuesta de @ jehof) de la siguiente manera:

    internal sealed class TestLogger<T> : ILogger<T>, IDisposable
    {
        private readonly List<LoggedMessage> _messages = new List<LoggedMessage>();

        public IReadOnlyList<LoggedMessage> Messages => _messages;

        public void Dispose()
        {
        }

        public IDisposable BeginScope<TState>(TState state)
        {
            return this;
        }

        public bool IsEnabled(LogLevel logLevel)
        {
            return true;
        }

        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
        {
            var message = formatter(state, exception);
            _messages.Add(new LoggedMessage(logLevel, eventId, exception, message));
        }

        public sealed class LoggedMessage
        {
            public LogLevel LogLevel { get; }
            public EventId EventId { get; }
            public Exception Exception { get; }
            public string Message { get; }

            public LoggedMessage(LogLevel logLevel, EventId eventId, Exception exception, string message)
            {
                LogLevel = logLevel;
                EventId = eventId;
                Exception = exception;
                Message = message;
            }
        }
    }

Puede acceder fácilmente a todos los mensajes registrados y hacer valer todos los parámetros significativos proporcionados con ellos.

Igor Kustov
fuente