libevent/test/test-changelist.c

200 lines
4.3 KiB
C
Raw Normal View History

Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
/*
* based on test-eof.c
*/
#include "event-config.h"
#ifdef WIN32
#include <winsock2.h>
#include <windows.h>
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
#else
#include <unistd.h>
#endif
#include <sys/types.h>
#include <sys/stat.h>
#ifdef _EVENT_HAVE_SYS_TIME_H
#include <sys/time.h>
#endif
#ifdef _EVENT_HAVE_SYS_SOCKET_H
#include <sys/socket.h>
#endif
#include <fcntl.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include <errno.h>
#include <event2/event.h>
#include <event2/util.h>
#include <time.h>
struct cpu_usage_timer {
#ifdef WIN32
HANDLE thread;
FILETIME usertimeBegin;
FILETIME kerneltimeBegin;
#else
clock_t ticksBegin;
#endif
struct timeval timeBegin;
};
static void
start_cpu_usage_timer(struct cpu_usage_timer *timer)
{
#ifdef WIN32
int r;
FILETIME createtime, exittime;
timer->thread = GetCurrentThread();
r = GetThreadTimes(timer->thread, &createtime, &exittime,
&timer->usertimeBegin, &timer->kerneltimeBegin);
if (r==0) printf("GetThreadTimes failed.");
#else
timer->ticksBegin = clock();
#endif
evutil_gettimeofday(&timer->timeBegin, NULL);
}
#ifdef WIN32
static ev_int64_t
filetime_to_100nsec(const FILETIME *ft)
{
/* Number of 100-nanosecond units */
ev_int64_t n = ft->dwHighDateTime;
n <<= 32;
n += ft->dwLowDateTime;
return n;
}
static double
filetime_diff(const FILETIME *ftStart, const FILETIME *ftEnd)
{
ev_int64_t s, e, diff;
double r;
s = filetime_to_100nsec(ftStart);
e = filetime_to_100nsec(ftEnd);
diff = e - s;
r = (double) diff;
return r / 1.0e7;
}
#endif
static void
get_cpu_usage(struct cpu_usage_timer *timer, double *secElapsedOut,
double *secUsedOut, double *usageOut)
{
#ifdef WIN32
double usertime_seconds, kerneltime_seconds;
FILETIME createtime, exittime, usertimeEnd, kerneltimeEnd;
int r;
#else
clock_t ticksEnd;
#endif
struct timeval timeEnd, timeDiff;
double secondsPassed, secondsUsed;
#ifdef WIN32
r = GetThreadTimes(timer->thread, &createtime, &exittime,
&usertimeEnd, &kerneltimeEnd);
if (r==0) printf("GetThreadTimes failed.");
usertime_seconds = filetime_diff(&timer->usertimeBegin, &usertimeEnd);
kerneltime_seconds = filetime_diff(&timer->kerneltimeBegin, &kerneltimeEnd);
secondsUsed = kerneltime_seconds + usertime_seconds;
#else
ticksEnd = clock();
secondsUsed = (ticksEnd - timer->ticksBegin) / (double)CLOCKS_PER_SEC;
#endif
evutil_gettimeofday(&timeEnd, NULL);
evutil_timersub(&timeEnd, &timer->timeBegin, &timeDiff);
secondsPassed = timeDiff.tv_sec + (timeDiff.tv_usec / 1.0e6);
*secElapsedOut = secondsPassed;
*secUsedOut = secondsUsed;
*usageOut = secondsUsed / secondsPassed;
}
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
static void
write_cb(evutil_socket_t fd, short event, void *arg)
2010-07-19 15:03:43 +02:00
{
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
printf("write callback. should only see this once\n");
2010-07-19 15:03:43 +02:00
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
/* got what we want remove the event */
event_del(*(struct event**)arg);
/* opps changed my mind add it back again */
event_add(*(struct event**)arg,NULL);
/* not a good day for decisiveness, I really didn't want it after all */
event_del(*(struct event**)arg);
}
static void
timeout_cb(evutil_socket_t fd, short event, void *arg)
2010-07-19 15:03:43 +02:00
{
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
printf("timeout fired, time to end test\n");
event_del(*(struct event**)arg);
return;
}
int
main(int argc, char **argv)
{
struct event* ev;
struct event* timeout;
struct event_base* base;
int pair[2];
int res;
struct timeval tv;
struct cpu_usage_timer timer;
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
double usage, secPassed, secUsed;
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
#ifdef WIN32
WORD wVersionRequested;
WSADATA wsaData;
int err;
wVersionRequested = MAKEWORD(2, 2);
err = WSAStartup(wVersionRequested, &wsaData);
#endif
if (evutil_socketpair(AF_UNIX, SOCK_STREAM, 0, pair) == -1)
return (1);
/* Initalize the event library */
base = event_base_new();
/* Initalize a timeout to terminate the test */
timeout = evtimer_new(base,timeout_cb,&timeout);
/* and watch for writability on one end of the pipe */
ev = event_new(base,pair[1],EV_WRITE | EV_PERSIST, write_cb, &ev);
tv.tv_sec = 5;
tv.tv_usec = 0;
evtimer_add(timeout, &tv);
event_add(ev, NULL);
start_cpu_usage_timer(&timer);
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
res = event_base_dispatch(base);
get_cpu_usage(&timer, &secPassed, &secUsed, &usage);
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
/* attempt to calculate our cpu usage over the test should be
virtually nil */
2010-07-19 15:03:43 +02:00
printf("usec used=%d, usec passed=%d, cpu usage=%.2f%%\n",
(int)(secUsed*1e6),
(int)(secPassed*1e6),
usage*100);
Possible fix to 100% cpu usage with epoll and openssl I'm running a fairly simple bit of test code using libevent2 with epoll and openssl bufferevents and I've run into a 100% cpu usage problem. Looking into it 100% usage was caused by epoll_wait constantly returning write events on the openssl socket when it shouldn't really have been looking for write events at all (N_ACTIVE_CALLBACKS() was returning 0 also). Looking a bit deeper eventbuffer_openssl socket seems to be requesting that the EV_WRITE event be removed when it should, but the event isn't actually being removed from epoll. Continuing to follow this I think I've found a bug in event_changelist_del. For evpoll event_del calls event_changelist_del which caches the change which is then actioned later when evpoll_dispatch is called. In event_changlist_del there is a check so that if the currently changed action is an add then the cached action is changed to a no-op rather than a delete (which makes sense). The problem arises if there are more than two add or delete operations between calls to dispatch, in this case it's possible that the delete is turned into a no-op when it shouldn't have been. For example starting with the event on, a delete followed by an add and then another delete results in a no-op when it should have been a delete (I added a fair bit of debug output that seems to confirm this behaviour). I've applied a small change that checks the original old_event stored with the change and only converts the delete to a no-op if the event isn't on in old_event. This seems to have fixed my problem.
2010-07-19 13:44:56 +12:00
if (usage > 50.0) /* way too high */
return 1;
return 0;
}