NetBSD Problem Report #50094
From www@NetBSD.org Sun Jul 26 19:08:27 2015
Return-Path: <www@NetBSD.org>
Received: from mail.netbsd.org (mail.netbsd.org [149.20.53.66])
(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
(Client CN "mail.netbsd.org", Issuer "Postmaster NetBSD.org" (verified OK))
by mollari.NetBSD.org (Postfix) with ESMTPS id 36974A567D
for <gnats-bugs@gnats.NetBSD.org>; Sun, 26 Jul 2015 19:08:27 +0000 (UTC)
Message-Id: <20150726190826.12321A6555@mollari.NetBSD.org>
Date: Sun, 26 Jul 2015 19:08:26 +0000 (UTC)
From: cmeerw@cmeerw.org
Reply-To: cmeerw@cmeerw.org
To: gnats-bugs@NetBSD.org
Subject: not all threads woken up when multiple threads waiting with keven on same kqueue
X-Send-Pr-Version: www-1.0
>Number: 50094
>Notify-List: bsiegert@NetBSD.org, mpratt@google.com
>Category: kern
>Synopsis: not all threads woken up when multiple threads waiting with keven on same kqueue
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: jdolecek
>State: closed
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Sun Jul 26 19:10:00 +0000 2015
>Closed-Date: Thu Feb 04 17:49:27 +0000 2021
>Last-Modified: Tue May 25 17:55:01 +0000 2021
>Originator: Christof Meerwald
>Release: netbsd-7
>Organization:
>Environment:
NetBSD droid 7.0_RC1 NetBSD 7.0_RC1 (ODROID-C1.201507211940Z) evbarm
>Description:
as reported in http://mail-index.netbsd.org/tech-userlevel/2015/07/26/msg009262.html
I have got multiple threads waiting on a single kqueue and want to
wake up all these threads at some point (before exiting). I believe
the way to do it is to have a dummy socket/pipe added to the kqueue
and close the other end (I have also found
http://thread.gmane.org/gmane.os.netbsd.devel.kernel/28051 which seems
to agree on that approach).
But when I am actually testing this approach, some threads don't seem
to be woken up and keep waiting in the kevent syscall. Source code for
a test case is available from
http://svn.cmeerw.net/src/nginetd/trunk/test/kqtest-wakeup.cc
I have tested on my ODROID-C1 (quad core ARMv7) with netbsd-7 (build
from a few days ago) and seen the problem occur with 3 or more
threads.
This has also been confirmed in netbsd-6 on x86 in http://mail-index.netbsd.org/tech-userlevel/2015/07/26/msg009257.html
>How-To-Repeat:
compile with g++ -pthread and run specifying the number of threads (e.g. 16) as the argument. Test case should consistently terminate after a 1 second sleep.
#include <stdio.h>
#include <stdlib.h>
#include <errno.h>
#include <fcntl.h>
#include <unistd.h>
#include <arpa/inet.h>
#include <sys/event.h>
#include <sys/fcntl.h>
#include <sys/socket.h>
#include <sys/time.h>
#include <pthread.h>
namespace
{
extern "C" void *worker(void *arg)
{
const int kqid = *static_cast<int *>(arg);
struct kevent events[16];
bool done = false;
while (!done)
{
int rc_kevent = kevent(kqid, NULL, 0,
events, sizeof(events)/sizeof(*events),
NULL);
done = rc_kevent != 0;
}
}
}
int main(int argc, const char * const argv[])
{
const int nr_threads = (argc > 1) ? atoi(argv[1]) : 1;
int kqid(kqueue());
int syncsockets[2];
socketpair(AF_UNIX, SOCK_STREAM, 0, syncsockets);
{
struct kevent const events[] = {
{ syncsockets[1], EVFILT_READ, EV_ADD, 0, 0, 0 },
};
kevent(kqid, events, 1, NULL, 0, NULL);
}
pthread_t *threads = new pthread_t[nr_threads];
for (int i = 0; i < nr_threads; ++i)
{
pthread_create(threads + i, NULL, worker, &kqid);
}
sleep(1);
close(syncsockets[0]);
for (int i = 0; i < nr_threads; ++i)
{
pthread_join(threads[i], NULL);
}
close(syncsockets[1]);
close(kqid);
delete [] threads;
return 0;
}
>Fix:
>Release-Note:
>Audit-Trail:
From: Christof Meerwald <cmeerw@cmeerw.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50094: not all threads woken up when multiple threads
waiting with keven on same kqueue
Date: Mon, 27 Jul 2015 21:17:58 +0200
I think I now know what is going on here.
For events that have neither EV_ONESHOT and EV_CLEAR set, the knote is
removed from the kqueue, the kqueue is unlocked, the event is
re-checked, the kqueue is locked again and the knote is re-added to
the kqueue.
The problem here is that there is a good chance that some of the
threads will see the kqueue being empty when woken up (while another
thread has removed the knote from the kqueue and is re-checking the
event) and go back to sleep.
A potential straightforward fix appears to be to add a cv_broadcast
call after the knote has been re-added to the kqueue.
Index: kern_event.c
===================================================================
RCS file: /cvsroot/src/sys/kern/kern_event.c,v
retrieving revision 1.83
diff -u -r1.83 kern_event.c
--- kern_event.c 2 Mar 2015 19:24:53 -0000 1.83
+++ kern_event.c 27 Jul 2015 19:05:30 -0000
@@ -1266,6 +1266,7 @@
kq->kq_count++;
kn->kn_status |= KN_QUEUED;
kq_check(kq);
+ cv_broadcast(&kq->kq_cv);
}
if (nkev == kevcnt) {
/* do copyouts in kevcnt chunks */
Christof
--
http://cmeerw.org sip:cmeerw at cmeerw.org
mailto:cmeerw at cmeerw.org xmpp:cmeerw at cmeerw.org
From: Michael Pratt <mpratt@google.com>
To: gnats-bugs@netbsd.org
Cc:
Subject: Re: kern/50094
Date: Thu, 17 Dec 2020 12:27:40 -0500
This problem is affecting the Go language runtime. See
https://github.com/golang/go/issues/42515 for complete details.
In particular, see
https://github.com/golang/go/issues/42515#issuecomment-747097912,
where I came to the same conclusion as Christof that the problem is
that the kqueue is unlocked with the knote removed, thus a racing
kevent call may miss the event. I've also captured custom ktrace
traces to demonstrate the problem.
However, while I believe Christof's proposed fix would work for
blocking kevent calls, it would still allow non-blocking kevent calls
to miss the event and return without it in violation of the API. It is
not clear to me how this should be fixed as I don't know exactly what
constraints require unlocking in the first place. For reference,
FreeBSD seems to handle this issue by noticing that the kqueue is "in
flux" and waiting for it to settle:
https://github.com/freebsd/freebsd/blob/master/sys/kern/kern_event.c#L1859-L1869.
I have a C reproducer similar to Go's usage at
https://gist.github.com/prattmic/8b5bc6c87437bd4496d5f546fb3226fc,
which is copied at the end of this email for convenience.
The C reproducer should be sufficient to see the issue, but here's
some additional context on Go's usage for reference:
Go uses a single kqueue to track networking file descriptors
("netpoll"). Typically there is one blocking kevent caller to capture
events when the process is otherwise idle, plus multiple non-blocking
callers from threads looking for work (so we don't need complete
synchronization with the blocking thread).
The blocking thread serves a second purpose to implement Go timers.
The timeout on the kevent is set to the earliest expiring timer. When
the kevent times out, we notice and handle the now-expired timer. If
user code sets a timer expiring earlier than any other, then we need
to break out of the blocking kevent to restart with a shorter timeout.
We do this by writing to a special purpose pipe used just for
generating events to break out of kevent. It is these "netpoll break"
events that we are occasionally missing due to this bug.
In Go 1.15 and prior, there was an additional background thread
running periodically that could also notice overrun timers and handle
them (at the expense of latency, since this only runs periodically).
For Go 1.16, various improvements to improve timer latency have made
that periodic check unnecessary, so it has been removed. Now this bug
is loudly exposed as we can completely miss timers for an unbounded
period, hanging programs and causing test timeouts.
As a workaround we will add back the periodic check for NetBSD, but as
mentioned above, it is at the expense of timer latency, so we'd really
like to see this bug fixed.
Regards,
Michael Pratt
---
// $ gcc -pthread kqueue_race.c
// $ ./a.out
// kevent = 0
// Incorrect number of events after 477 calls!
#include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <sys/event.h>
#include <sys/time.h>
#include <unistd.h>
int kq;
void* read_kevent(void* arg) {
int count = 0;
while (1) {
count++;
// Non-blocking.
struct timespec ts = {};
struct kevent ev;
int n = kevent(kq, NULL, 0, &ev, 1, &ts);
if (n < 0) {
perror("kevent");
exit(1);
} else if (n != 1) {
printf("kevent = %d\n", n);
printf("Incorrect number of events after %d calls!\n", count);
exit(2);
}
}
}
int main(int argc, char** argv) {
int p[2];
int ret = pipe(p);
if (ret < 0) {
perror("pipe");
return 1;
}
kq = kqueue();
if (kq < 0) {
perror("kqueue");
return 1;
}
struct kevent ev = {};
EV_SET(&ev, p[0], EVFILT_READ, EV_ADD, 0, 0, 0);
ret = kevent(kq, &ev, 1, NULL, 0, NULL);
if (ret < 0) {
perror("kevent register");
return 1;
}
// Write to pipe, kevent now ready for read end.
char c = 0;
ret = write(p[1], &c, 1);
if (ret != 1) {
perror("write");
return 1;
}
pthread_t t1, t2;
ret = pthread_create(&t1, NULL, read_kevent, NULL);
if (ret < 0) {
perror("pthread_create");
return 1;
}
ret = pthread_create(&t2, NULL, read_kevent, NULL);
if (ret < 0) {
perror("pthread_create");
return 1;
}
pthread_join(t1, NULL);
pthread_join(t2, NULL);
return 0;
}
Responsible-Changed-From-To: kern-bug-people->jdolecek
Responsible-Changed-By: jdolecek@NetBSD.org
Responsible-Changed-When: Sat, 19 Dec 2020 11:57:46 +0000
Responsible-Changed-Why:
I'll look into this over next week or so.
From: =?UTF-8?B?SmFyb23DrXIgRG9sZcSNZWs=?= <jaromir.dolecek@gmail.com>
To: "gnats-bugs@NetBSD.org" <gnats-bugs@netbsd.org>
Cc: cmeerw@cmeerw.org
Subject: Re: kern/50094
Date: Sat, 26 Dec 2020 17:18:38 +0100
Thanks for additional info. I was able to reproduce the problem using
the supplied test program even under 1 cpu VM. I'm looking into
adapting the FreeBSD fix.
From: "Jaromir Dolecek" <jdolecek@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: src/sys/kern
Date: Sun, 27 Dec 2020 12:45:33 +0000
Module Name: src
Committed By: jdolecek
Date: Sun Dec 27 12:45:33 UTC 2020
Modified Files:
src/sys/kern: kern_event.c
Log Message:
reduce indentation for the main processing loop in kqueue_scan(), this also
makes the code more similar to FreeBSD; NFCI
part of PR kern/50094
To generate a diff of this commit:
cvs rdiff -u -r1.109 -r1.110 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
State-Changed-From-To: open->feedback
State-Changed-By: jdolecek@NetBSD.org
State-Changed-When: Wed, 20 Jan 2021 21:41:11 +0000
State-Changed-Why:
Fix committed, can you please confirm it fixes the problem for you?
I've tested the change with Michael Pratt's program, which no longer
fails.
From: "Jaromir Dolecek" <jdolecek@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: src/sys/kern
Date: Wed, 20 Jan 2021 21:39:09 +0000
Module Name: src
Committed By: jdolecek
Date: Wed Jan 20 21:39:09 UTC 2021
Modified Files:
src/sys/kern: kern_event.c
Log Message:
fix a race in kqueue_scan() - when multiple threads check the same
kqueue, it could happen other thread seen empty kqueue while kevent
was being checked for re-firing and re-queued
make sure to keep retrying if there are outstanding kevents even
if no kevent is found on first pass through the queue, and only
drop the KN_QUEUED flag and kq_count when actually completely done
with the kevent
change is inspired by the FreeBSD in-flux handling, but without
introducing the reference counting
PR kern/50094 by Christof Meerwald
To generate a diff of this commit:
cvs rdiff -u -r1.110 -r1.111 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
From: "Jaromir Dolecek" <jdolecek@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: src/sys/kern
Date: Thu, 21 Jan 2021 18:09:24 +0000
Module Name: src
Committed By: jdolecek
Date: Thu Jan 21 18:09:23 UTC 2021
Modified Files:
src/sys/kern: kern_event.c
Log Message:
adjust kq_check() (enabled with DEBUG) to new reality - it's now perfectly
normal to have kq_count bigger than number of the linked entries
on the kqueue
PR kern/50094, problem pointed out by Chuck Silvers
To generate a diff of this commit:
cvs rdiff -u -r1.111 -r1.112 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
From: "Jaromir Dolecek" <jdolecek@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: src/sys/kern
Date: Sun, 24 Jan 2021 11:31:48 +0000
Module Name: src
Committed By: jdolecek
Date: Sun Jan 24 11:31:47 UTC 2021
Modified Files:
src/sys/kern: kern_event.c
Log Message:
don't check signals while waiting for other kqueue scans to finish
reportedly somewhat improves behaviour for PR kern/55946
part of PR kern/50094 fix
To generate a diff of this commit:
cvs rdiff -u -r1.113 -r1.114 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
From: "Jaromir Dolecek" <jdolecek@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: src/sys/kern
Date: Mon, 25 Jan 2021 19:57:05 +0000
Module Name: src
Committed By: jdolecek
Date: Mon Jan 25 19:57:05 UTC 2021
Modified Files:
src/sys/kern: kern_event.c
Log Message:
put back clearing of KN_QUEUED and check for re-queue - as rev. 1.53 notes,
it's necessary for correct function
fixes PR kern/55946, thanks to Paul Goyette for testing
part of PR kern/50094 fix
To generate a diff of this commit:
cvs rdiff -u -r1.114 -r1.115 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
From: "Jaromir Dolecek" <jdolecek@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: src/sys/kern
Date: Tue, 26 Jan 2021 19:09:18 +0000
Module Name: src
Committed By: jdolecek
Date: Tue Jan 26 19:09:18 UTC 2021
Modified Files:
src/sys/kern: kern_event.c
Log Message:
call f_touch with kq_lock held, and without KERNEL_LOCK() - for this
adjust EVFILT_USER, which is the only filter actually using that hook
kqueue_scan() now doesn't need to exit/enter the kq_lock when calling
f_touch, which removes another possible race
part of PR kern/50094
To generate a diff of this commit:
cvs rdiff -u -r1.115 -r1.116 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
State-Changed-From-To: feedback->pending-pullups
State-Changed-By: jdolecek@NetBSD.org
State-Changed-When: Tue, 26 Jan 2021 19:32:42 +0000
State-Changed-Why:
The test program now consistently exits after around 1s as it should,
there is not much more to test.
I'm requesting pullup to netbsd-9
From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc:
Subject: PR/50094 CVS commit: [netbsd-9] src/sys/kern
Date: Thu, 4 Feb 2021 16:57:25 +0000
Module Name: src
Committed By: martin
Date: Thu Feb 4 16:57:25 UTC 2021
Modified Files:
src/sys/kern [netbsd-9]: kern_event.c
Log Message:
Pullup the following (requested by jdolecek in ticket #1191):
sys/kern/kern_event.c r1.110-1.115 (via patch)
fix a race in kqueue_scan() - when multiple threads check the same
kqueue, it could happen other thread seen empty kqueue while kevent
was being checked for re-firing and re-queued
make sure to keep retrying if there are outstanding kevents even
if no kevent is found on first pass through the queue, and only
kq_count when actually completely done with the kevent
PR kern/50094 by Christof Meerwal
Also fixes timer latency in Go, as reported in
https://github.com/golang/go/issues/42515 by Michael Pratt
To generate a diff of this commit:
cvs rdiff -u -r1.104 -r1.104.4.1 src/sys/kern/kern_event.c
Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.
State-Changed-From-To: pending-pullups->closed
State-Changed-By: jdolecek@NetBSD.org
State-Changed-When: Thu, 04 Feb 2021 17:49:27 +0000
State-Changed-Why:
Pullup to netbsd-9 done as ticket #1191
From: =?UTF-8?B?SmFyb23DrXIgRG9sZcSNZWs=?= <jaromir.dolecek@gmail.com>
To: "gnats-bugs@NetBSD.org" <gnats-bugs@netbsd.org>, mpratt@google.com
Cc:
Subject: Re: kern/50094
Date: Tue, 25 May 2021 19:52:33 +0200
Michael,
The new stable system version NetBSD 9.2 was released with the fix, so
the NetBSD-specific code can be dropped as convenient.
Jaromir
Le jeu. 17 d=C3=A9c. 2020 =C3=A0 18:31, Michael Pratt <mpratt@google.com> a=
=C3=A9crit :
>
> The following reply was made to PR kern/50094; it has been noted by GNATS=
.
>
> From: Michael Pratt <mpratt@google.com>
> To: gnats-bugs@netbsd.org
> Cc:
> Subject: Re: kern/50094
> Date: Thu, 17 Dec 2020 12:27:40 -0500
>
> This problem is affecting the Go language runtime. See
> https://github.com/golang/go/issues/42515 for complete details.
>
> In particular, see
> https://github.com/golang/go/issues/42515#issuecomment-747097912,
> where I came to the same conclusion as Christof that the problem is
> that the kqueue is unlocked with the knote removed, thus a racing
> kevent call may miss the event. I've also captured custom ktrace
> traces to demonstrate the problem.
>Unformatted:
(Contact us)
$NetBSD: query-full-pr,v 1.46 2020/01/03 16:35:01 leot Exp $
$NetBSD: gnats_config.sh,v 1.9 2014/08/02 14:16:04 spz Exp $
Copyright © 1994-2020
The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.
Home