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

[John Baldwin]

On Monday, February 11, 2013 2:58:43 pm Garance A Drosehn wrote:
> On 2/7/13 4:35 PM, Christoph Mallon wrote:
> >
> > currently the style for printing panic messages varies greatly.
> > Here are some examples of the most common styles:
> > 	panic("just a message");
> > 	panic("function_name: message");
> > 	panic("wrong_function_name: message");
> > 	panic("%s: message", __func__);
> > Especially the third -- a wrong function name being shown -- is annoying
> > and quite common.  I propose a simple macro, which wraps panic() and
> > ensures that the right name is shown always by using __func__.
> 
> > Do you have suggestions to improve this proposal?
> >
> > 	Chrsopth
> 
> While I'm replying to the first message in the thread, I've read
> most of the messages up to this point.  I do very little development
> in the kernel, but as it happens I've spent the last three weeks
> untangling a somewhat large C-based project which has similar
> messages, and due to the nature of the project it's nearly impossible
> to run debuggers on it.  So I can't just pop into the debugger and
> get some kind of stack trace.
> 
> 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.

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.

-- 
John Baldwin