A program's (effective) log messages can have many sources

August 9, 2023

One of the things you could say about log messages from programs is that even a program doesn't want to commit to long term stability of its log messages (which I think it shouldn't), it should be able to document a list of the messages for any particular release. Then system administrators and other parties could go through the documentation with some confidence to build log parsing and matching rules for the current version.

(You can imagine plausible ways of collecting such a list, since we've already faced this general issue of a 'message catalog' when it comes to localization and have developed various tools for it.)

Unfortunately, modern life is not quite so convenient, because in a typical modern programming environment not all of the messages that your program will emit come from its own code. My recent issue with the Prometheus host agent crashing makes an excellent example, because the crash didn't come from the the host agent's code. Instead it came from the Go runtime detecting an internal deadlock and panicing; as part of the panic, the runtime printed various information, including such reports as 'fatal error: all goroutines are asleep - deadlock!' (plus a bunch of stack traces).

On the one hand, of course we want language runtime environments to print messages instead of silently terminating your process (or worse, not terminating your process even when it's known to be deadlocked). Similar things hold for third party libraries and packages our programs use, in situations where it's impossible to return an error to the caller or otherwise keep on going. On the other hand, as a practical matter these other sources of messages are very unlikely to supply a message catalog or be interested in doing so (and they're almost certainly not interested in committing to these messages as an API that will be preserved over time). Most language runtimes and third party libraries have other priorities.

(A corollary to this is that simply rebuilding your program with a different version of your language's runtime may change the messages that it can emit, as can changing the versions of third party code.)

So while you can certainly collect a log message catalog for your own code, some of the most interesting and dangerous log messages will probably not be included in that catalog. Similarly, while your program may emit structured logging from your own code, there's no guarantee that your language runtime or other things will.

Of course in some sense (and in some environments) these messages won't be logged to the same place as your program's regular log messages and thus may not be considered log messages at all. For example, in a pre-systemd Unix environment, often anything a program printed out in operation would simply be discarded, with only things sent to syslog being captured. In this kind of environment, we might have had no output at all to explain why the Prometheus host agent was being restarted.

(As a system administrator, I tend to take a whole system view of log messages. In the modern Linux systemd world, pretty much everything a program prints out, syslogs, or records to the systemd journal tends to wind up in the same place, all mixed together and all mixed with the same from other programs. There are still programs that write logs to dedicated locations, often for good reason, but they're somewhat the minority for our systems.)

Written on 09 August 2023.
« Programs shouldn't commit to fixed and predictable log messages
Browsers barely care what HTTP status code your web pages are served with »

Page tools: View Source, Add Comment.
Login: Password:
Atom Syndication: Recent Comments.

Last modified: Wed Aug 9 23:14:58 2023
This dinky wiki is brought to you by the Insane Hackers Guild, Python sub-branch.