this resulted in – you guessed it – a classic out-of-order deadlock scenario
Wait – does this log component stupidly acquire a long-lived lock, or did you use it in a stupid way?
If your logging is deadlocking you, there is stupid going on. A logger only needs a lock to serialise information going into the log, so …
Option 1: use one log file per thread. No locking required.
Option 2: dedicate one thread to logging. Other threads enter a critical section just long enough to write to a buffer; the log thread commits the buffer to disk when it has the time.
Option 3: sacrifice performance and enter+leave the critical section on every log call.
Option 4: do something stupid and get deadlocked.
Logging means more code
Then use a language or addon (like AOP) that can inject logging automatically.
it actively obscures the code that’s doing the real work
You’re assuming logging doesn’t do real work. 8 years of maintaining applications that run at customer sites in other cities suggest otherwise.
If it’s worth saving to a logfile, it’s worth showing in the user interface.
No. The user interface is there to interact with the user. Event logging is there for the administrator to get a summary of what’s going on (alerts, errors, warnings, changes in configuration, access to sensitive data, etc). These all relate to the operational requirements of the application.
What you are describing - primarily - is debug logging: dumping enough stuff in enough detail to help a developer figure out what went wrong, and why.
Logging isn’t free.
No, it’s not. Which is why most sensible logging subsystems will have a runtime option to change the log detail level, and will start with a quick check to determine if the log statement in question needs processing or not. In C/C++ one would use macros for this, to avoid a function call if the particular log statement isn’t going to be executed.
The more you log, the less you can find.
YMMV. This depends substantially on how your log is presented (does it have a way to show stack depth, for example), what you are logging, how consistently you are logging, and whether you have tools to parse the logs.
it’s the brainpower needed to make sense of these giant logs.
Or the brainpower needed to log sensibly. Here are some approaches:
Don’t allow a single concern or transaction to cross a thread boundary. Use one log file per thread, or include the thread id in the log, and it is easy to reconstruct the transaction.
Tag each transaction with a system-wide unique ID, and make sure it gets logged. It is now easy to reconstruct the transaction.
Good luck getting everyone on your team to agree on the exact definitions of FATAL, ERROR, DEBUG, INFO, and whatever other logging levels you have defined.
It doesn’t matter. So long as there is agreement on what goes to the event log (read by the administrator, not the developers) and what goes to the development log (development only) … and that’s a customer requirements problem.
The whole problem here is that you see logging as some optional extra. That’s kindof like a civil engineer dismissing drainage as an optional extra - sure it’s not the core of the building, but you’re going to end up knee-deep in shit if you leave it out! Design to accomodate it from the outset and it will perform as expected.