From owner-freebsd-arch@FreeBSD.ORG Wed Feb 20 12:51:41 2013 Return-Path: Delivered-To: freebsd-arch@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by hub.freebsd.org (Postfix) with ESMTP id DBD1B129; Wed, 20 Feb 2013 12:51:41 +0000 (UTC) (envelope-from jhb@freebsd.org) Received: from bigwig.baldwin.cx (bigknife-pt.tunnel.tserv9.chi1.ipv6.he.net [IPv6:2001:470:1f10:75::2]) by mx1.freebsd.org (Postfix) with ESMTP id 88BD8FAE; Wed, 20 Feb 2013 12:51:41 +0000 (UTC) Received: from pakbsde14.localnet (unknown [38.105.238.108]) by bigwig.baldwin.cx (Postfix) with ESMTPSA id DC67CB95E; Wed, 20 Feb 2013 07:51:40 -0500 (EST) From: John Baldwin To: Garance A Drosehn Subject: Re: Proposal: Unify printing the function name in panic messages() Date: Tue, 19 Feb 2013 15:41:22 -0500 User-Agent: KMail/1.13.5 (FreeBSD/8.2-CBSD-20110714-p25; KDE/4.5.5; amd64; ; ) References: <51141E33.4080103@gmx.de> <201302191133.08938.jhb@freebsd.org> <5123C287.4040201@FreeBSD.org> In-Reply-To: <5123C287.4040201@FreeBSD.org> MIME-Version: 1.0 Content-Type: Text/Plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Message-Id: <201302191541.22311.jhb@freebsd.org> X-Greylist: Sender succeeded SMTP AUTH, not delayed by milter-greylist-4.2.7 (bigwig.baldwin.cx); Wed, 20 Feb 2013 07:51:41 -0500 (EST) Cc: Kirk McKusick , Christoph Mallon , freebsd-arch@freebsd.org X-BeenThere: freebsd-arch@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Discussion related to FreeBSD architecture List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 20 Feb 2013 12:51:41 -0000 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: 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