I tend to use printf-style debugging as my primary troubleshooting method and only resort to gdb as a last resort.
While I like its ease of use printf debugging isn't without its annoyances, namely removing the print statements once you're done.
I used to use trace-level logging from proper logging libraries but adding trace calls in every corner quickly gets out of control and results in an overwhelming amount of output.
To scratch my own itch I created dlg - a minimal debugging library that disappears completely from production builds. Its API exposes just a single function, Printf [1].
dlg is optimized for performance in debug builds and, most importantly, when compiled without the dlg build tag, all calls are eliminated by the Go linker as if dlg was never imported.
For debug builds it adds optional stack trace generation configurable via environment variables or linker flags.
GitHub: https://github.com/vvvvv/dlg
Any feedback is much appreciated.
[1]: Actually two functions - there's also SetOutput.
dlg.Printf("the thing.Something is %+v", thing.Something())
And don't misunderstand me: it's a grave pet peeve of mine to do action inside the args to Printf but I can tell you it's a very common [anti-]pattern so I'd presume your users will want a story for how that interacts with the "disappears completely" claim
If we consider this example:
func risky() error {
return fmt.Errorf("unexpected error")
}
func risky2() error{
return fmt.Errorf("also an error")
}
func main() {
fmt.Printf("something failed: %v", risky())
dlg.Printf("something failed: %v", risky2())
}
0x10009f354 d503201f NOOP ; Dead code of dlg.Printf
0x10009f358 b0000000 ADRP 4096(PC), R0 ; Load "also an error" string address
0x10009f35c 9124ec00 ADD $2363, R0, R0 ; Calculate exact string address
0x10009f360 d28001a1 MOVD $13, R1 ; Set string length=13 (R1)
0x10009f364 aa1f03e2 MOVD ZR, R2 ; Clear R2
0x10009f368 aa1f03e3 MOVD ZR, R3 ; Clear R3
0x10009f36c aa0303e4 MOVD R3, R4 ; Clear R4
0x10009f370 97ffd890 CALL fmt.Errorf(SB) ; Call fmt.Errorf
I'll add a section to the README that explains this. Thanks for pointing it out.
package main
import (
"fmt"
"github.com/vvvvv/dlg"
)
func risky() error {
_, err := fmt.Printf("unexpected error\n")
return err
}
func main() {
dlg.Printf("something failed: %s", risky())
risky()
}
ETA: Presumably if there was at least an option for passing a closure that would provide a way to address this? Since the closure will only uselessly compile, and not actually uselessly run?
I'd appreciate any feedback on whether these changes make the behavior more transparent and less misleading.
Use something like stacked git[1], and then it's just one "stg pop" and poof, they're gone.
I rarely use branches, my local work area is about 50-100 commits on top of master.
I pick/reorder/edit with “git rebase -i”
I’ll prefix the commit summary with a word that helps me keep straight debug changes from ones that will go toward a MR.
Just one thought: I don't think your stack traces need to include the lines inside Printf itself and it adds to the noise a bit. Maybe just go up to the line where the call to Printf is made?
You're absolutely right, it annoys me as well.
It's a bit finicky to do so, but I'm currently in an exploratory phase of providing an even more fine grained stack tracing feature and filtering out dlg itself is definitly on my todo list.
There is way too much going on in this code whose feature essentially boils down to
func Printf(f string, v ...any) {
if CONDITION {
fmt.Printf(f, v...)
}
}
I'd say it is fair to call it zero cost, if the costs you are seeing are due to the way you are using it. If the values being logged are values you are already computing and storing, constants, or some mix of the two (concatenated via its printf function), by my understanding (caveat: I've never actually used Go myself) all the logging code should be stripped out as dead code in the link stage.
Obviously if you are performing extra computations with intermediate values to produce the log messages, your code there might produce something that is not reliably detected as eliminable dead code so there would be cost there.
> The only way (I believe) to implement zero cost is some type of macro system which go does not support.
That looks to be effectively what it is doing, just at the link stage instead of in a preprocessor. Where C & friends would drop the code inside #ifdef when the relevant value is not set (so it won't be compiled at all) this should throw it out later in the process if DLG_STACKTRACE isn't set at compile time.
So there will always be a compile-time cost (unlike with a preprocessor macro, something will be produced then thrown away and the analysis of what to throw away will take longer with more code present), but not a run-time cost if the logging is not enabled, assuming you don't have any logic in the trace lines beside the calls to this module.
One obvious cost to code that is removed in production is that there is now a divergence between what your source code says it does and what it actually does. I now need to keep in mind the context the program is running in. There is a cost to that. It might be worth it, but it isn't zero.
My favored approach is a context aware level logger with structured logs going to an aggregator like Splunk.
Because it is context aware, custom filtering logic is available in a middleware.
Which is a relatively recent addition to the Go standard library, based on the collective experience with logging over the years. Compare with the original log standard library: https://pkg.go.dev/log and you can see the changes in even just the time since Go was developed in logging best practices.
Slog, once you understand the interfaces involved in stuff, has performed most every trick I could desire, up to and including things like subloggers with their own priorities for outputs that override the global settings.
I'd like to see some slog integration in this package, though I say that without a design in mind. As it stands, this is exactly what it says on the tin; debugging-only output that you fully intend to just disappear out of the production binary.
The trick it uses is a fairly straightforward use of Go's tag-based compilation features, which I do not mean as a criticism, but to point out that any Go programmer who likes the looks of this but wants to adapt it to their own task will find it easy to simply take the technique directly and adapt it in not very many lines of code.
That being said even with 100% coverage your code may still contain bugs. If you've never had to debug code with extensive tests then hats off to you.
I expect that is what the parent is really asking about: What does this meaningfully offer over the "built-in" debug logging?
"100% coverage" is just a measure of line coverage and is highly useless to reason about.
For testing to become meaningful, you should have test data covering way more than that for the relevant parts.
I'm not saying that tests are perfect, but if you do find a bug, you write a new test and fix it. You don't add print statements that you expect to keep around any longer than the amount of effort there is to write the test and fix the code.
Maybe this product is for people who don't write tests, but even in this codebase, there is a pretty well done set of tests and zero dogfood usage that I noticed.