[libvirt] PATCH: 0/4: Fix the event loop (again) no really, this time its fixed.

Back in March I attempted to fix the event loop handling of deleted file handles http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html but have merely succeeded in screwing it up in a different fun & exciting way. That patch fixed a case where there was a deleted file handle in the list at the time virEventRunOnce() starts. Which was nice. Not nice, though was that it then breaks the case where a file handle is deleted during the course of dispatching events afer poll(). Investigating this also identified that when we were marking a file handle as deleted, we were forgetting to run virEventInterrupt(), which meant that in some cases the main thread would not be woken up until the next event triggers. Not very critical, but at the same time, not good because it delays cleanup & release of resources. This series of patches fixes the problems, and more importantly, adds a unit test which cover these nasty edge cases. Daniel -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|

The qemudSetNonBlock() and qemudSetCloseExec() should not exist anymore since we have impls virSetNonBlock virSetCloseExec in util.h. Removing these makes it possible to link directly to qemud/event.c for a later test case. Daniel diff -r d5dc15adcbea qemud/event.c --- a/qemud/event.c Fri May 08 11:58:19 2009 +0100 +++ b/qemud/event.c Fri May 08 15:52:29 2009 +0100 @@ -30,7 +30,8 @@ #include <errno.h> #include <unistd.h> -#include "qemud.h" +#include "threads.h" +#include "logging.h" #include "event.h" #include "memory.h" #include "util.h" @@ -597,10 +598,10 @@ int virEventInit(void) return -1; if (pipe(eventLoop.wakeupfd) < 0 || - qemudSetNonBlock(eventLoop.wakeupfd[0]) < 0 || - qemudSetNonBlock(eventLoop.wakeupfd[1]) < 0 || - qemudSetCloseExec(eventLoop.wakeupfd[0]) < 0 || - qemudSetCloseExec(eventLoop.wakeupfd[1]) < 0) + virSetNonBlock(eventLoop.wakeupfd[0]) < 0 || + virSetNonBlock(eventLoop.wakeupfd[1]) < 0 || + virSetCloseExec(eventLoop.wakeupfd[0]) < 0 || + virSetCloseExec(eventLoop.wakeupfd[1]) < 0) return -1; if (virEventAddHandleImpl(eventLoop.wakeupfd[0], diff -r d5dc15adcbea qemud/qemud.c --- a/qemud/qemud.c Fri May 08 11:58:19 2009 +0100 +++ b/qemud/qemud.c Fri May 08 15:52:29 2009 +0100 @@ -371,32 +371,6 @@ qemudDispatchSignalEvent(int watch ATTRI virMutexUnlock(&server->lock); } -int qemudSetCloseExec(int fd) { - int flags; - if ((flags = fcntl(fd, F_GETFD)) < 0) - goto error; - flags |= FD_CLOEXEC; - if ((fcntl(fd, F_SETFD, flags)) < 0) - goto error; - return 0; - error: - VIR_ERROR0(_("Failed to set close-on-exec file descriptor flag")); - return -1; -} - - -int qemudSetNonBlock(int fd) { - int flags; - if ((flags = fcntl(fd, F_GETFL)) < 0) - goto error; - flags |= O_NONBLOCK; - if ((fcntl(fd, F_SETFL, flags)) < 0) - goto error; - return 0; - error: - VIR_ERROR0(_("Failed to set non-blocking file descriptor flag")); - return -1; -} static int qemudGoDaemon(void) { int pid = fork(); @@ -525,8 +499,8 @@ static int qemudListenUnix(struct qemud_ goto cleanup; } - if (qemudSetCloseExec(sock->fd) < 0 || - qemudSetNonBlock(sock->fd) < 0) + if (virSetCloseExec(sock->fd) < 0 || + virSetNonBlock(sock->fd) < 0) goto cleanup; memset(&addr, 0, sizeof(addr)); @@ -687,8 +661,8 @@ remoteListenTCP (struct qemud_server *se else sock->port = -1; - if (qemudSetCloseExec(sock->fd) < 0 || - qemudSetNonBlock(sock->fd) < 0) + if (virSetCloseExec(sock->fd) < 0 || + virSetNonBlock(sock->fd) < 0) goto cleanup; if (listen (sock->fd, 30) < 0) { @@ -1273,8 +1247,8 @@ static int qemudDispatchServer(struct qe setsockopt (fd, IPPROTO_TCP, TCP_NODELAY, (void *)&no_slow_start, sizeof no_slow_start); - if (qemudSetCloseExec(fd) < 0 || - qemudSetNonBlock(fd) < 0) { + if (virSetCloseExec(fd) < 0 || + virSetNonBlock(fd) < 0) { close(fd); return -1; } @@ -2872,10 +2846,10 @@ int main(int argc, char **argv) { goto error1; if (pipe(sigpipe) < 0 || - qemudSetNonBlock(sigpipe[0]) < 0 || - qemudSetNonBlock(sigpipe[1]) < 0 || - qemudSetCloseExec(sigpipe[0]) < 0 || - qemudSetCloseExec(sigpipe[1]) < 0) { + virSetNonBlock(sigpipe[0]) < 0 || + virSetNonBlock(sigpipe[1]) < 0 || + virSetCloseExec(sigpipe[0]) < 0 || + virSetCloseExec(sigpipe[1]) < 0) { char ebuf[1024]; VIR_ERROR(_("Failed to create pipe: %s"), virStrerror(errno, ebuf, sizeof ebuf)); diff -r d5dc15adcbea qemud/qemud.h --- a/qemud/qemud.h Fri May 08 11:58:19 2009 +0100 +++ b/qemud/qemud.h Fri May 08 15:52:29 2009 +0100 @@ -198,9 +198,6 @@ void qemudLog(int priority, const char * ATTRIBUTE_FORMAT(printf,2,3); -int qemudSetCloseExec(int fd); -int qemudSetNonBlock(int fd); - int remoteDispatchClientRequest (struct qemud_server *server, struct qemud_client *client, -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|

On Mon, May 11, 2009 at 12:13:52PM +0100, Daniel P. Berrange wrote:
The qemudSetNonBlock() and qemudSetCloseExec() should not exist anymore since we have impls virSetNonBlock virSetCloseExec in util.h. Removing these makes it possible to link directly to qemud/event.c for a later test case.
ACK, Daniel -- Daniel Veillard | libxml Gnome XML XSLT toolkit http://xmlsoft.org/ daniel@veillard.com | Rpmfind RPM search engine http://rpmfind.net/ http://veillard.com/ | virtualization library http://libvirt.org/

Several methods forgot to call virEventInterruptLocked() in critical times, or called it at the wrong point. This fixes that problem. It also changes watch and timer numbers to start from 1, instead of 0. This is because we've had a number of bugs where code has passed an uninitialized timer/watch ID to an update/delete method, and this has resulted in deleting a real important timer/watch. Changing to start from 1, and logging invalid watches will protect us from uninitialized watches/timers. Daniel diff -r df82b18a3425 qemud/event.c --- a/qemud/event.c Fri May 08 15:52:29 2009 +0100 +++ b/qemud/event.c Fri May 08 16:06:40 2009 +0100 @@ -84,10 +84,10 @@ struct virEventLoop { static struct virEventLoop eventLoop; /* Unique ID for the next FD watch to be registered */ -static int nextWatch = 0; +static int nextWatch = 1; /* Unique ID for the next timer to be registered */ -static int nextTimer = 0; +static int nextTimer = 1; static void virEventLock(void) { @@ -143,15 +143,22 @@ int virEventAddHandleImpl(int fd, int ev void virEventUpdateHandleImpl(int watch, int events) { int i; + EVENT_DEBUG("Update handle w=%d e=%d", watch, events); + + if (watch <= 0) { + VIR_WARN("Ignoring invalid update watch %d", watch); + return; + } + virEventLock(); for (i = 0 ; i < eventLoop.handlesCount ; i++) { if (eventLoop.handles[i].watch == watch) { eventLoop.handles[i].events = virEventHandleTypeToPollEvent(events); + virEventInterruptLocked(); break; } } - virEventInterruptLocked(); virEventUnlock(); } @@ -164,6 +171,12 @@ void virEventUpdateHandleImpl(int watch, int virEventRemoveHandleImpl(int watch) { int i; EVENT_DEBUG("Remove handle %d", watch); + + if (watch <= 0) { + VIR_WARN("Ignoring invalid remove watch %d", watch); + return -1; + } + virEventLock(); for (i = 0 ; i < eventLoop.handlesCount ; i++) { if (eventLoop.handles[i].deleted) @@ -172,11 +185,11 @@ int virEventRemoveHandleImpl(int watch) if (eventLoop.handles[i].watch == watch) { EVENT_DEBUG("mark delete %d %d", i, eventLoop.handles[i].fd); eventLoop.handles[i].deleted = 1; + virEventInterruptLocked(); virEventUnlock(); return 0; } } - virEventInterruptLocked(); virEventUnlock(); return -1; } @@ -232,6 +245,12 @@ void virEventUpdateTimeoutImpl(int timer struct timeval tv; int i; EVENT_DEBUG("Updating timer %d timeout with %d ms freq", timer, frequency); + + if (timer <= 0) { + VIR_WARN("Ignoring invalid update timer %d", timer); + return; + } + if (gettimeofday(&tv, NULL) < 0) { return; } @@ -244,10 +263,10 @@ void virEventUpdateTimeoutImpl(int timer frequency >= 0 ? frequency + (((unsigned long long)tv.tv_sec)*1000) + (((unsigned long long)tv.tv_usec)/1000) : 0; + virEventInterruptLocked(); break; } } - virEventInterruptLocked(); virEventUnlock(); } @@ -260,6 +279,12 @@ void virEventUpdateTimeoutImpl(int timer int virEventRemoveTimeoutImpl(int timer) { int i; EVENT_DEBUG("Remove timer %d", timer); + + if (timer <= 0) { + VIR_WARN("Ignoring invalid remove timer %d", timer); + return -1; + } + virEventLock(); for (i = 0 ; i < eventLoop.timeoutsCount ; i++) { if (eventLoop.timeouts[i].deleted) @@ -267,11 +292,11 @@ int virEventRemoveTimeoutImpl(int timer) if (eventLoop.timeouts[i].timer == timer) { eventLoop.timeouts[i].deleted = 1; + virEventInterruptLocked(); virEventUnlock(); return 0; } } - virEventInterruptLocked(); virEventUnlock(); return -1; } @@ -617,9 +642,12 @@ static int virEventInterruptLocked(void) char c = '\0'; if (!eventLoop.running || - pthread_self() == eventLoop.leader) + pthread_self() == eventLoop.leader) { + VIR_DEBUG("Skip interrupt, %d %d", eventLoop.running, (int)eventLoop.leader); return 0; + } + VIR_DEBUG0("Interrupting"); if (safewrite(eventLoop.wakeupfd[1], &c, sizeof(c)) != sizeof(c)) return -1; return 0; -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|

On Mon, May 11, 2009 at 12:17:23PM +0100, Daniel P. Berrange wrote:
Several methods forgot to call virEventInterruptLocked() in critical times, or called it at the wrong point. This fixes that problem.
It also changes watch and timer numbers to start from 1, instead of 0. This is because we've had a number of bugs where code has passed an uninitialized timer/watch ID to an update/delete method, and this has resulted in deleting a real important timer/watch. Changing to start from 1, and logging invalid watches will protect us from uninitialized watches/timers.
Sounds good !
virEventLock(); for (i = 0 ; i < eventLoop.handlesCount ; i++) { if (eventLoop.handles[i].watch == watch) { eventLoop.handles[i].events = virEventHandleTypeToPollEvent(events); + virEventInterruptLocked(); break; } } - virEventInterruptLocked(); virEventUnlock(); }
Okay so basically the core of the patch is to lock as soon as we match and not once out of the loop
@@ -172,11 +185,11 @@ int virEventRemoveHandleImpl(int watch) if (eventLoop.handles[i].watch == watch) { EVENT_DEBUG("mark delete %d %d", i, eventLoop.handles[i].fd); eventLoop.handles[i].deleted = 1; + virEventInterruptLocked(); virEventUnlock(); return 0; } } - virEventInterruptLocked(); virEventUnlock(); return -1; }
same here
@@ -244,10 +263,10 @@ void virEventUpdateTimeoutImpl(int timer frequency >= 0 ? frequency + (((unsigned long long)tv.tv_sec)*1000) + (((unsigned long long)tv.tv_usec)/1000) : 0; + virEventInterruptLocked(); break; } } - virEventInterruptLocked(); virEventUnlock(); }
and here
@@ -267,11 +292,11 @@ int virEventRemoveTimeoutImpl(int timer)
if (eventLoop.timeouts[i].timer == timer) { eventLoop.timeouts[i].deleted = 1; + virEventInterruptLocked(); virEventUnlock(); return 0; } } - virEventInterruptLocked(); virEventUnlock(); return -1; }
and here. I assume the problem were on imbricated loops. Patch looks fine, ACK, and an important fix ! Daniel -- Daniel Veillard | libxml Gnome XML XSLT toolkit http://xmlsoft.org/ daniel@veillard.com | Rpmfind RPM search engine http://rpmfind.net/ http://veillard.com/ | virtualization library http://libvirt.org/

This patch fixes handling of deleted file handles. First of all it reverts the patch http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html As an alternative solution to that original problem, the first thing that virEventRunOnce() does, is to purge all timers/watches which were marked as deleted. This deals with deletes that happen between invocations of the virEventRunOnce() method. It also ensures that when going into poll(), all the registered timers/watches are live. This guarentees that array indexes match up between the poll FD array and our list of watches. Then during the dispatch of FDs, we have a simpler check to skip invocation of file handles / timers marked as deleted. Daniel diff -r 63d6824fe2a3 qemud/event.c --- a/qemud/event.c Fri May 08 16:06:40 2009 +0100 +++ b/qemud/event.c Fri May 08 16:07:04 2009 +0100 @@ -313,7 +313,7 @@ static int virEventCalculateTimeout(int EVENT_DEBUG("Calculate expiry of %d timers", eventLoop.timeoutsCount); /* Figure out if we need a timeout */ for (i = 0 ; i < eventLoop.timeoutsCount ; i++) { - if (eventLoop.timeouts[i].deleted || eventLoop.timeouts[i].frequency < 0) + if (eventLoop.timeouts[i].frequency < 0) continue; EVENT_DEBUG("Got a timeout scheduled for %llu", eventLoop.timeouts[i].expiresAt); @@ -350,32 +350,26 @@ static int virEventCalculateTimeout(int * file handles. The caller must free the returned data struct * returns: the pollfd array, or NULL on error */ -static int virEventMakePollFDs(struct pollfd **retfds) { +static struct pollfd *virEventMakePollFDs(void) { struct pollfd *fds; - int i, nfds = 0; + int i; + + /* Setup the poll file handle data structs */ + if (VIR_ALLOC_N(fds, eventLoop.handlesCount) < 0) + return NULL; for (i = 0 ; i < eventLoop.handlesCount ; i++) { - if (eventLoop.handles[i].deleted) - continue; - nfds++; - } - *retfds = NULL; - /* Setup the poll file handle data structs */ - if (VIR_ALLOC_N(fds, nfds) < 0) - return -1; - - for (i = 0, nfds = 0 ; i < eventLoop.handlesCount ; i++) { - if (eventLoop.handles[i].deleted) - continue; - fds[nfds].fd = eventLoop.handles[i].fd; - fds[nfds].events = eventLoop.handles[i].events; - fds[nfds].revents = 0; + EVENT_DEBUG("Prepare n=%d w=%d, f=%d e=%d", i, + eventLoop.handles[i].watch, + eventLoop.handles[i].fd, + eventLoop.handles[i].events); + fds[i].fd = eventLoop.handles[i].fd; + fds[i].events = eventLoop.handles[i].events; + fds[i].revents = 0; //EVENT_DEBUG("Wait for %d %d", eventLoop.handles[i].fd, eventLoop.handles[i].events); - nfds++; } - *retfds = fds; - return nfds; + return fds; } @@ -435,26 +429,30 @@ static int virEventDispatchTimeouts(void * Returns 0 upon success, -1 if an error occurred */ static int virEventDispatchHandles(int nfds, struct pollfd *fds) { - int i, n; + int i; - for (i = 0, n = 0 ; i < eventLoop.handlesCount && n < nfds ; i++) { + /* NB, use nfds not eventLoop.handlesCount, because new + * fds might be added on end of list, and they're not + * in the fds array we've got */ + for (i = 0 ; i < nfds ; i++) { if (eventLoop.handles[i].deleted) { - EVENT_DEBUG("Skip deleted %d", eventLoop.handles[i].fd); + EVENT_DEBUG("Skip deleted n=%d w=%d f=%d", i, + eventLoop.handles[i].watch, eventLoop.handles[i].fd); continue; } - if (fds[n].revents) { + if (fds[i].revents) { virEventHandleCallback cb = eventLoop.handles[i].cb; void *opaque = eventLoop.handles[i].opaque; - int hEvents = virPollEventToEventHandleType(fds[n].revents); - EVENT_DEBUG("Dispatch %d %d %p", fds[n].fd, - fds[n].revents, eventLoop.handles[i].opaque); + int hEvents = virPollEventToEventHandleType(fds[i].revents); + EVENT_DEBUG("Dispatch n=%d f=%d w=%d e=%d %p", i, + fds[i].fd, eventLoop.handles[i].watch, + fds[i].revents, eventLoop.handles[i].opaque); virEventUnlock(); (cb)(eventLoop.handles[i].watch, - fds[n].fd, hEvents, opaque); + fds[i].fd, hEvents, opaque); virEventLock(); } - n++; } return 0; @@ -545,22 +543,21 @@ static int virEventCleanupHandles(void) * at least one file handle has an event, or a timer expires */ int virEventRunOnce(void) { - struct pollfd *fds; + struct pollfd *fds = NULL; int ret, timeout, nfds; virEventLock(); eventLoop.running = 1; eventLoop.leader = pthread_self(); - if ((nfds = virEventMakePollFDs(&fds)) < 0) { - virEventUnlock(); - return -1; - } - if (virEventCalculateTimeout(&timeout) < 0) { - VIR_FREE(fds); - virEventUnlock(); - return -1; - } + if (virEventCleanupTimeouts() < 0 || + virEventCleanupHandles() < 0) + goto error; + + if (!(fds = virEventMakePollFDs()) || + virEventCalculateTimeout(&timeout) < 0) + goto error; + nfds = eventLoop.handlesCount; virEventUnlock(); @@ -572,38 +569,31 @@ int virEventRunOnce(void) { if (errno == EINTR) { goto retry; } - VIR_FREE(fds); - return -1; + goto error_unlocked; } virEventLock(); - if (virEventDispatchTimeouts() < 0) { - VIR_FREE(fds); - virEventUnlock(); - return -1; - } + if (virEventDispatchTimeouts() < 0) + goto error; if (ret > 0 && - virEventDispatchHandles(nfds, fds) < 0) { - VIR_FREE(fds); - virEventUnlock(); - return -1; - } - VIR_FREE(fds); + virEventDispatchHandles(nfds, fds) < 0) + goto error; - if (virEventCleanupTimeouts() < 0) { - virEventUnlock(); - return -1; - } - - if (virEventCleanupHandles() < 0) { - virEventUnlock(); - return -1; - } + if (virEventCleanupTimeouts() < 0 || + virEventCleanupHandles() < 0) + goto error; eventLoop.running = 0; virEventUnlock(); + VIR_FREE(fds); return 0; + +error: + virEventUnlock(); +error_unlocked: + VIR_FREE(fds); + return -1; } static void virEventHandleWakeup(int watch ATTRIBUTE_UNUSED, -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|

On Mon, May 11, 2009 at 12:21:40PM +0100, Daniel P. Berrange wrote:
This patch fixes handling of deleted file handles. First of all it reverts the patch http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html As an alternative solution to that original problem, the first thing that virEventRunOnce() does, is to purge all timers/watches which were marked as deleted. This deals with deletes that happen between invocations of the virEventRunOnce() method. It also ensures that when going into poll(), all the registered timers/watches are live. This guarentees that array indexes match up between the poll FD array and our list of watches. Then during the dispatch of FDs, we have a simpler check to skip invocation of file handles / timers marked as deleted. [...] -static int virEventMakePollFDs(struct pollfd **retfds) { +static struct pollfd *virEventMakePollFDs(void) { struct pollfd *fds; - int i, nfds = 0; + int i; + + /* Setup the poll file handle data structs */ + if (VIR_ALLOC_N(fds, eventLoop.handlesCount) < 0) + return NULL;
for (i = 0 ; i < eventLoop.handlesCount ; i++) { - if (eventLoop.handles[i].deleted) - continue; - nfds++; - } - *retfds = NULL; - /* Setup the poll file handle data structs */ - if (VIR_ALLOC_N(fds, nfds) < 0) - return -1; - - for (i = 0, nfds = 0 ; i < eventLoop.handlesCount ; i++) { - if (eventLoop.handles[i].deleted) - continue; - fds[nfds].fd = eventLoop.handles[i].fd; - fds[nfds].events = eventLoop.handles[i].events; - fds[nfds].revents = 0; + EVENT_DEBUG("Prepare n=%d w=%d, f=%d e=%d", i, + eventLoop.handles[i].watch, + eventLoop.handles[i].fd, + eventLoop.handles[i].events); + fds[i].fd = eventLoop.handles[i].fd; + fds[i].events = eventLoop.handles[i].events; + fds[i].revents = 0; //EVENT_DEBUG("Wait for %d %d", eventLoop.handles[i].fd, eventLoop.handles[i].events); - nfds++; }
- *retfds = fds; - return nfds; + return fds; }
Okay the loop is way simpler now
@@ -435,26 +429,30 @@ static int virEventDispatchTimeouts(void * Returns 0 upon success, -1 if an error occurred */ static int virEventDispatchHandles(int nfds, struct pollfd *fds) { - int i, n; + int i;
- for (i = 0, n = 0 ; i < eventLoop.handlesCount && n < nfds ; i++) { + /* NB, use nfds not eventLoop.handlesCount, because new + * fds might be added on end of list, and they're not + * in the fds array we've got */ + for (i = 0 ; i < nfds ; i++) { if (eventLoop.handles[i].deleted) { - EVENT_DEBUG("Skip deleted %d", eventLoop.handles[i].fd); + EVENT_DEBUG("Skip deleted n=%d w=%d f=%d", i, + eventLoop.handles[i].watch, eventLoop.handles[i].fd); continue; }
- if (fds[n].revents) { + if (fds[i].revents) { virEventHandleCallback cb = eventLoop.handles[i].cb; void *opaque = eventLoop.handles[i].opaque; - int hEvents = virPollEventToEventHandleType(fds[n].revents); - EVENT_DEBUG("Dispatch %d %d %p", fds[n].fd, - fds[n].revents, eventLoop.handles[i].opaque); + int hEvents = virPollEventToEventHandleType(fds[i].revents); + EVENT_DEBUG("Dispatch n=%d f=%d w=%d e=%d %p", i, + fds[i].fd, eventLoop.handles[i].watch, + fds[i].revents, eventLoop.handles[i].opaque); virEventUnlock(); (cb)(eventLoop.handles[i].watch, - fds[n].fd, hEvents, opaque); + fds[i].fd, hEvents, opaque); virEventLock(); } - n++; }
return 0;
and here too
@@ -545,22 +543,21 @@ static int virEventCleanupHandles(void) * at least one file handle has an event, or a timer expires */ int virEventRunOnce(void) { - struct pollfd *fds; + struct pollfd *fds = NULL; int ret, timeout, nfds;
virEventLock(); eventLoop.running = 1; eventLoop.leader = pthread_self(); - if ((nfds = virEventMakePollFDs(&fds)) < 0) { - virEventUnlock(); - return -1; - }
- if (virEventCalculateTimeout(&timeout) < 0) { - VIR_FREE(fds); - virEventUnlock(); - return -1; - } + if (virEventCleanupTimeouts() < 0 || + virEventCleanupHandles() < 0) + goto error; + + if (!(fds = virEventMakePollFDs()) || + virEventCalculateTimeout(&timeout) < 0) + goto error; + nfds = eventLoop.handlesCount;
virEventUnlock();
here we separate the processing
@@ -572,38 +569,31 @@ int virEventRunOnce(void) { if (errno == EINTR) { goto retry; } - VIR_FREE(fds); - return -1; + goto error_unlocked; }
virEventLock(); - if (virEventDispatchTimeouts() < 0) { - VIR_FREE(fds); - virEventUnlock(); - return -1; - } + if (virEventDispatchTimeouts() < 0) + goto error;
if (ret > 0 && - virEventDispatchHandles(nfds, fds) < 0) { - VIR_FREE(fds); - virEventUnlock(); - return -1; - } - VIR_FREE(fds); + virEventDispatchHandles(nfds, fds) < 0) + goto error;
- if (virEventCleanupTimeouts() < 0) { - virEventUnlock(); - return -1; - } - - if (virEventCleanupHandles() < 0) { - virEventUnlock(); - return -1; - } + if (virEventCleanupTimeouts() < 0 || + virEventCleanupHandles() < 0) + goto error;
eventLoop.running = 0; virEventUnlock(); + VIR_FREE(fds); return 0; + +error: + virEventUnlock(); +error_unlocked: + VIR_FREE(fds); + return -1; }
Okay, looks fine ! Daniel -- Daniel Veillard | libxml Gnome XML XSLT toolkit http://xmlsoft.org/ daniel@veillard.com | Rpmfind RPM search engine http://rpmfind.net/ http://veillard.com/ | virtualization library http://libvirt.org/

This patch adds a new test case to validate the various wierd scenarios that can occur when adding/removing/updating watches & timers in the event loop. In particular it checks - Handling of watches marked as deleted before virEventRunOnce - Handling of watches marked as deleted during dispatch of poll() results - Correct interrupt of main thread if watches change during poll() sleep These are the 3 problems we've been hitting with all these issues. I've tested they all fail prior to this patch http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html and now all 3 pass Daniel diff -r d5dc15adcbea tests/.cvsignore --- a/tests/.cvsignore Fri May 08 11:58:19 2009 +0100 +++ b/tests/.cvsignore Fri May 08 15:51:11 2009 +0100 @@ -16,6 +16,7 @@ nodeinfotest statstest qparamtest seclabeltest +eventtest *.gcda *.gcno *.exe diff -r d5dc15adcbea tests/Makefile.am --- a/tests/Makefile.am Fri May 08 11:58:19 2009 +0100 +++ b/tests/Makefile.am Fri May 08 15:51:11 2009 +0100 @@ -125,6 +125,11 @@ if WITH_SECDRIVER_SELINUX TESTS += seclabeltest endif +if WITH_LIBVIRTD +noinst_PROGRAMS += eventtest +TESTS += eventtest +endif + TESTS += nodedevxml2xmltest path_add = $$abs_top_builddir/src$(PATH_SEPARATOR)$$abs_top_builddir/qemud @@ -226,4 +231,10 @@ qparamtest_SOURCES = \ qparamtest.c testutils.h testutils.c qparamtest_LDADD = $(LDADDS) +if WITH_LIBVIRTD +eventtest_SOURCES = \ + eventtest.c testutils.h testutils.c ../qemud/event.c +eventtest_LDADD = -lrt $(LDADDS) +endif + CLEANFILES = *.cov *.gcov .libs/*.gcda .libs/*.gcno *.gcno *.gcda diff -r d5dc15adcbea tests/eventtest.c --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/tests/eventtest.c Fri May 08 15:51:11 2009 +0100 @@ -0,0 +1,444 @@ +/* + * eventtest.c: Test the libvirtd event loop impl + * + * Copyright (C) 2009 Red Hat, Inc. + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + * + * Author: Daniel P. Berrange <berrange@redhat.com> + */ + +#include <config.h> + +#include <stdlib.h> +#include <signal.h> +#include <time.h> + +#include "testutils.h" +#include "internal.h" +#include "threads.h" +#include "logging.h" +#include "../qemud/event.h" + +#define NUM_FDS 5 +#define NUM_TIME 5 + +static struct handleInfo { + int pipeFD[2]; + int fired; + int watch; + int error; + int delete; +} handles[NUM_FDS]; + +static struct timerInfo { + int timeout; + int timer; + int fired; + int error; + int delete; +} timers[NUM_TIME]; + +enum { + EV_ERROR_NONE, + EV_ERROR_WATCH, + EV_ERROR_FD, + EV_ERROR_EVENT, + EV_ERROR_DATA, +}; + +static void +testPipeReader(int watch, int fd, int events, void *data) +{ + struct handleInfo *info = data; + char one; + + info->fired = 1; + + if (watch != info->watch) { + info->error = EV_ERROR_WATCH; + return; + } + + if (fd != info->pipeFD[0]) { + info->error = EV_ERROR_FD; + return; + } + + if (!(events & VIR_EVENT_HANDLE_READABLE)) { + info->error = EV_ERROR_EVENT; + return; + } + if (read(fd, &one, 1) != 1) { + info->error = EV_ERROR_DATA; + return; + } + info->error = EV_ERROR_NONE; + + if (info->delete != -1) + virEventRemoveHandleImpl(info->delete); +} + + +static void +testTimer(int timer, void *data) +{ + struct timerInfo *info = data; + + info->fired = 1; + + if (timer != info->timer) { + info->error = EV_ERROR_WATCH; + return; + } + + info->error = EV_ERROR_NONE; + + if (info->delete != -1) + virEventRemoveTimeoutImpl(info->delete); +} + +static pthread_mutex_t eventThreadMutex = PTHREAD_MUTEX_INITIALIZER; +static pthread_cond_t eventThreadRunCond = PTHREAD_COND_INITIALIZER; +static int eventThreadRunOnce = 0; +static pthread_cond_t eventThreadJobCond = PTHREAD_COND_INITIALIZER; +static int eventThreadJobDone = 0; + + +static void *eventThreadLoop(void *data ATTRIBUTE_UNUSED) { + while (1) { + pthread_mutex_lock(&eventThreadMutex); + while (!eventThreadRunOnce) { + pthread_cond_wait(&eventThreadRunCond, &eventThreadMutex); + } + eventThreadRunOnce = 0; + pthread_mutex_unlock(&eventThreadMutex); + + virEventRunOnce(); + + pthread_mutex_lock(&eventThreadMutex); + eventThreadJobDone = 1; + pthread_cond_signal(&eventThreadJobCond); + pthread_mutex_unlock(&eventThreadMutex); + } +} + + +static int +verifyFired(int handle, int timer) +{ + int handleFired = 0; + int timerFired = 0; + int i; + for (i = 0 ; i < NUM_FDS ; i++) { + if (handles[i].fired) { + if (i != handle) { + fprintf(stderr, "FAIL Handle %d fired, but expected %d\n", i, handle); + return EXIT_FAILURE; + } else { + if (handles[i].error != EV_ERROR_NONE) { + fprintf(stderr, "FAIL Handle %d fired, but had error %d\n", i, + handles[i].error); + return EXIT_FAILURE; + } + handleFired = 1; + } + } else { + if (i == handle) { + fprintf(stderr, "FAIL Handle %d should have fired, but didn't\n", handle); + return EXIT_FAILURE; + } + } + } + if (handleFired != 1 && handle != -1) { + fprintf(stderr, "FAIL Something wierd happened, expecting handle %d\n", handle); + return EXIT_FAILURE; + } + + + for (i = 0 ; i < NUM_TIME ; i++) { + if (timers[i].fired) { + if (i != timer) { + fprintf(stderr, "FAIL Timer %d fired, but expected %d\n", i, timer); + return EXIT_FAILURE; + } else { + if (timers[i].error != EV_ERROR_NONE) { + fprintf(stderr, "FAIL Timer %d fired, but had error %d\n", i, + timers[i].error); + return EXIT_FAILURE; + } + timerFired = 1; + } + } else { + if (i == timer) { + fprintf(stderr, "FAIL Timer %d should have fired, but didn't\n", timer); + return EXIT_FAILURE; + } + } + } + if (timerFired != 1 && timer != -1) { + fprintf(stderr, "FAIL Something wierd happened, expecting timer %d\n", timer); + return EXIT_FAILURE; + } + return EXIT_SUCCESS; +} + +static void +startJob(const char *msg, int *test) +{ + fprintf(stderr, "%2d: %s ", (*test)++, msg); + eventThreadRunOnce = 1; + eventThreadJobDone = 0; + pthread_cond_signal(&eventThreadRunCond); + pthread_mutex_unlock(&eventThreadMutex); + sched_yield(); + pthread_mutex_lock(&eventThreadMutex); +} + +static int +finishJob(int handle, int timer) +{ + struct timespec waitTime; + int rc; + clock_gettime(CLOCK_REALTIME, &waitTime); + waitTime.tv_sec += 5; + rc = 0; + while (!eventThreadJobDone && rc == 0) + rc = pthread_cond_timedwait(&eventThreadJobCond, &eventThreadMutex, &waitTime); + if (rc != 0) { + fprintf(stderr, "FAIL Timed out waiting for pipe event\n"); + return EXIT_FAILURE; + } + + if (verifyFired(handle, timer) != EXIT_SUCCESS) + return EXIT_FAILURE; + + fprintf(stderr, "OK\n"); + return EXIT_SUCCESS; +} + +static void +resetAll(void) +{ + int i; + for (i = 0 ; i < NUM_FDS ; i++) { + handles[i].fired = 0; + handles[i].error = EV_ERROR_NONE; + } + for (i = 0 ; i < NUM_TIME ; i++) { + timers[i].fired = 0; + timers[i].error = EV_ERROR_NONE; + } +} + +static int +mymain(int argc, char **argv) +{ + int ret = 0; + char *progname; + int i; + pthread_t eventThread; + char one = '1'; + int test = 1; + + progname = argv[0]; + + if (argc > 1) { + fprintf(stderr, "Usage: %s\n", progname); + return EXIT_FAILURE; + } + + for (i = 0 ; i < NUM_FDS ; i++) { + if (pipe(handles[i].pipeFD) < 0) { + fprintf(stderr, "Cannot create pipe: %d", errno); + return EXIT_FAILURE; + } + } + + if (virThreadInitialize() < 0) + return EXIT_FAILURE; + char *debugEnv = getenv("LIBVIRT_DEBUG"); + if (debugEnv && *debugEnv && *debugEnv != '0') { + if (STREQ(debugEnv, "2") || STREQ(debugEnv, "info")) + virLogSetDefaultPriority(VIR_LOG_INFO); + else if (STREQ(debugEnv, "3") || STREQ(debugEnv, "warning")) + virLogSetDefaultPriority(VIR_LOG_WARN); + else if (STREQ(debugEnv, "4") || STREQ(debugEnv, "error")) + virLogSetDefaultPriority(VIR_LOG_ERROR); + else + virLogSetDefaultPriority(VIR_LOG_DEBUG); + } + + virEventInit(); + + for (i = 0 ; i < NUM_FDS ; i++) { + handles[i].delete = -1; + handles[i].watch = + virEventAddHandleImpl(handles[i].pipeFD[0], + VIR_EVENT_HANDLE_READABLE, + testPipeReader, + &handles[i], NULL); + } + + for (i = 0 ; i < NUM_TIME ; i++) { + timers[i].delete = -1; + timers[i].timeout = -1; + timers[i].timer = + virEventAddTimeoutImpl(timers[i].timeout, + testTimer, + &timers[i], NULL); + } + + pthread_create(&eventThread, NULL, eventThreadLoop, NULL); + + pthread_mutex_lock(&eventThreadMutex); + + /* First time, is easy - just try triggering one of our + * registered handles */ + startJob("Simple write", &test); + ret = write(handles[1].pipeFD[1], &one, 1); + if (finishJob(1, -1) != EXIT_SUCCESS) + return EXIT_FAILURE; + + resetAll(); + + /* Now lets delete one before starting poll(), and + * try triggering another handle */ + virEventRemoveHandleImpl(handles[0].watch); + startJob("Deleted before poll", &test); + ret = write(handles[1].pipeFD[1], &one, 1); + if (finishJob(1, -1) != EXIT_SUCCESS) + return EXIT_FAILURE; + + resetAll(); + + /* Next lets delete *during* poll, which should interrupt + * the loop with no event showing */ + + /* NB: this case is subject to a bit of a race condition. + * We yield & sleep, and pray that the other thread gets + * scheduled before we run EventRemoveHandleImpl */ + startJob("Interrupted during poll", &test); + pthread_mutex_unlock(&eventThreadMutex); + sched_yield(); + usleep(100 * 1000); + pthread_mutex_lock(&eventThreadMutex); + virEventRemoveHandleImpl(handles[1].watch); + if (finishJob(-1, -1) != EXIT_SUCCESS) + return EXIT_FAILURE; + + resetAll(); + + /* Getting more fun, lets delete a later handle during dispatch */ + + /* NB: this case is subject to a bit of a race condition. + * Only 1 time in 3 does the 2nd write get triggered by + * before poll() exits for the first write(). We don't + * see a hard failure in other cases, so nothing to worry + * about */ + startJob("Deleted during dispatch", &test); + handles[2].delete = handles[3].watch; + ret = write(handles[2].pipeFD[1], &one, 1); + ret = write(handles[3].pipeFD[1], &one, 1); + if (finishJob(2, -1) != EXIT_SUCCESS) + return EXIT_FAILURE; + + resetAll(); + + /* Extreme fun, lets delete ourselves during dispatch */ + startJob("Deleted during dispatch", &test); + handles[2].delete = handles[2].watch; + ret = write(handles[2].pipeFD[1], &one, 1); + if (finishJob(2, -1) != EXIT_SUCCESS) + return EXIT_FAILURE; + + resetAll(); + + + + /* Run a timer on its own */ + virEventUpdateTimeoutImpl(timers[1].timer, 100); + startJob("Firing a timer", &test); + if (finishJob(-1, 1) != EXIT_SUCCESS) + return EXIT_FAILURE; + virEventUpdateTimeoutImpl(timers[1].timer, -1); + + resetAll(); + + /* Now lets delete one before starting poll(), and + * try triggering another timer */ + virEventUpdateTimeoutImpl(timers[1].timer, 100); + virEventRemoveTimeoutImpl(timers[0].timer); + startJob("Deleted before poll", &test); + if (finishJob(-1, 1) != EXIT_SUCCESS) + return EXIT_FAILURE; + virEventUpdateTimeoutImpl(timers[1].timer, -1); + + resetAll(); + + /* Next lets delete *during* poll, which should interrupt + * the loop with no event showing */ + + /* NB: this case is subject to a bit of a race condition. + * We yield & sleep, and pray that the other thread gets + * scheduled before we run EventRemoveTimeoutImpl */ + startJob("Interrupted during poll", &test); + pthread_mutex_unlock(&eventThreadMutex); + sched_yield(); + usleep(100 * 1000); + pthread_mutex_lock(&eventThreadMutex); + virEventRemoveTimeoutImpl(timers[1].timer); + if (finishJob(-1, -1) != EXIT_SUCCESS) + return EXIT_FAILURE; + + resetAll(); + + /* Getting more fun, lets delete a later timer during dispatch */ + + /* NB: this case is subject to a bit of a race condition. + * Only 1 time in 3 does the 2nd write get triggered by + * before poll() exits for the first write(). We don't + * see a hard failure in other cases, so nothing to worry + * about */ + virEventUpdateTimeoutImpl(timers[2].timer, 100); + virEventUpdateTimeoutImpl(timers[3].timer, 100); + startJob("Deleted during dispatch", &test); + timers[2].delete = timers[3].timer; + if (finishJob(-1, 2) != EXIT_SUCCESS) + return EXIT_FAILURE; + virEventUpdateTimeoutImpl(timers[2].timer, -1); + + resetAll(); + + /* Extreme fun, lets delete ourselves during dispatch */ + virEventUpdateTimeoutImpl(timers[2].timer, 100); + startJob("Deleted during dispatch", &test); + timers[2].delete = timers[2].timer; + if (finishJob(-1, 2) != EXIT_SUCCESS) + return EXIT_FAILURE; + + for (i = 0 ; i < NUM_FDS ; i++) + virEventRemoveHandleImpl(handles[i].watch); + for (i = 0 ; i < NUM_TIME ; i++) + virEventRemoveTimeoutImpl(timers[i].timer); + + + //pthread_kill(eventThread, SIGTERM); + + return EXIT_SUCCESS; +} + + +VIRT_TEST_MAIN(mymain) diff -r d5dc15adcbea tests/testutils.h --- a/tests/testutils.h Fri May 08 11:58:19 2009 +0100 +++ b/tests/testutils.h Fri May 08 15:51:11 2009 +0100 @@ -11,6 +11,8 @@ #ifndef __VIT_TEST_UTILS_H__ #define __VIT_TEST_UTILS_H__ +#include <stdio.h> + double virtTestCountAverage(double *items, int nitems); -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|

On Mon, May 11, 2009 at 12:25:08PM +0100, Daniel P. Berrange wrote:
This patch adds a new test case to validate the various wierd scenarios that can occur when adding/removing/updating watches & timers in the event loop. In particular it checks
- Handling of watches marked as deleted before virEventRunOnce - Handling of watches marked as deleted during dispatch of poll() results - Correct interrupt of main thread if watches change during poll() sleep
These are the 3 problems we've been hitting with all these issues. I've tested they all fail prior to this patch
http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html
and now all 3 pass
Okay, it would be great to have a slightly more generic framework for event tesing using for example scenarios files, but that's a good first step, ACK ! Daniel -- Daniel Veillard | libxml Gnome XML XSLT toolkit http://xmlsoft.org/ daniel@veillard.com | Rpmfind RPM search engine http://rpmfind.net/ http://veillard.com/ | virtualization library http://libvirt.org/

On Mon, 2009-05-11 at 12:11 +0100, Daniel P. Berrange wrote:
Back in March I attempted to fix the event loop handling of deleted file handles
http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html
but have merely succeeded in screwing it up in a different fun & exciting way. That patch fixed a case where there was a deleted file handle in the list at the time virEventRunOnce() starts. Which was nice. Not nice, though was that it then breaks the case where a file handle is deleted during the course of dispatching events afer poll(). Investigating this also identified that when we were marking a file handle as deleted, we were forgetting to run virEventInterrupt(), which meant that in some cases the main thread would not be woken up until the next event triggers. Not very critical, but at the same time, not good because it delays cleanup & release of resources.
This series of patches fixes the problems, and more importantly, adds a unit test which cover these nasty edge cases.
It's not obvious to me from your description, so for others, one of the problems these patches fix is where destroying one running guest can cause another to also be destroyed: https://bugzilla.redhat.com/499698 Cheers, Mark.

On Mon, May 11, 2009 at 12:47:38PM +0100, Mark McLoughlin wrote:
On Mon, 2009-05-11 at 12:11 +0100, Daniel P. Berrange wrote:
Back in March I attempted to fix the event loop handling of deleted file handles
http://www.redhat.com/archives/libvir-list/2009-March/msg00246.html
but have merely succeeded in screwing it up in a different fun & exciting way. That patch fixed a case where there was a deleted file handle in the list at the time virEventRunOnce() starts. Which was nice. Not nice, though was that it then breaks the case where a file handle is deleted during the course of dispatching events afer poll(). Investigating this also identified that when we were marking a file handle as deleted, we were forgetting to run virEventInterrupt(), which meant that in some cases the main thread would not be woken up until the next event triggers. Not very critical, but at the same time, not good because it delays cleanup & release of resources.
This series of patches fixes the problems, and more importantly, adds a unit test which cover these nasty edge cases.
It's not obvious to me from your description, so for others, one of the problems these patches fix is where destroying one running guest can cause another to also be destroyed:
NB That's just one symptom. The core problem is that you end up with an off-by-1 error when dispatching the callbacks. ie, instead of dispatching the nth callback, we dispatch the nth+1 callbck. There are lots of different things registering callbacks so effects are pretty unpredictable. Normally the callbacks for running guests don't align, but if you restart libvirtd while a set of guests are running, you end up with all the guest callbacks registered in series, so are quite likely to see this double destroy. Daniel -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|
participants (3)
-
Daniel P. Berrange
-
Daniel Veillard
-
Mark McLoughlin