Function A() calls B() calls C(), which encounters an error. Which function writes to the log and which function reports to the user?
My first inclination is that all functions should write to the log, and that the inner-most UI-facing function should be responsible for outputting the error to the user. However, the fix needs to be done in C(), so perhaps instead of having an super-long log file which will take a while to parse, I should simply have the function which encountered the error log the error and the parameters used to call it.
Likewise, I’m not too convinced that the inner-most UI-facing function should output the error (consider CLI apps, as opposed to web or GUI apps). That was more of a gut-feeling decision, so any insight into actually engineering a solution would be appreciated.
As there are two distinct audiences for the error report, with completely different information needs, it makes sense to have the error reporting at multiple levels.
On the one hand, there are the developers who need to know exactly where the error was detected and all the nitty gritty details of the error itself. As the developers are also the ones who analyse the log files, it makes most sense to produce a log for an error as soon as it is detected, where most of the relevant information for the developers is still at hand and can be incorporated in the log.
On the other hand, the end-users of the application don’t really care about what went wrong. They just want to know if the function they requested succeeded and if not, what they can do to make it succeed the next time.
This information is at a higher level of abstraction than the usual error-detection code and usually not even known at the level where the error is first detected.
For example, if there is an error when saving a file, the code responsible for writing the data to disk can’t know if the save action was triggered automatically or by explicit request from the user, but that is important information when deciding how to inform the end-user of the problem.
In summary, error reports should be generated at the level where the information is at the right abstraction level to provide a meaningful and helpful report to the intended audience of the report.
Additionally, human readable texts meant for end-users should be generated in the UI components of the application to ensure that only the UI is affected if you need to support additional languages for the end users.
Logging
Let me start with the logging. Well as I’m sure you’re aware, there are various logging levels which most libraries support: Debug, Info, Warning, and Error.
My approach is that Debug output should show all information that I, the programmer, would want to see. The user using your program isn’t likely going to want to see that you entered a specific method in the GUI, but I would in the case of a crash. If you have no way of retrieving the stack trace of the crash, then the next best thing is to print out to the log the entry and exit of every method in your program with log level debug.
In your example, that means a log with the following output:
DEBUG <timestamp>: ClassA::A() : Entering A
DEBUG <timestamp>: ClassB::B() : Entering B
DEBUG <timestamp>: ClassC::C() : Entering C
DEBUG <timestamp>: ClassC::C() : Exiting C // These don't show
DEBUG <timestamp>: ClassB::B() : Exiting B // in the case of
DEBUG <timestamp>: ClassA::A() : Exiting A // an error in C.
Log level Info is information that I would consider to be relevant to functionality of the program. Suppose for the purposes of this example that the objective of A is to perform an operation using a selected database, B is a means to view existing database connections and to create new database connections, and C is the specific information pertaining to a new database and a way of testing said connection.
Relevant Info level log messages for me would be:
INFO <timestamp>: ClassC::C() : Saved database connection "localhost".
INFO <timestamp>: ClassA::A() : Performing transaction using database connection "localhost".
INFO <timestamp>: ClassA::A() : Transaction complete using database connection "localhost".
Notice that these are messages you would also likely want to show to the user throughout the program (albeit a little verbose). For me that is the difference between Debug and Info: whether or not the user may also want to see this information. Obviously logging levels warning and error should also be both logged and shown to the user.
WARNING <timestamp>: ClassC::C() : Connection test for "localhost" failed.
What I typically do in my programs is take an optional parameter which determines at what logging level I should present messages to the user with a default value of Info. If the user does not want a verbose interface, he or she can set it to Warning instead and see only warnings and errors, and I can use it in order to output debugging information, for example. In that case, just be sure to provide an alternative indicator that a particular task is finished (execute button becomes disabled during elaboration then afterwards becomes again enabled, for instance).
Exceptions
That said, how do I approach exceptions? It depends on the context of the error. If ClassC handles creation of new database connections and upon testing the connection, throws an exception, I would want to handle that sql exception inside ClassC since I am expecting potential problems. Notice that I would only handle a sql exception. If the problem were another that I wasn’t expecting, it would slip through Class C and consequently move to ClassB. ClassB may decide to catch exceptions related to missing drivers, since that is not entirely unexpected, and I wouldn’t want such problems to be caught at lower levels.
However, assuming it is not either, we hit ClassA who’s only role in calling ClassB was to allow the user the possibility to create new database connections. If an exception hits ClassA, something serious has happened. In such instances, what I typically do is to catch any exception, write the error and its stacktrace (if possible) to the log, show an unexpected error message to the user, then rethrow the exception. In my personal opinion, it is irresponsible to catch all exceptions without being prepared to rethrow it, since it is correct that unexpected errors are still thrown.
The important point to note here is the level of responsibility. The exceptions that I’m expecting are handled locally while unexpected exceptions in the context of my class are allowed to move up the chain. In the absolute worst case, be sure to try to log the error and show an error message to the user. Combine this with precision logging, and you’re sure to be able to trace your steps to the place of error in most cases.