Proposal: Unify printing the function name in panic messages()

[John Baldwin]

On Tuesday, February 19, 2013 1:20:55 pm Garance A Drosehn wrote:
> On 2/19/13 11:33 AM, John Baldwin wrote:
>  > On Monday, February 11, 2013 Garance A Drosehn wrote:
>  >>
>  >> That project uses __func__ on some printf()s, and __FILE__ on others.
>  >> I found it quite useful there.  When tracking down a few specific
>  >> bugs there were multiple places which could generate the error
>  >> message I was looking for, so I added __LINE__ to those printf()s.
>  >> This was helpful, particularly in one case where the entire message
>  >> was specified as a constant string in one place, but the same error
>  >> *could* be printed out by a different printf which built the message
>  >> via format specifiers.  So scanning for the message would pick up
>  >> the first case as an obvious hit, and never notice the second case.
>  >> And, of course, it turned out that the message in my log file was
>  >> coming from that second case.
>  >>
>  >> So maybe it'd be good to have two panic options.  One with the
>  >> __LINE__ number, and one without.
>  >
>  > Here's a (possibly) useful suggestion.  Rather than having a
>  > macro that alters the format string, perhaps change panic()
>  > to be this:
>  >
>  > static void
>  > dopanic(const char *func, const char *file, int line,
>  >         const char *fmt, ...);
>  >
>  > #define panic(...)	do_panic(__func__, __FILE__, \
>  >                                __LINE__, __VA_ARGS__)
>  >
>  > You could then use a runtime sysctl to decide if you want to
>  > log the extra metadata along with a panic.  Keeping the "raw"
>  > format string works better for my testing stuff since I have
>  > a hook at the start of panic() and it can use the string
>  > without the extra metadata (and even possibly supply the
>  > metadata in the 'catch' phase so I can ignore panics based
>  > on that metadata.
> 
> I've tried this, and there's one minor annoyance with it.  Let's say
> the programmer does:
>      panic(badaddr: invalid size (%s)", int_size);
> The compiler will warn that parameter #5 does not match the format-code,
> not parameter #2.  In this example it's easy to see the problem, but it
> gets more confusing if the call does have a lot of parameters.  But in
> glancing through the panic() messages in the base source, almost all
> of them are so short that this wouldn't be much of an issue.

Eww, that is annoying.

> Yet another alternate tactic would be to have:
> 
> static void prepanic1(const char *func);
> static void prepanic2(const char *file, int line);
> static void prepanic3(const char *file, const char *func, int line);
> 
> And then on a per-source-file basis, one could select one of:
> 
> #define panic(...) { prepanic1(__func__) ; panic(__VA_ARGS__) }
> #define panic(...) { prepanic2(__FILE__, __LINE__) ; \
> 		     panic(__VA_ARGS__) }
> #define panic(...) { prepanic3(__FILE__, __func__, __LINE__) ; \
> 		     panic(__VA_ARGS__) }
> 
> One could even just #define panic1(), panic2(), and panic3(), and
> then let the programmer decide on a per-call basis how much detail
> any given panic message will need.  Either way, someone who wanted
> to recompile could trim unwanted bloat with very little effort.

Interesting.  You'd have to stuff that data somewhere, perhaps hang
it off of 'struct thread' until the real panic() was called.

>  > However, one consideration with this is how much bloat comes from
>  > having the various __func__ and __FILE__ strings (esp. the latter).
>  > You may want to have an option to strip them out (see
>  > LOCK_FILE/LOCK_LINE where we use NULL instead in production kernels
>  > when calling locking primitive routines to avoid the bloat of
>  > filenames).  Also, if you want to use __FILE__ at all you will
>  > likely need something akin to 'fixup_filename()' from subr_witness.c.
>  > I think that one is tailored more to old style kernel builds and
>  > probably doesn't DTRT for the 'make buildkernel' case.  It maybe
>  > that fixup_filename() should just be basename() at this point.
> 
> Hmm.  In the places where I've used this, __FILE__ has produced just
> the basename of the file.  Maybe I'm always compiling things where
> 'cc' was given just the basename, but I'm pretty sure some of my
> things are compiled as "subdir/somefile.c".  Quite possible that
> I've just been lucky on this!

I think you've just been lucky. :)

% cat /usr/tmp/foo.c 
const char *somefunc(void);

const char *
somefunc(void)
{
        return (__FILE__);
}

% cc -S -o /dev/stdout /usr/tmp/foo.c 
        .file   "foo.c"
        .section        .rodata
.LC0:
        .string "/usr/tmp/foo.c"
        .text
        .p2align 4,,15
.globl somefunc
        .type   somefunc, @function
somefunc:
.LFB2:
        pushq   %rbp
.LCFI0:
        movq    %rsp, %rbp
.LCFI1:
        movl    $.LC0, %eax
        leave
        ret
.LFE2:
<much junk after this omitted>

Even better:

% cc -S -o /dev/stdout /usr/tmp/../../usr/tmp/foo.c
        .file   "foo.c"
        .section        .rodata
.LC0:
        .string "/usr/tmp/../../usr/tmp/foo.c"
        .text

-- 
John Baldwin