Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 20 Jul 2007 20:50:09 +0200
From:      Romain =?iso-8859-1?Q?Tarti=E8re?= <romain@blogreen.org>
To:        freebsd-hackers <freebsd-hackers@freebsd.org>
Subject:   Insufficient locking in log() / kvprintf() / somewhere?
Message-ID:  <20070720185009.GA79090@marvin.blogreen.org>

next in thread | raw e-mail | index | archive | help

--Dxnq1zWXvFF0Q93v
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

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:

=3D=3D=3D begin snippet =3D=3D=3D
> 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 eo=
d no ns isginganla l 111
> 1
>=20
> pid 85070 (httpd), uid 80: exited on signal 11
> pid 85069 (httpd), uid 80: exited on signal 11
=3D=3D=3D end snippet =3D=3D=3D

(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 =3D NULL;
>         pca.pri =3D level;
>         pca.flags =3D log_open ? TOLOG : TOCONS;
>
>         va_start(ap, fmt);
>         kvprintf(fmt, putchar, &pca, 10, ap);
>         va_end(ap);
>
>         msgbuftrigger =3D 1;
> }
=2E.. 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

--=20
Romain Tarti=E8re <romain@blogreen.org>        http://romain.blogreen.org/
pgp: 8DAB A124 0DA4 7024 F82A  E748 D8E9 A33F FF56 FF43 (ID: 0xFF56FF43)
(plain text =3Dnon-HTML=3D PGP/GPG encrypted/signed e-mail much appreciated)

--Dxnq1zWXvFF0Q93v
Content-Type: application/pgp-signature
Content-Disposition: inline

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.4 (FreeBSD)

iD8DBQFGoQPh2OmjP/9W/0MRAuOwAJwNFiMgvmI2qoIETzvlfyU7wehlwgCfQxXh
MJvLYctf4kltW1gVlZYNKQ8=
=WPjV
-----END PGP SIGNATURE-----

--Dxnq1zWXvFF0Q93v--



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20070720185009.GA79090>