Fix a serious bug in syslogd regarding the handling of pipes. The bug

would cause syslogd to eventually kill innocent processes in the
system over time (note: not `could' but `would').  Many thanks to my
colleague Mirko for digging into the kernel structures and providing
me with the debugging framework to find out about the nature of this
bug (and to isolate that syslogd was the culprit) in a rather large
set of distributed machines at client sites where this happened
occasionally.

Whenever a child process was no longer responsive, or when syslogd
receives a SIGHUP so it closes all its logging file descriptors, for
any descriptor that refers to a pipe syslogd enters the data about the
old logging child process into a `dead queue', where it is being
removed from (and the status of the dead kitten being fetched) upon
receipt of a SIGCHLD.  However, there's a high probability that the
SIGCHLD already arrives before the child's data are actually entered
into the dead queue inside the SIGHUP handler, so the SIGCHLD handler
has nothing to fetch and remove and simply continues.  Whenever this
happens, the process'es data remain on the dead queue forever, and
since domark() tried to get rid of totally unresponsive children by
first sending a SIGTERM and later a SIGKILL, it was only a matter of
time until the system had recycled enough PIDs so an innocent process
got shot to death.

Fix the race by masking SIGHUP and SIGCHLD from both handlers mutually.

Add additional bandaids ``just in case'', i. e. don't enter a process
into the dead queue if we can't signal it (this should only happen in
case it is already dead by that time so we can fetch the status
immediately instead of deferring this to the SIGCHLD handler); for the
kill(2) inside domark(), check for an error status (/* Can't happen */
:) and remove it from the dead queue in this case (which if it would
have been there in the first place would have reduced the problem to a
statistically minimal likelihood so i certainly would never have
noticed the bug at all :).

Mirko also reviewed the fix in priciple (mutual blocking of both
signals inside the handlers), but not the actual code.

Reviewed by:	Mirko Kaffka <mirko@interface-business.de>
Approved by:	jkh
This commit is contained in:
Joerg Wunsch 2000-02-28 17:49:43 +00:00
parent ac13e0c5a0
commit 6b5c2dd6a1
Notes: svn2git 2020-12-20 02:59:44 +00:00
svn path=/head/; revision=57558

View File

@ -271,7 +271,8 @@ int LogFacPri = 0; /* Put facility and priority in log message: */
int allowaddr __P((char *));
void cfline __P((char *, struct filed *, char *));
char *cvthname __P((struct sockaddr_in *));
void deadq_enter __P((pid_t));
void deadq_enter __P((pid_t, const char *));
int deadq_remove __P((pid_t));
int decode __P((const char *, CODE *));
void die __P((int));
void domark __P((int));
@ -279,6 +280,7 @@ void fprintlog __P((struct filed *, int, char *));
void init __P((int));
void logerror __P((const char *));
void logmsg __P((int, char *, char *, int));
void log_deadchild __P((pid_t, int, const char *));
void printline __P((char *, char *));
void printsys __P((char *));
int p_open __P((char *, pid_t *));
@ -302,6 +304,8 @@ main(argc, argv)
FILE *fp;
char *p, *hname, line[MAXLINE + 1];
struct timeval tv, *tvp;
struct sigaction sact;
sigset_t mask;
pid_t ppid = 1;
socklen_t len;
@ -368,7 +372,18 @@ main(argc, argv)
(void)signal(SIGTERM, die);
(void)signal(SIGINT, Debug ? die : SIG_IGN);
(void)signal(SIGQUIT, Debug ? die : SIG_IGN);
(void)signal(SIGCHLD, reapchild);
/*
* We don't want the SIGCHLD and SIGHUP handlers to interfere
* with each other; they are likely candidates for being called
* simultaneously (SIGHUP closes pipe descriptor, process dies,
* SIGCHLD happens).
*/
sigemptyset(&mask);
sigaddset(&mask, SIGHUP);
sact.sa_handler = reapchild;
sact.sa_mask = mask;
sact.sa_flags = 0;
(void)sigaction(SIGCHLD, &sact, NULL);
(void)signal(SIGALRM, domark);
(void)signal(SIGPIPE, SIG_IGN); /* We'll catch EPIPE instead. */
(void)alarm(TIMERINTVL);
@ -440,7 +455,13 @@ main(argc, argv)
dprintf("off & running....\n");
init(0);
(void)signal(SIGHUP, init);
/* prevent SIGHUP and SIGCHLD handlers from running in parallel */
sigemptyset(&mask);
sigaddset(&mask, SIGCHLD);
sact.sa_handler = init;
sact.sa_mask = mask;
sact.sa_flags = 0;
(void)sigaction(SIGHUP, &sact, NULL);
tvp = &tv;
tv.tv_sec = tv.tv_usec = 0;
@ -938,7 +959,8 @@ fprintlog(f, flags, msg)
int e = errno;
(void)close(f->f_file);
if (f->f_un.f_pipe.f_pid > 0)
deadq_enter(f->f_un.f_pipe.f_pid);
deadq_enter(f->f_un.f_pipe.f_pid,
f->f_un.f_pipe.f_pname);
f->f_un.f_pipe.f_pid = 0;
errno = e;
logerror(f->f_un.f_pipe.f_pname);
@ -1036,12 +1058,9 @@ void
reapchild(signo)
int signo;
{
int status, code;
int status;
pid_t pid;
struct filed *f;
char buf[256];
const char *reason;
dq_t q;
while ((pid = wait3(&status, WNOHANG, (struct rusage *)NULL)) > 0) {
if (!Initialized)
@ -1049,35 +1068,17 @@ reapchild(signo)
continue;
/* First, look if it's a process from the dead queue. */
for (q = TAILQ_FIRST(&deadq_head); q != NULL; q = TAILQ_NEXT(q, dq_entries))
if (q->dq_pid == pid) {
TAILQ_REMOVE(&deadq_head, q, dq_entries);
free(q);
goto oncemore;
}
if (deadq_remove(pid))
goto oncemore;
/* Now, look in list of active processes. */
for (f = Files; f; f = f->f_next)
if (f->f_type == F_PIPE &&
f->f_un.f_pipe.f_pid == pid) {
(void)close(f->f_file);
errno = 0; /* Keep strerror() stuff out of logerror messages. */
f->f_un.f_pipe.f_pid = 0;
if (WIFSIGNALED(status)) {
reason = "due to signal";
code = WTERMSIG(status);
} else {
reason = "with status";
code = WEXITSTATUS(status);
if (code == 0)
goto oncemore; /* Exited OK. */
}
(void)snprintf(buf, sizeof buf,
"Logging subprocess %d (%s) exited %s %d.",
pid, f->f_un.f_pipe.f_pname,
reason, code);
logerror(buf);
log_deadchild(pid, status,
f->f_un.f_pipe.f_pname);
break;
}
oncemore:
@ -1148,7 +1149,8 @@ domark(signo)
switch (q->dq_timeout) {
case 0:
/* Already signalled once, try harder now. */
kill(q->dq_pid, SIGKILL);
if (kill(q->dq_pid, SIGKILL) != 0)
(void)deadq_remove(q->dq_pid);
break;
case 1:
@ -1156,9 +1158,12 @@ domark(signo)
* Timed out on dead queue, send terminate
* signal. Note that we leave the removal
* from the dead queue to reapchild(), which
* will also log the event.
* will also log the event (unless the process
* didn't even really exist, in case we simply
* drop it from the dead queue).
*/
kill(q->dq_pid, SIGTERM);
if (kill(q->dq_pid, SIGTERM) != 0)
(void)deadq_remove(q->dq_pid);
/* FALLTHROUGH */
default:
@ -1253,7 +1258,8 @@ init(signo)
case F_PIPE:
(void)close(f->f_file);
if (f->f_un.f_pipe.f_pid > 0)
deadq_enter(f->f_un.f_pipe.f_pid);
deadq_enter(f->f_un.f_pipe.f_pid,
f->f_un.f_pipe.f_pname);
f->f_un.f_pipe.f_pid = 0;
break;
}
@ -1912,10 +1918,23 @@ p_open(prog, pid)
}
void
deadq_enter(pid)
deadq_enter(pid, name)
pid_t pid;
const char *name;
{
dq_t p;
int status;
/*
* Be paranoid, if we can't signal the process, don't enter it
* into the dead queue (perhaps it's already dead). If possible,
* we try to fetch and log the child's status.
*/
if (kill(pid, 0) != 0) {
if (waitpid(pid, &status, WNOHANG) > 0)
log_deadchild(pid, status, name);
return;
}
p = malloc(sizeof(struct deadq_entry));
if (p == 0) {
@ -1928,3 +1947,45 @@ deadq_enter(pid)
p->dq_timeout = DQ_TIMO_INIT;
TAILQ_INSERT_TAIL(&deadq_head, p, dq_entries);
}
int
deadq_remove(pid)
pid_t pid;
{
dq_t q;
for (q = TAILQ_FIRST(&deadq_head); q != NULL; q = TAILQ_NEXT(q, dq_entries))
if (q->dq_pid == pid) {
TAILQ_REMOVE(&deadq_head, q, dq_entries);
free(q);
return 1;
}
return 0;
}
void
log_deadchild(pid, status, name)
pid_t pid;
int status;
const char *name;
{
int code;
char buf[256];
const char *reason;
errno = 0; /* Keep strerror() stuff out of logerror messages. */
if (WIFSIGNALED(status)) {
reason = "due to signal";
code = WTERMSIG(status);
} else {
reason = "with status";
code = WEXITSTATUS(status);
if (code == 0)
return;
}
(void)snprintf(buf, sizeof buf,
"Logging subprocess %d (%s) exited %s %d.",
pid, name, reason, code);
logerror(buf);
}