Observability - logging

Observability

It's super frustrating to not know what your application is doing at runtime. And even more so when people tell you "it's not doing so well today" and you have no idea why that may be. That is why you should think about observability when you architect your application. Or your architect should think about it. Well somebody should.

So what is it? Well, it could be a simple "I'm alive" healthcheck or it could be full blown application profiling depending on you or your users' needs. Often it's somewhere in between. I like to be able to monitor performance counters like cpu and memory usage as a bare minimum. If you're running a web application, you would probably also want to monitor response times. Maybe disk usage, database usage, cache usage - I could go on a little longer, but I wont.

There are many ways to accomplish observability - one of which is logging.

Logging - how hard can it be?

Logging is something we know. And we looove us some logging. But when you do logging the wrong way, it becomes a stone dragging you down. So how exactly do you log the wrong way? I'm glad you asked! There are at least three ways:
- Logging in the wrong format
- Logging the wrong things
- Logging using the wrong tools 

Format

"I lOg EvErYtHiNg In (XmL|jSoN|wHaTeVeR)" ...  Ok, there are legitimate reasons for structuring your logs - and that would be for subsequent parsing/aggregation. But xml is just way too much overhead. JSON is better in that respect but not by much. A simple comma-delimited file works just as well. It's also easier on the eyes. I will concede, that if you only log very little - application exceptions for instance - then a nice structured xml/json log would be preferable, but if you have many and/or large log files, use the simplest format possible.

Contents

One thing you should always consider when writing log statements in code: Why am I logging this? Is it to help troubleshooting? Is it to provide performance data. Is to track traffic? To just have some kind of output? Will I ever need to scan my log(s) to find this bit of string again or is it just a waste of disk? 

Often we write logging statements to have some way of knowing if our application logic behaves as expected. I know I have written code like this: _logger.Info($"This should not happen :o/ ({myObject})"); - and probably forgot to remove it before deploy. But this is only really useful to a developer with a recent copy of the application source code. To the IT dude(-tte) this is just a lot of nonsense. Wrap stuff like that in _logger.Verbose() or _logger.Debug() and provide the devops guy with something meaningful in stead in Info/Warning.

Oh, and don't log stuff that's not meant to leave your application, like GDPR (EU data privacy legal stuff) protected stuff.

Tooling

One common way to drown is to log to Console. Console-logging is neat because it doesn't break your application - even if run as a service - but it's distinctly un-neat that Console.WriteLine is one of those "hold everything" events that freezes your application. 

Another is to explicitly log to a FileStream - or worse: A database. Bu why would you want the hassle of a managed resource on top of your application logic? Always wrap that logic in some kind of abstraction. And make it an abstraction that is able to roll your logs by date/time/size - you do not want to have to open a log file that is several gigabytes in size. And maybe just use one of the many abstractions that is already out there.

Use an abstraction

My preferred logger is Serilog. I like how it can be configured in both code and markup (json), and it provides a nice abstraction over the whole logging experience. If NLog is more to your liking that's cool too. Or maybe you go full native and only use Microsoft.Extensions.Logging.ILogger - or a combination. I usually like to add ILogger and use Serilog as implementation.

Serilog provides ways to override which namespaces are logged to which level of verbosity. For instance I usually only let System.* and Microsoft.* only Warnings or Errors, while letting my own code log Information as well. 

At application initialization configure the output and formats. For instance when developing the application, have it log to Console. When it's ready to run, make it log to disk (or ELK or wherever). If you use some kind of build/deploy-automation, It'll handle everything for you.

Use multiple logs

This is important. If you answered the rhetorical questions above (Do you log monitor performance) - eg. do you parse the logfiles to monitor incoming requests and their execution times, then that's for a certain type of log. Do you log actions within your code for debugging purposes - well why not put that in a separate log? Auditing events - that's an audit log.

Dos and Don'ts

Do make sure you log correctly: Debug, Verbose, Info, Warning, Error - these priorities are there for a reason. Log appropriately 
Do make sure you test what happens when a logger in unavailable. E.g. what happens if the disk is full?
Don't log every little thing. Ask yourself :"Would this bit of information make sense to [whomever]?". If not, maybe log it Verbosely.

Make you logs available

So - if you log stuff, it's meant to be read by someone or some program. If you hide your logs away in some obscure folder, these logs will only be read when your IT Crowd has the time to dig them out. I'm not saying mail the logs to everyone when they roll - just make sure they're available when needed. Make a share out of the log folder or stream your logs to ElasticSearch or maybe Loki.

Conclusion

This was a bunch of hand waving - but you all have different setups and requirements. But I like to think that by making YOU think about how you do logging, you will improve your logging game. 

Comments are closed