Separate Implementation and Diagnostic Code

Photo by Christian Wiediger on Unsplash

The Single Responsibility Principle (SRP) states that 

“Every module should only be responsible for one and only one actor.”

In this context, ‘actor’ means a group of system users. It’s a term that originated from UML, the Unified Modelling Language, which was the object modelling methodology of choice in the 1990s and early 2000s.

Can you tell why the method GetAccount() on AccountProvider is violating the SRP?

  public async Task<Account> GetAccount(string accountNumber)
  {
     await Logger.LogDebug($"Call AccountProvider.GetAccount('{accountNumber}').");
     var account = await Reader.GetAccount(accountNumber);
     var result = account != null ? $"a '{account.BankName}' account" : "null";
     await Logger.LogDebug($"AccountProvider.GetAccount('{accountNumber}') returned {result}.");
     return account;
  }

No? Seems OK? 

The SRP has raised the protest flag on AccountProvider.GetAccount() because it is subject to change from two actors:

1. The application end-user wants the functionality to work and an account retrieved. They would be the actor asking for changes to how the account is requested. For example, to enable global banking, they may want an international bank identifier to the account.
2. Those diagnostic log statements sure are handy for debugging, but they do obscure the real action—the call to Reader.GetAccount(). Who is interested in this logging code? Well, we, the programmers, are. We want to see where and why the application fell over in production. 

In effect, the SRP urges us to have the logging statements in a separate place from the functional code. How could we remove the diagnostics into a different class and still log? Today I’ll show you one way.

Here’s your step by step guide to separating logging:

1. Make AccountProvider's GetAccount() virtual:

  public virtual async Task<Account> GetAccount(string accountNumber)

 2. Create another class called LoggedAccountProvider that derives from AccountProvider:

  public class LoggedAccountProvider : AccountProvider

 3. Override GetAccount() in LoggedAccountProvider:

  public override async Task<Account> GetAccount(string accountNumber)

 4. Move the logging code to LoggedAccountProvider and ensure that the base class method, ie. AccountProvider, is called in between the log statements:

  public override async Task<Account> GetAccount(string accountNumber)
  {
     await Logger.LogDebug($"Call AccountProvider.GetAccount('{accountNumber}').");
     var account = await base.GetAccount(accountNumber);
     var result = account != null ? $"a '{account.BankName}' account" : "null";
     await Logger.LogDebug($"AccountProvider.GetAccount('{accountNumber}') returned {result}.");
     return account;
  }

and AccountProvider.GetAccount() becomes simply:

  public virtual async Task<Account> GetAccount(string accountNumber)
  {
     return await Reader.GetAccount(accountNumber);       
  }

How neat is GetAccount()? All the logging cruft has moved out and moved in with LoggedAccountProvider. Now that all the noise is gone, we can see what is going on.

When we want to log, then use LoggedAccountProvider, otherwise use AccountProvider.

This “Extract & Override” technique works best when the application partitioning is well-thought-out and in small classes. It is then possible to confine logging to the start and end of each method. This approach is useless in large functions where log statements are on every third line.

Nowadays, when I see log statements, database logic or web context mixed in with business logic, I cringe. I suspect you might now too. Once you’ve seen the light, you can’t unsee it.

Please consider removing logging into separate modules using the demonstrated technique—or others.