Should I log errors on exception throwing constructors?

Question

I was building an application for a few months and I come to realize a pattern that emerged:

logger.error(ERROR_MSG);
throw new Exception(ERROR_MSG);

Or, when catching:

try { 
    // ...block that can throw something
} catch (Exception e) {
    logger.error(ERROR_MSG, e);
    throw new MyException(ERROR_MSG, e);
}

So, whenever I was throwing or catching an exception, I would log it. In fact, that was almost all logging I did on the application (besides something for application initialization).

So, as a programmer, I shun repetition; So I decided to move the logger calls to the exception construction, so, whenever I was building an exception, things would be logged. I could also, certainly, create a ExceptionHelper that throwed the exception for me, but that would make my code harder to interpret and, even worse, the compiler wouldn't deal well with it, failing to realize that a call to that member would throw immediately.

So, is this an anti-pattern? If so, why?

Answer 1

Not sure if it qualifies as an anti-pattern, but IMO it's a bad idea: it's unnecessary coupling to intertwine an exception with logging.

You might not always want to log all instances of a given exception (maybe it occurs during input validation, the logging of which might be both voluminous and uninteresting).

Secondly, you might decide to log different occurrences of an error with different logging levels, at which point you'd have to specify that when constructing the exception, which again represents muddying the exception creation with logging behavior.

Finally, what if exceptions occurred during the logging of another exception? Would you log that? It gets messy...

Your choices basically are:

• Catch, log and (re)throw, as you gave in your example
• Create an ExceptionHelper class to do both for you, but Helpers have a code smell, and I wouldn't recommend this either.
• Move the catch-all exception handling to a higher level
• Consider AOP for a more sophisticated solution to cross-cutting concerns such as logging and exception handling (but far more complex than just having those two lines in your catch blocks ;) )

Answer 2

So, as a programmer, I shun repetition [...]

There is a danger here whenever the concept of "don't repeat yourself" is taken a little too seriously to the point where it becomes the smell.

Answer 3

To echo @Dan1701

This is about separation of concerns - moving the logging into the exception creates tight coupling between the exception and the logging and also means that you've added an additional responsibility to the exception of logging which in turn may create dependencies for the exception class that it doesn't need.

From a maintenance point of view you can (I would) argue that you're hiding the fact that the exception is being logged from the maintainer (at least in the context of something like the example), you're also changing the context (from the location of the exception handler to the constructor of the exception) which is probably not what you intended.

Finally you're making an assumption that you always want to log an exception, in exactly the same fashion, at the point at which its created/raised - which is probably not the case. Unless you're going to have logging and non-logging exceptions which would get deeply unpleasant quite quickly.

So in this case I think "SRP" trumps "DRY".

Answer 4

Your error is logging an exception where you cannot handle it, and thus cannot know whether logging is any part of properly handling it.
There are very few cases where you can or must handle part of the error, which might include logging, but must still signal the error to the caller. Examples are uncorrectable read-errors and the like, if you do the lowest-level reading, but they generally have in common that the info communicated to the caller is severely filtered, for security and usability.

The only thing you can do in your case, and for some reason have to do, is translating the exception the implementation throws into one the caller expects, chaining the original for context, and leaving anything else well alone.

To sum it up, your code arrogated right and duty for partial handling of the exception, thus violating the SRP.
DRY doesn't come into it.

Answer 5

I know it's an old thread, but I just came across a similar problem and figured out a similar solution so I'll add my 2 cents.

I don't buy the SRP violation argument. Not entirely anyway. Let's assume 2 things: 1. You actually do want to log exceptions as they occur (at trace level to be able to recreate program flow). This has nothing to do with handling exceptions. 2. You can't or you won't use AOP for that - I agree that would be the best way to go but unfortunately I'm stuck with a language that doesn't provide tools for that.

The way I see it, you're basically sentenced to a large scale SRP violation, because any class that wants to throw exceptions has to be aware of the log. Moving logging to the exception class actually greatly reduces the SRP violation because now only the exception violates it and not every class in the code base.

Answer 6

Rethrowing an exception only because you decided to log it using a catch block (meaning the exception has not changed at all) is a bad idea.

One of the reasons we use exceptions, exceptions messages and its handling is so that we know what went wrong and cleverly written exceptions can speed up finding the bug by a great margin.

Also remember, handling exceptions costs way more resources than let's say have an if, so you shouldn't be handling them all to often just because you feel like it. It has impact on the performance of your application.

It is however good approach to use exception as a mean to mark the application layer in which the error appeared.

Consider the following semi-pseudo code:

interface ICache<T, U>
{
    T GetValueByKey(U key); // may throw an CacheException
}

class FileCache<T, U> : ICache<T, U>
{
    T GetValueByKey(U key)
    {
        throw new CacheException("Could not retrieve object from FileCache::getvalueByKey. The File could not be opened. Key: " + key);
    }
}

class RedisCache<T, U> : ICache<T, U>
{
    T GetValueByKey(U key)
    {
        throw new CacheException("Could not retrieve object from RedisCache::getvalueByKey. Failed connecting to Redis server. Redis server timed out. Key: " + key);
    }
}

class CacheableInt
{
    ICache<int, int> cache;
    ILogger logger;

    public CacheableInt(ICache<int, int> cache, ILogger logger)
    {
        this.cache = cache;
        this.logger = logger;
    }

    public int GetNumber(int key) // may throw service exception
    {
        int result;

        try {
            result = this.cache.GetValueByKey(key);
        } catch (Exception e) {
            this.logger.Error(e);
            throw new ServiceException("CacheableInt::GetNumber failed, because the cache layer could not respond to request. Key: " + key);
        }

        return result;
    }
}

class CacheableIntService
{
    CacheableInt cacheableInt;
    ILogger logger;

    CacheableInt(CacheableInt cacheableInt, ILogger logger)
    {
        this.cacheableInt = cacheableInt;
        this.logger = logger;
    }

    int GetNumberAndReturnCode(int key)
    {
        int number;

        try {
            number = this.cacheableInt.GetNumber(key);
        } catch (Exception e) {
            this.logger.Error(e);
            return 500; // error code
        }

        return 200; // ok code
    }
}

Let's assume someone has called the GetNumberAndReturnCode and recieved the 500 code, signaling an error. He would call the support, who would open the log file and see this:

ERROR: 12:23:27 - Could not retrieve object from RedisCache::getvalueByKey. Failed connecting to Redis server. Redis server timed out. Key: 28
ERROR: 12:23:27 - CacheableInt::GetNumber failed, because the cache layer could not respond to request. Key: 28

The developer then immediately knows which layer of the software caused the process to abort and has an easy way of identifying the issue. In this case it is critical, because Redis timing out should never happend.

Perhaps another user would call the same method, also recieve the 500 code, but log would show the following:

INFO: 11:11:11- Could not retrieve object from RedisCache::getvalueByKey. Value does not exist for the key 28.
INFO: 11:11:11- CacheableInt::GetNumber failed, because the cache layer could not find any data for the key 28.

In which case the support could simply respond to the user that the request was invalid because he is requesting a value for a non-existent ID.

---

Summary

If you are handling exceptions, make sure to handle them in the correct way. Also make sure your exceptions include the correct data/messages in the first place, following your architecture layers, so the messages will help you identify a problem which may occur.

Answer 7

I think the problem is on a more basic level: you log the error and throw it as an exception at the same place. That's the anti-pattern. This means the same error is logged many times if it is caught, perhaps wrapped into another exception and and re-thrown.

Instead of this I suggest to log errors not when the exception is created, but when it is caught. (For this, of course, you must make sure it is always caught somewhere.) When an exception is caught, I'd only log its stacktrace if it is not re-thrown or wrapped as cause into another exception. The stacktraces and messages of wrapped exceptions are logged in stack traces as "Caused by ...", anyway. And the catcher could also decide e.g. to retry without logging the error on the first failure, or just treat it as a warning, or whatever.

Answer 8

This is an anti-pattern.

In my opinion, making a logging call in the constructor of an exception would be an example of the following: Flaw: Constructor does Real Work.

I would never expect (or desire) a constructor to make some external service call. That's a very undesirable side-effect which, as Miško Hevery points out, forces subclasses and mocks to inherit unwanted behavior.

As such, it would also violate the principle of least astonishment.

If you're developing an application with others, then this side-effect will likely not be apparent to them. Even if you're working alone, you may forget about it and surprise yourself down the road.