Date: Thu, 13 Sep 2001 19:43:56 -0700 (PDT) From: Martin Baker <martinb-fbsd@kemokid.com> To: freebsd-gnats-submit@FreeBSD.org Subject: kern/30567: kqueue/kevent doesn't always work properly with pipes Message-ID: <200109140243.f8E2huG60963@freefall.freebsd.org>
next in thread | raw e-mail | index | archive | help
>Number: 30567
>Category: kern
>Synopsis: kqueue/kevent doesn't always work properly with pipes
>Confidential: no
>Severity: serious
>Priority: high
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Thu Sep 13 19:50:00 PDT 2001
>Closed-Date:
>Last-Modified:
>Originator: Martin Baker
>Release: 4.2, 4.3, and 4.4rc4
>Organization:
IronPort Systems
>Environment:
4.2-RELEASE FreeBSD 4.2-RELEASE #4: Mon Jun 25 15:40:44 PDT 2001
i386
>Description:
Using kevent() to read from fds from popen() does not always work; sometimes
kevent() waits the full timeout period and then returns zero events,
even when the pipe is clearly full (as in the output of a small, fast
Unix utility such as "df"). Oddly, printing any debug output
>How-To-Repeat:
The source for a simple test case follows. Using an fd from popen() and
repeating adding a filter using EV_ONESHOT and then asking for events,
the first, third, and following times I get proper behaviour. The second
time kevent waits the entire timeout period, then returns zero events.
Compiling this program "pipe_kqueue.c" with "make pipe_kqueue", and then
running it, you will see:
0th kevent call started at time offset 0, returned 1
1th kevent call started at time offset 0, returned 0
2th kevent call started at time offset 3, returned 1
3th kevent call started at time offset 3, returned 1
4th kevent call started at time offset 3, returned 1
All calls completed by time offset 3
If you uncomment the call to print_kevent(), the problem will not occur
(everything happens at time zero, returning one event).
Source code for pipe_kqueue.c (spacing doesn't matter):
/* minimal C example of pipe/kqueue bug */
#include <errno.h>
#include <stdio.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/event.h>
static void
print_kevent (struct kevent *e)
{
fprintf (stderr, "<kevent id=%d fflags=%d data=%d udata=0x%x>\n",
e->ident, e->fflags, (unsigned int)e->data,
(unsigned int)e->udata);
}
static void
hit_bug ()
{
FILE *fp;
int kq, fd;
int i, retval;
int count = 0;
struct kevent event;
char buf[256];
time_t times[20];
int values[20];
int entered;
errno = 0;
fp = popen ("df -m", "r");
if (fp == NULL) {
fprintf (stderr, "Could not open pipe: %s.\n", strerror (errno));
exit (1);
}
kq = kqueue();
if (kq < 0) {
fprintf (stderr, "Could not create kqueue: %s.\n", strerror (errno));
exit (1);
}
fd = fileno (fp);
if (fd < 0) {
fprintf (stderr, "Could not get fd: %s.\n", strerror (errno));
exit (1);
}
while (1) {
struct timespec timeout;
entered = 0; /* within the while loop because we use EV_ONESHOT */
timeout.tv_sec = 3;
timeout.tv_nsec = 0;
event.ident = fd;
event.filter = EVFILT_READ;
event.flags = EV_ONESHOT | EV_ADD;
event.fflags = 0;
event.data = 0;
event.udata = (void *) 0xdeadbeef;
if (!entered) {
retval = kevent (kq, &event, 1, NULL, 0, NULL);
if (retval < 0) {
fprintf (stderr, "kevent returned %d: %s.\n", retval, strerror (errno));
exit (1);
}
entered = 1;
}
times[count] = time (NULL);
retval = kevent (kq, NULL, 0, &event, 1, &timeout);
if (retval < 0) {
fprintf (stderr, "kevent returned %d: %s.\n", retval, strerror (errno));
exit (1);
}
values[count++] = retval;
if (retval > 0) {
/* Printing anything out here will hide the bug. */
/* print_kevent (&event); */
entered = 1;
}
if ((retval == 0) && (count < 15)) continue;
retval = fread (buf, 50, 1, fp);
if (retval < 0) {
fprintf (stderr, "kevent returned %d: %s.\n", retval, strerror (errno));
exit (1);
}
if (retval == 0) break;
}
times[count] = time (NULL);
values[count++] = 0;
for (i=0; i<count-1; i++) {
fprintf (stderr,
"%dth kevent call started at time offset %d, returned %d\n",
i, times[i] - times[0], values[i]);
}
fprintf (stderr, " All calls completed by time offset %d\n",
times[count-1] - times[0]);
}
int
main (int argc, char *argv[])
{
hit_bug();
return 0;
}
>Fix:
None known, except printing a lot. Creating files also seems to ward
off the bug.
>Release-Note:
>Audit-Trail:
>Unformatted:
To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-bugs" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200109140243.f8E2huG60963>