15
Parzi
4y

People don't seem to know how to properly do print-debugging, so here's a simple guide:

1. A log of "aaaaaa" or "got here" isn't as helpful as you think when ALL OF THEM ARE THE FUCKING SAME. You put a descriptive label or copy verbatim the conditional statement. This saves time matching statements, allows one to watch multiple branches at once, and allows others to understand and help faster when dragged in to help.
2. When trying to see where code fucks up, before each line, paste said line into a proper print statement for your language. If there's, say, a function call or some shit, have it output something like "functionCall(varA=<varA contents>,varB=<varB contents);" Most normal lines should be like this too, but it's especially helpful for calls and comparisons.
If need be, add return values after if they're not shown in another print statement later.
This allows for a trail of execution AND the line that fucks up will be the last in the log, making finding it easier when dealing with hangs and such.
3. Putting something unique like "DEBUG: " or something in front of all statements ensures you can just search for them to ensure you're not rolling one out to production. It also separates debug output from normal output at a glance, making digging through logs faster.

Comments
  • 6
    My goto:

    DEBUG:
    - line: 123
    - file: xyz.cls
    - output:
    that thing you are checking.

    ---
    It's always been effective tracking down exactly what i'm looking for and in large log files make filtering super easy.
  • 2
    ... or use a proper debugger 🤔

    Not gonna sit on my high horse here, I know it sometimes can be difficult to set up.

    I use guids in those debug statements. Makes it easy to see where it came from.
  • 2
    Extra fun for segfaults: printf to stderr or set stdout to unbuffered. Otherwise, you sometimes won't see the output even if the segfault happens afterwards because it's buffered and the program is already terminated before the buffer is flushed to output.
  • 1
    Personally I use a method that takes a indicator parameter and a string of texts.

    E.G

    public String log(int n, String t) {
    switch (n) {
    case 1:
    return "[*] "+t;
    break;
    case 2:
    return "[+] "+t;
    break;
    case 3:
    return "[-] "+t;
    break;
    }
    }
  • 1
    Mm people who cannot work with gdb/windbg make me sick 😤
  • 1
    @Pyjong some of us use langs where that's not helpful.
  • 1
    @C0D4 A similar concept, yeah... that might work better for multi-file setups with massive logs.
  • 1
    @groxx thats a shame. Why polute code with printfs if you can get the same and much more by setting a breakpoint.
  • 2
    @Pyjong Because a breakpoint stops execution, which may suck. Execution in the debugger may be slower, which also may be an issue. Though of course everything after the first printf also has a different timing.

    Also, the printf debugger is a good preparation for systems that don't have any debugger at all, and these are a preparation for when you don't even have access to the real program execution because it's totally elsewhere.
  • 2
    @Fast-Nop breakpoint stops execution may suck? Cmon 🙂 set it when you need it or make it conditional. Done.
    But yeah I would rather use kernel prints than use gdb remotely with serial. That takes ages.
    No debugger at all mmm.. I understand, although Id say every processor has a debug instruction, so there is a way to make it work. Ermm yeah all in all I'd add an extra " except for remote machine debugging" to my claim.
  • 1
    @groxx exactly, builds and debugger are the first two things that must work. I hate when my colleagues play their guessing games. I'm not saying its a cure for everything but it is a cure for almost everything that runs on cpu and should be used in the first place.
  • 2
    @Pyjong Sometimes, I don't want the execution to actually stop, just get some debug output. Especially when it's about external inputs that arrive in real time, like in a protocol stack.

    About the only time when I fire up GDB at all is when I have really strange segfaults because some pointer bug has garbled over some unrelated variable, and that's exceptionally rare. And then it's GDB right from the CLI.

    I developed for systems where the only "debugger" was abusing either some LED or some free IO pin for attaching an oscilloscope. No other debugger available.
  • 2
    @Pyjong In contrast to that, I think a dev shouldn't depend on a debugger. It should be a "nice to have" tool, not more. The primary method of debugging should be reading and understanding the code.
  • 2
    @Fast-Nop yup debugger doesnt come for free, thats true. But it is not that hard to get breakpoints and memory/register dumps work. Not that I use any public ones but there are debug commands interpreters for embedded on github after all. I think its better to send debugger commands instead of traces in the long run. So the question is: is the run long enough to take the effort?
    Anyway, I'm more upset about people who have the debugger at their disposal, but dont use it.

    I agree on the code reading skills but i think they are more ofa prerequisite. Without that debugger hardly helps.
  • 1
    I use a very specific printf debugging format that helps me follow the call chain. I've found this is often more useful than stepping through with a debugger, and it's certainly faster.

    Format for logging each interesting method call:

    ```\n\n[objtype Full::Object::Path(id) :: method(interesting,param,names)]
    | param: value
    | param: value
    | hash_param:
    | | arg: value
    | | arg: value```

    Subsequent log entries within the same method:

    ```\n[objtype Full::Object::Path(id) :: method(interesting,param,names)] Message type: Description```

    The differing amounts of new lines let me differentiate between new method calls at a glanc, as well as separate my log entries from the rest of the output. Obviously I don't add entries for every single method; only those I'm curious about.

    ------

    Example log entries:
    \n
    \n
    [model Redemption::PaperCert(rp_a1b2c3d4) :: redeem(site,data)]
    | site: st_47df9e0 (TriThai)
    | data:
    | | amount: 46.63
    | | location_id: 5
    \n
    [model Redemption::PaperCert(rp_a1b2c3d4) :: redeem(site,data)] Info: $53.37 remaining on the cert

    The first entry tells me which model it's from, which class instance (via its custom id), which method got called, when (time stamp added by the logger; not shown here), and what data it recieved. (Or at least the args I deemed interesting). The nesting also makes it trivial to read at a glance.

    With a log full of entries like this, I can quickly and easily follow the execution and see interesting data as it flows through the methods. It makes debugging a breeze.

    It's easy to implement (customized copypasta) and the format also lends itself to regex grepping for e.g. automation or highlighting.
  • 1
    @Root yes yes YES this is what i'm TALKING ABOUT
Add Comment