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>