Hacker News Reader

Comment by spaetzleesser | Hacker News Reader

I totally disagree with the “log after “. I have seen it multiple times where the log ended but it wasn’t possible to tell in what code section because some call had thrown an exception. I much prefer to see a log where I see lines like “attempting to do x with parameters a,b,c”.

In general I set the bar for “ too much logging” very high. It’s a better problem to have too much log to store and sift through vs having no data.

View on HN

In that case, the stack trace from the exception should be able to tell you that you failed on the line _before_ the "log after".

It won't be nearly as convenient to dig that fact out, though.

> the exception should be able to tell you that you failed on the line _before_ the "log after".

It is an extension of the «but it worked on my laptop» mentality.

No, it won't work in a complex environment, specifically in a scenario where a server farm sits behind a load balancer with a VIP (geographically distributed or not), which is ubiquitous. Specifically, it won't work in a situation where a server instance the application attempted to connect to sits in a subnet in another data centre across a WAN link, and the networks put a shoddy firewall rule in last night or applied a bit rotten firmware patch to the router, and new server connections suddenly started getting TCP resets halfway through the data exchange. You won't know which particular service instance the resolver ended up resolving and connecting to unless you have a "before" log entry as well. Hiding the dead horse in the cloud will help in a serverless or in a simple scenario, but, if you have a load balancer and multiple availability zones, you still have the same problem, due to cloud load balancers failing over to another AZ at will (it is more nuanced than that, though).

Logging inputs is as critically important as logging preceding statement's outcome, albeit it has to be used wisely as excessive and, worse, not properly structured log entries can (and will) overwhelm the log sink in a high data volume environment. Log ring buffers can be a solution for some cases, and a monitoring component that is integrated into an app can be an answer in some other cases, but there is no single, one size fits it all, solution for an arbitrary setup in a high data volume environment.

In the apis that I am familiar with, there is typically generic, cross-cutting logging as a filter on all http requests, so you always log the "GET on /customers/123".

This is a given, it's typically done by "add the library, one line of code at startup to enable it"

While this technically qualifies as "Logging inputs before" it does not seem to be what the author is talking about. I was assuming that was present, and had been reached - cause if it had not, what request are you even debugging? Rather than some "«but it worked on my laptop» mentality" straw man.

That assumes that the all fail cases will create an exception and properly pass on that a failure occurred, with enough information so that the caller can decide what to do next.

The assumption upfront is that you don't reach the "log after" point. IMHO, given that, not having an exception will be rare, and probably involve code that looks "off" and fixing that is the first task. YMMV though, depending on language

You don’t know the input that caused the exception. Some exceptions give you good detail but a lot don’t.

I would say that since I have spent time ensuring that exceptions are properly detailed, and those details properly logged (1), this is correct, but is not an invariant that makes exceptions useless. It is often something to fix.

1) shout out to https://github.com/RehanSaeed/Serilog.Exceptions

The author does log before, just at DEBUG level. In the scenario you describe, the information you desire would be available.

I've also seen issues with logging after.

It feels more natural to log when something is complete instead of constantly saying when you're starting to do something, but it leads to issues where you have no idea what the system was actually doing when it failed. It's very easy to have the process die without logging what made it die, especially if you're using a language that doesn't provide stack traces or you have them turned off for performance.

Logging before an action also means it's possible to know what's going on when a process hangs. It might lead me to where I should look to resolve the problem instead of forcing me to just restart the service and hope for the best.

Another option is to log after, but in a cross cutting way, e.g. using a middleware or filter. Extra properties can be added along the way, and if there's an exception the middleware can handle it and add the problem to the log event.

The power of structured logging here is in enriching events to make them queryable later, so you could e.g. view all events for a request.

> In general I set the bar for “ too much logging” very high.

Which is pretty good practice because when things go wrong in Prod, you want your logs to tell you quickly what went wrong. Too many times I have seen that something goes wrong in Prod and then people say "Oh we should have logged that"

Log after is SOP in any reasonably large architecture. Too much logging is a problem you encounter very quickly with nontrivial traffic.

That’s a good point. However, I suspect that a lot of people are not working on a scale that would qualify as “large”. I am just working on a project where the infrastructure guys planned for massive scaling but so far the highest we ever got was 3 pods and we easily could have handled this with one server. I think I would wait for logging to become a problem before reducing it. If that ever happens.

Reply on news.ycombinator.com