←back to thread

1087 points smartmic | 1 comments | | HN request time: 0.341s | source
Show context
titanomachy ◴[] No.44305194[source]
“Good debugger worth weight in shiny rocks, in fact also more”

I’ve spent time at small startups and on “elite” big tech teams, and I’m usually the only one on my team using a debugger. Almost everyone in the real world (at least in web tech) seems to do print statement debugging. I have tried and failed to get others interested in using my workflow.

I generally agree that it’s the best way to start understanding a system. Breaking on an interesting line of code during a test run and studying the call stack that got me there is infinitely easier than trying to run the code forwards in my head.

Young grugs: learning this skill is a minor superpower. Take the time to get it working on your codebase, if you can.

replies(48): >>44305342 #>>44305375 #>>44305388 #>>44305397 #>>44305400 #>>44305414 #>>44305437 #>>44305534 #>>44305552 #>>44305628 #>>44305806 #>>44306019 #>>44306034 #>>44306065 #>>44306133 #>>44306145 #>>44306181 #>>44306196 #>>44306403 #>>44306413 #>>44306490 #>>44306654 #>>44306671 #>>44306799 #>>44307053 #>>44307204 #>>44307278 #>>44307864 #>>44307933 #>>44308158 #>>44308299 #>>44308373 #>>44308540 #>>44308675 #>>44309088 #>>44309822 #>>44309825 #>>44309836 #>>44310156 #>>44310430 #>>44310742 #>>44311403 #>>44311432 #>>44311683 #>>44312050 #>>44312132 #>>44313580 #>>44315651 #
geophile ◴[] No.44305628[source]
I am also in the camp that has very little use for debuggers.

A point that may be pedantic: I don't add (and then remove) "print" statements. I add logging code, that stays forever. For a major interface, I'll usually start with INFO level debugging, to document function entry/exit, with param values. I add more detailed logging as I start to use the system and find out what needs extra scrutiny. This approach is very easy to get started with and maintain, and provides powerful insight into problems as they arise.

I also put a lot of work into formatting log statements. I once worked on a distributed system, and getting the prefix of each log statement exactly right was very useful -- node id, pid, timestamp, all of it fixed width. I could download logs from across the cluster, sort, and have a single file that interleaved actions from across the cluster.

replies(4): >>44305698 #>>44306106 #>>44306184 #>>44308522 #
AdieuToLogic ◴[] No.44306184[source]
> A point that may be pedantic: I don't add (and then remove) "print" statements. I add logging code, that stays forever. For a major interface, I'll usually start with INFO level debugging, to document function entry/exit, with param values.

This is an anti-pattern which results in voluminous log "noise" when the system operates as expected. To the degree that I have personally seen gigabytes per day produced by employing it. It also can litter the solution with transient concerns once thought important and are no longer relevant.

If detailed method invocation history is a requirement, consider using the Writer Monad[0] and only emitting log entries when either an error is detected or in an "unconditionally emit trace logs" environment (such as local unit/integration tests).

0 - https://williamyaoh.com/posts/2020-07-26-deriving-writer-mon...

replies(2): >>44306322 #>>44307569 #
strken ◴[] No.44306322[source]
It's absolutely not an anti-pattern if you have appropriate tools to handle different levels of logging, and especially not if you can filter debug output by area. You touch on this, but it's a bit strange to me that the default case is assumed to be "all logs all the time".

I usually roll my own wrapper around an existing logging package, but https://www.npmjs.com/package/debug is a good example of what life can be like if you're using JS. Want to debug your rate limiter? Write `DEBUG=app:middleware:rate-limiter npm start` and off you go.

replies(3): >>44306540 #>>44307369 #>>44309715 #
AdieuToLogic ◴[] No.44306540[source]
> It's absolutely not an anti-pattern if you have appropriate tools to handle different levels of logging, and especially not if you can filter debug output by area.

It is an anti-pattern due to what was originally espoused:

  I add logging code, that stays forever. For a major 
  interface, I'll usually start with INFO level debugging, to 
  document function entry/exit, with param values.
There is no value for logging "function entry/exit, with param values" when all collaborations succeed and the system operates as intended. Note that service request/response logging is its own concern and is out of scope for this discussion.

Also, you did not address the non-trivial cost implications of voluminous log output.

> You touch on this, but it's a bit strange to me that the default case is assumed to be "all logs all the time".

Regarding the above, production-ready logging libraries such as Logback[0], log4net[1], log4cpp[2], et al, allow for run-time configuration to determine what "areas" will have their entries emitted. So "all logs all the time" is a non sequitur in this context.

What is relevant is the technique identified of emitting execution context when it matters and not when it doesn't. As to your `npm` example, I believe this falls under the scenario I explicitly identified thusly:

  ... an "unconditionally emit trace logs" environment
  (such as local unit/integration tests).
0 - https://logback.qos.ch/

1 - https://logging.apache.org/log4net/index.html

2 - https://log4cpp.sourceforge.net/

replies(2): >>44306621 #>>44318706 #
strken ◴[] No.44306621[source]
I understand that you explained some exceptions to the rule, but I disagree with two things: the assumption of incompetence on the part of geophile to not make logging conditional in some way, and adding the label of "anti-pattern" to something that's evidently got so much nuance to it.

> the non-trivial cost implications of voluminous log output

If log output is conditional at compile time there are no non-trivial cost implications, and even at runtime the costs are often trivial.

replies(2): >>44306829 #>>44308529 #
AdieuToLogic ◴[] No.44306829[source]
> ... I disagree with two things: the assumption of incompetence on the part of geophile to not make logging conditional in some way ...

I assumed nothing of the sort. What I did was identify an anti-pattern and describe an alternative which experience has shown to be a better approach.

"Incompetence" is your word, not mine.

> ... and adding the label of "anti-pattern" to something that's evidently got so much nuance to it.

I fail to see the nuance you apparently can see.

>> the non-trivial cost implications of voluminous log output

> If log output is conditional at compile time there are no non-trivial cost implications, and even at runtime the costs are often trivial.

Cloud deployment requires transmission of log entries to one or more log aggregators in order to be known.

By definition, this involves network I/O.

Network communication is orders of magnitude slower than local I/O.

Useless logging of "function entry/exit, with param values" increases pressure on network I/O.

Unless logging is allowed to be lossy, which it never is, transmission must be completed when log buffers are near full capacity.

Provisioning production systems having excessive logging can often require more resources than those which do not excessively log.

Thus disproving:

> ... even at runtime the costs are often trivial.

When considering the implication of voluminous log output in a production environment.

replies(3): >>44307087 #>>44318745 #>>44318757 #
geophile ◴[] No.44318745[source]
You are very attached to this "voluminous" point. What do you mean by it?

As I said, responding to another comment of yours, a distributed system I worked on produced a few GB a day. The logs were rotated daily. They were never transmitted anywhere, during normal operation. When things go wrong, sure, we look at them, and generate even more logging. But that was rare. I cannot stress enough how much of a non-issue log volume was in practice.

So I ask you to quantify: What counts (to you) as voluminous, as in daily log file sizes, and how many times they are sent over the network?

replies(1): >>44323710 #
AdieuToLogic ◴[] No.44323710[source]
> You are very attached to this "voluminous" point. What do you mean by it?

I mean "a lot" or more specifically; "a whole lot."

Here is an exercise which illustrates this. For the purposes here, assume ASCII characters are used for log entries to make the math a bit easier.

Suppose the following:

  Each log statement is 100 characters.
  Each service invocation emits 50 log statements.
  Average transactions per second during high usage is 200tps.
  High usage is on average 2 hours per day.

  100 x 50 x 200 x 60 x 60 x 2 = 7_200_000_000 = 7.2GB / day
> So I ask you to quantify: What counts (to you) as voluminous, as in daily log file sizes, and how many times they are sent over the network?

The quantification is above and regarding log entries being sent over a network - in many production systems, log entries are unconditionally sent to a log aggregator and never stored in a local file system.

replies(1): >>44328512 #
1. geophile ◴[] No.44328512[source]
7.2G/day doesn't sound terrible. And I'd reduce it by a factor of 25, since in normal operation (i.e., not looking into a problem) I would have either 2 log statements per call (entry, exit), or none at all. It might be more than 2, if I needed detailed logging.

But in normal usage, even in the scenario you describe your argument about log volume is not convincing.