[prev in list] [next in list] [prev in thread] [next in thread] 

List:       freebsd-hackers
Subject:    Re: Insufficient locking in log() / kvprintf() / somewhere?
From:       Tom Judge <tom () tomjudge ! com>
Date:       2007-07-20 21:44:51
Message-ID: 46A12CD3.4000600 () tomjudge ! com
[Download RAW message or body]

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@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "freebsd-hackers-unsubscribe@freebsd.org"
[prev in list] [next in list] [prev in thread] [next in thread]