From owner-freebsd-bugs  Thu Sep 13 19:50:19 2001
Delivered-To: freebsd-bugs@hub.freebsd.org
Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21])
	by hub.freebsd.org (Postfix) with ESMTP id E9C9C37B40E
	for <freebsd-bugs@hub.freebsd.org>; Thu, 13 Sep 2001 19:50:00 -0700 (PDT)
Received: (from gnats@localhost)
	by freefall.freebsd.org (8.11.4/8.11.4) id f8E2o0R61569;
	Thu, 13 Sep 2001 19:50:00 -0700 (PDT)
	(envelope-from gnats)
Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21])
	by hub.freebsd.org (Postfix) with ESMTP id 644E637B406
	for <freebsd-gnats-submit@FreeBSD.org>; Thu, 13 Sep 2001 19:43:56 -0700 (PDT)
Received: (from nobody@localhost)
	by freefall.freebsd.org (8.11.4/8.11.4) id f8E2huG60963;
	Thu, 13 Sep 2001 19:43:56 -0700 (PDT)
	(envelope-from nobody)
Message-Id: <200109140243.f8E2huG60963@freefall.freebsd.org>
Date: Thu, 13 Sep 2001 19:43:56 -0700 (PDT)
From: Martin Baker <martinb-fbsd@kemokid.com>
To: freebsd-gnats-submit@FreeBSD.org
X-Send-Pr-Version: www-1.0
Subject: kern/30567: kqueue/kevent doesn't always work properly with pipes
Sender: owner-freebsd-bugs@FreeBSD.ORG
Precedence: bulk
List-ID: <freebsd-bugs.FreeBSD.ORG>
List-Archive: <http://docs.freebsd.org/mail/> (Web Archive)
List-Help: <mailto:majordomo@FreeBSD.ORG?subject=help> (List Instructions)
List-Subscribe: <mailto:majordomo@FreeBSD.ORG?subject=subscribe%20freebsd-bugs>
List-Unsubscribe: <mailto:majordomo@FreeBSD.ORG?subject=unsubscribe%20freebsd-bugs>
X-Loop: FreeBSD.org


>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