Enhancing logging with JSON

All of us have logged control messages with strings at some point. But there are two drawbacks of string-based logging:

1. It's hard to think of a suitable wording for the log messages, and this uses up valuable time that could've been spent elsewhere.
2. They cannot be programmatically parsed.

String messages are good for human injection, but let's say you have different logging levels, and you want an action to be taken every time a log message of level "error" is generated. Given that it's only provided the contents of the log file, it is impossible to parse the strings in the log file, sometimes you may be able to drill to the relevant information using regular expressions but even that can only be done if you format string messages consistently.

So why not log messages in JSON?

JSON messages eliminate the first problem as all JSON data has a syntax structure, and solves the second problem by virtue of JSON import/export libraries. You can do things like organizing groups of related data into an inner dictionary accessible by another key.

I have started logging all my messages in JSON, with the help of NodeJS loggers such as pino and winston, and it was a very pleasant experience to debug. These basic guidelines will assist you in choosing keys and values for your messages

No null values or keys

This is the most important rule because some loggers like the ones I mentioned above won't log values or keys which are null or undefined, and the key/value pair will be missing completely. So you should have a fallback string such as "(null/undefined)" or whatever best suits your app and log the key or value using the OR conditional to log the fallback string if the value is null, like this: key: value || null_string

Give all your key names the same prefix

So their names don't clash with keys that the loggers themselves write. Pino logs a time key in the JSON, so if you also want to make a time key, then name yours app_time or something else, and make sure the other user-written keys have an app_ prefix as well, just in case.

Log at least one key name in all messages

And make its value the functionality of the app this log message is related to (database, API request, processing etc.) This will allow your analyzer script to assume the existence of at least one key and will let it determine the existence of other keys based on the value of the functionality key.

Example: I log a key {"app_subsystem": string, ...} where the value of string indicates which other keys exist. If the string is "database" then there are keys {..., "app_database": database_name, "app_table": table_name, ...} for the database and table names. If string is "request" then there are keys {..., "app_http_request", request_type, "app_http_headers", http_headers, ...} for the type of request (GET/POST/etc.) and the HTTP headers.

Log a message each time you enter a function

The tricky part is what name you log the function as. I just use the line which indicates the start of a function, so my keys are similar to {"app_function": 'app.get(\'/currentproject\', function (req, res) {'}, where I have just copied the line the anonymous function is defined. In case you're wondering whether I also log line numbers, I do; but only in stack traces.

Log these kind of messages using the lowest log level, usually trace or debug.

Don't log generic objects

This is JSON so everything you log must map to a JSON type. If you try to log a NodeJS object, excluding dictionary, then it will be logged as an empty object {}. Attempt to convert the object into a string using its toString() method first, and if there is no such method then try logging its properties instead. After all it is unnecessary to log function properties of objects.

Log whether the function succeeded or failed

This is arguably the most important key to log because if you don't log this, then how will you find the root of errors? It can simply be a boolean value with a key named something like "success", and if the value is false, a key with the error message or stack trace in it, or if the value is true, a key with the stringified result.

Finally I should note that even those I wrote this guide with NodeJS in mind, this logging technique is not solely applicable to NodeJS and can be used in any programming language that can read and write files.