Re: Insufficient locking in log() / kvprintf() / somewhere?

Romain Tartière wrote:
Hello FreeBSD hackers!

I recently got some apache problems (maybe just forgetting to restart it
after an update, but it is not the interest of this e-mail) and each
httpd process was segfaulting as soon as created. I got surprising
things like that in my systems log:

=== begin snippet ===
pid 85055 (httpd), uid 80: exited on signal 11
pid 85063 (httpd), uid 80: exited on signal 11
pid 85064 (httpd), uid 80: exited on signal 11
pid 85066 (httpd), uid 80: exited on signal 11
pid 85065 (httpd), uid 80: exited on signal 11
<<66>>ppiidd 8580506678 ((hhtttptdp)d,), uuid id8 0: 8ex0: eixteidt eod no ns isginganla l 111
1

pid 85070 (httpd), uid 80: exited on signal 11
pid 85069 (httpd), uid 80: exited on signal 11
=== end snippet ===

(uname: FreeBSD 6.2-STABLE #4: Thu Jun 7 00:56:26 CEST 2007 i386)

Obviously, having two processes on a dual core machine crashing
simultaneously produce weird stuff. I poked a bit around in
/usr/src/sys/kern:

% grep -n 'exited on signal' *
kern_sig.c:2452: "pid %d (%s), uid %d: exited on signal %d%s\n",

The code in void sigexit(td, sig) is as follow:
if (kern_logsigexit)
log(LOG_INFO,
"pid %d (%s), uid %d: exited on signal %d%s\n",
p->p_pid, p->p_comm,
td->td_ucred ? td->td_ucred->cr_uid : -1,
sig &~ WCOREFLAG,
sig & WCOREFLAG ? " (core dumped)" : "");

The log() function is declared in /usr/src/sys/kern/subr_prf.c:229 as this:
void
log(int level, const char *fmt, ...)
{
va_list ap;
struct putchar_arg pca;

pca.tty = NULL;
pca.pri = level;
pca.flags = log_open ? TOLOG : TOCONS;

va_start(ap, fmt);
kvprintf(fmt, putchar, &pca, 10, ap);
va_end(ap);

msgbuftrigger = 1;
}
... so basically is calls kvprintf witch actually writes the message
AFAIK.

The issue is maybe a weird case-corner, but maybe some kind of locking
may have sense to avoid this?

Kind regards,
Romain

I have seen this problem a lot where certain apache server modules have been miss configured causing apache children to call abort and dump core as soon as they are spawned. (Makes for a lot of messages) I have also seen it produced by network drivers with large quantities of debug messages enabled.

Its kind of annoying to see messages interleaved like this.

Tom
_______________________________________________
freebsd-hackers@xxxxxxxxxxx mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "freebsd-hackers-unsubscribe@xxxxxxxxxxx"