Write small methods. How small? Small enough that any unhandled exception is easy to troubleshoot.

Imagine that you receive a bug report. This one include a logged exception:

System.NullReferenceException: Object reference not set to an instance of an object.
   at Ploeh.Samples.BookingApi.Validator.Validate(ReservationDto dto)
   at Ploeh.Samples.BookingApi.ReservationsController.Post(ReservationDto dto)
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
   at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
		

Oh, no, you think, not a NullReferenceException.

If you find it hard to troubleshoot NullReferenceExceptions, you're not alone. It doesn't have to be difficult, though. Open the method at the top of the stack trace, Validate:

public static class Validator
{
    public static string Validate(ReservationDto dto)
    {
        if (!DateTime.TryParse(dto.Date, out var _))
            return $"Invalid date: {dto.Date}.";
        return "";
    }
}

Take a moment to consider this method in the light of the logged exception. What do you think went wrong? Which object was null?

Failed hypothesis #

You may form one of a few hypotheses about which object was null. Could it be dto? dto.Date? Those are the only options I can see.

When you encounter a bug in a production system, if at all possible, reproduce it as a unit test.

If you think that the problem is that dto.Date is null, test your hypothesis in a unit test:

[Fact]
public void ValidateNullDate()
{
    var dto = new ReservationDto { Date = null };
    string actual = Validator.Validate(dto);
    Assert.NotEmpty(actual);
}

If you think that a null dto.Date should reproduce the above exception, you'd expect the test to fail. When you run it, however, it passes. It passes because DateTime.TryParse(null, out var _) returns false. It doesn't throw an exception.

That's not the problem, then.

That's okay, this sometimes happens. You form a hypothesis and fail to validate it. Reject it and move on.

Validated hypothesis #

If the problem isn't with dto.Date, it must be with dto itself. Write a unit test to test that hypothesis:

[Fact]
public void ValidateNullDto()
{
    string actual = Validator.Validate(null);
    Assert.NotEmpty(actual);
}

When you run this test, it does indeed fail:

Ploeh.Samples.BookingApi.UnitTests.ValidatorTests.ValidateNullDto
  Duration: 6 ms

  Message: 
    System.NullReferenceException : Object reference not set to an instance of an object.
  Stack Trace: 
    Validator.Validate(ReservationDto dto) line 12
    ValidatorTests.ValidateNullDto() line 36

This looks like the exception included in the bug report. You can consider this as validation of your hypothesis. This test reproduces the defect.

It's easy to address the issue:

public static string Validate(ReservationDto dto)
{
    if (dto is null)
        return "No reservation data supplied.";
    if (!DateTime.TryParse(dto.Date, out var _))
        return $"Invalid date: {dto.Date}.";
    return "";
}

The point of this article, however, is to show that small methods are easy to troubleshoot. How you resolve the problem, once you've identified it, is up to you.

Ambiguity #

Methods are usually more complex than the above example. Imagine, then, that you receive another bug report with this logged exception:

System.NullReferenceException: Object reference not set to an instance of an object.
   at Ploeh.Samples.BookingApi.MaîtreD.CanAccept(IEnumerable`1 reservations, Reservation reservation)
   at Ploeh.Samples.BookingApi.ReservationsController.Post(ReservationDto dto)
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
   at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)

When you open the code file for the MaîtreD class, this is what you see:

public class MaîtreD
{
    public MaîtreD(int capacity)
    {
        Capacity = capacity;
    }
 
    public int Capacity { get; }
 
    public bool CanAccept(IEnumerable<ReservationreservationsReservation reservation)
    {
        int reservedSeats = 0;
        foreach (var r in reservations)
            reservedSeats += r.Quantity;
 
        if (Capacity < reservedSeats + reservation.Quantity)
            return false;
 
        return true;
    }
}

This code throws a NullReferenceException, but which object is null? Can you identify it from the code?

I don't think that you can. It could be reservations or reservation (or both). Without more details, you can't tell. The exception is ambiguous.

The key to making troubleshooting easy is to increase your chances that, when exceptions are thrown, they're unambiguous. The problem with a NullReferenceException is that you can't tell which object was null.

Remove ambiguity by protecting invariants #

Consider the CanAccept method. Clearly, it requires both reservations and reservation in order to work. This requirement is, however, currently implicit. You can make it more explicit by letting the method protect its invariants. (This is also known as encapsulation. For more details, watch my Pluralsight course Encapsulation and SOLID.)

A simple improvement is to add a Guard Clause for each argument:

public bool CanAccept(IEnumerable<ReservationreservationsReservation reservation)
{
    if (reservations is null)
        throw new ArgumentNullException(nameof(reservations));
    if (reservation is null)
        throw new ArgumentNullException(nameof(reservation));
 
    int reservedSeats = 0;
    foreach (var r in reservations)
        reservedSeats += r.Quantity;
 
    if (Capacity < reservedSeats + reservation.Quantity)
        return false;
 
    return true;
}

If you'd done that from the start, the logged exception would instead have been this:

System.ArgumentNullException: Value cannot be null.
Parameter name: reservations
   at Ploeh.Samples.BookingApi.MaîtreD.CanAccept(IEnumerable`1 reservations, Reservation reservation)
   at Ploeh.Samples.BookingApi.ReservationsController.Post(ReservationDto dto)
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
   at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)

It's now clear that it was the reservations argument that was null. Now fix that issue. Why does the CanAccept receive a null argument?

You may now consider examining the next frame in the stack trace: ReservationsController.Post:

public ActionResult Post(ReservationDto dto)
{
    var validationMsg = Validator.Validate(dto);
    if (validationMsg != "")
        return BadRequest(validationMsg);
 
    var reservation = Mapper.Map(dto);
    var reservations = Repository.ReadReservations(reservation.Date);
 
    var accepted = maîtreD.CanAccept(reservationsreservation);
    if (!accepted)
        return StatusCode(
            StatusCodes.Status500InternalServerError,
            "Couldn't accept.");
    var id = Repository.Create(reservation);
    return Ok(id);
}

The Post code only calls CanAccept once, so again, you can unambiguously deduce where the null reference comes from. It comes from the Repository.ReadReservations method call. Now go there and figure out why it returns null.

Notice how troubleshooting is trivial when the methods are small.

Size matters #

How small is a small method? How large does a method have to be before it's no longer small?

A method is small when you can easily troubleshoot it based exclusively on a logged exception.

Until you get the hang of it, it can be hard to predict if a method is going to be easy to troubleshoot. I therefore also follow another rule of thumb:

For languages like C#, methods should have a maximum size of 80x24 characters.

What if you already have bigger methods? Those are much harder to troubleshoot. If you have a method that spans hundreds of lines of code, a logged exception is rarely sufficient for troubleshooting. In order to save space, I'm not going to show en example of such a method, but I'm sure that you can easily find one in the code base that you professionally work with. Such a method is likely to have dozens of objects that could be null, so a NullReferenceException and a stack trace will contain too little information to assist troubleshooting.

I often see developers add tracing or logging to such code in order to facilitate troubleshooting. This makes the code even more bloated, and harder to troubleshoot.

Instead, cut the big method into smaller helper methods. You can keep the helper methods private so that you don't change the API. Even so, a logged exception will now report the helper method in its stack trace. Keep those helper methods small, and troubleshooting becomes trivial.

Conclusion #

Small methods come with many benefits. One of these is that it's easy to troubleshoot a small method from a logged exception. Small methods typically take few arguments, and use few variables. A logged exception will often be all that you need to pinpoint where the problem occurred.

A large method body, on the other hand, is difficult to troubleshoot. If all you have is a logged exception, you'll be able to find multiple places in the code where that exception could have been thrown.

Refactor big methods into smaller helper methods. If one of these helper methods throws an exception, the method name will be included in the stack trace of a logged exception. When the helper method is small, you can easily troubleshoot it.

Keep methods small. Size does matter.


Comments

Tyson Williams

How did you create those exception stack traces?

Compared to your examples, I am used to seeing each stack frame line end with the source code line number. (Although, sometimes I have seen all line numbers being 0, which is equivalent to having no line numbers at all.) The exception stack trace in your unit test includes line numbers but your other exception stack traces do not. This Stack Overflow answer contains an exception stack trace like with line numbers like I am used to seeing.

The line containing "lambda_method" also seem odd to me. As I recall, invoking a lambda expression also contributes more information to the stack trace than your examples include. Although, that information is cryptic enough that I don't remember off the top of my head what it means. (After a quick search, I didn't find a good example of how I am used to seeing lambda expressions displayed in a stack trace.)

With this additional informaiton, the methods can be longer while reamining unambiguous (in the sense you described).

2019-11-18 14:57 UTC

Tyson, thank you for writing. IIRC, you only see line numbers for code compiled with debug information. That's why you normally don't see line numbers for .NET base class library methods, ASP.NET Core, etc.

While you can deploy and run an application in Debug mode, I wouldn't. When you compile in Release mode, the compiler makes optimisations (such as in-lining) that it can't do when it needs to retain a map to a specific source. In Debug mode, you squander those optimisations.

I've always deployed systems in Release mode. To make the examples realistic, I didn't include the line numbers in the stack trace, because in Release mode, they aren't going to be there.

When you're troubleshooting by reproducing a logged exception as a unit test, on the other hand, it's natural to do so in Debug mode.

2019-11-18 16:39 UTC
Tyson Williams

I just tried to verify this. I didn't find any difference between compiling in Debug or Release mode as well as no fundemental issue with in-lining. In all four cases (debug vs release and in-lining vs no inlining), exception stack traces still included line numbers. When in-lining, the only different was the absense of the in-lined method from the stack trace.

Instead, I found that line numbers are included in exception stack traces if and only if the corresponding .pdb file is next to the .exe file when executed.

2019-11-18 19:07 UTC

Tyson, that sounds correct. To be honest, I stopped putting effort into learning advanced debugging skills a long time ago. Early in my career we debugged by writing debug statements directly to output! Then I learned test-driven development, and with that disappeared most of the need to debug full systems. At the time I began working with systems that logged unhandled exceptions, the habit of writing small methods was already so entrenched that I never felt that I needed the line numbers.

FWIW, more than five years ago, I decided to publish symbols with AutoFixture, but I never found it useful.

2019-11-19 7:18 UTC


Wish to comment?

You can add a comment to this post by sending me a pull request. Alternatively, you can discuss this post on Twitter or somewhere else with a permalink. Ping me with the link, and I may respond.

Published

Monday, 18 November 2019 06:48:00 UTC

Tags



"Our team wholeheartedly endorses Mark. His expert service provides tremendous value."
Hire me!
Published: Monday, 18 November 2019 06:48:00 UTC