Sometimes there’s a path in a service or application that you want to test where all it does is log something and return. You could check other things, but sometimes it is hard to check to see if something didn’t happen… and it would be a lot easier to know if something did happen, like a log message. Or, heck, maybe you just really want to make sure that logging happened! Logging is important and can save your skin, so… I get it.
Scenario
Consider this scenario using Common Logging, a popular logging abstraction framework for C#:
private readonly ILog _log = LogManager.GetLogger<MyService>(); | |
public void ProcessOrder(int orderId, List<Item> items) | |
{ | |
if (!items.Any()) | |
{ | |
// We want to test this scenario | |
_log.Error($"Tried to process order {orderId}, but it " + | |
"had no items associated with it!"); | |
return; | |
} | |
// ... Process the order ... | |
_log.Trace($"Processing order {orderId}"); | |
_database.AddOrder(items); | |
} |
Obviously this is contrived, and we could easily check to make sure that _database.AddOrder is not called to verify that we hit the conditional, but suppose that there were more conditionals that you hit, or that you had some kind of consumer on your logging endpoint that would trigger an alert if certain log messages are seen. In that case, you might want to know that you hit this specific branch of the code when provided with a set of parameters.
Problem
The problem is that we have our ILog marked as readonly and being initialized through Common Logging’s LogManager. Presumably NLog or similar is configured in our application’s startup to handle how logs are created, so this works just fine at runtime. If you’re using a dependency injection framework, you could inject the ILog in to the constructor of MyService… but if you’re not, it makes it a little bit tricky to provided a mocked ILog to test and make sure that an expected log message was issued. You could use reflection to set the backing field if you really wanted to, but that would probably involve adding an additional dependency to your project or knowing a lot more about how C# does things under the covers… and, I mean, if that’s your thing, that’s cool, but I’d rather just do it an easy way.
LogManager
Luckily, LogManager is easily told how to create loggers, so we can use that to our advantage and make a fake adapter to provide a mock, which we can then verify at our leisure.
// Create a helper function to create a mocked logger and | |
// a copy of our service to test | |
private (MyService service, Mock<ILog> logMock) Setup() | |
{ | |
// Create a mocked logger | |
var logMock = new Mock<ILog>(); | |
// Create a mocked log adapter | |
var loggerAdapter = new Mock<ILoggerFactoryAdapter>(); | |
// Set up the log adapter to return our mocked logger | |
loggerAdapter.Setup(la => la.GetLogger(It.IsAny<Type>())) | |
.Returns(logMock.Object): | |
// Set the LogManager's adapter to be our mocked adapter | |
LogManager.Adapter = loggerAdapter.Object; | |
// Create the service | |
MyService service = new MyService(); | |
// Return both | |
return (service, logMock); | |
} |
[Test(DisplayName = "ProcessOrder should log an error when the list of items is empty")] | |
public void ProcessOrder_NoItems_LogsError() | |
{ | |
// Get our service and our logger mock | |
(var service, var logMock) = Setup(); | |
// Invoke a function to test | |
service.ProcessOrder(42, new List<Item>()); | |
// Verify that logging happened | |
logMock.Verify(l => l.Error(It.Is<string>(m => | |
m.Contains("had no items"))), Times.Once()); | |
} |
As you can see, it wasn’t exactly straightforward, so I wrote it down. Hopefully its useful!