sin/samba-mirror
1
0
Fork 0
mirror of https://github.com/samba-team/samba.git synced 2025-01-04 05:18:06 +03:00
Code

improve timing issue detections

Browse Source 
the original "Time jumped" messages are too coarse to interpret
exactly what was going wrong inside of CTDB.

This patch removes the original logs and adds two other logs that
differentiate between the time it took to work on an event and
the time it took to get the next event.

(This used to be ctdb commit fd8d54292f10b35bc4960d64cfa6843ce9aba225)
This commit is contained in:
Christian Ambach 2011-01-14 13:55:28 +01:00 committed by Ronnie Sahlberg
parent fcd98a7e59
commit ad56f321c8
6 changed files with 61 additions and 15 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

15
ctdb/lib/tevent/tevent.c
View File

@ -590,8 +590,6 @@ extern pid_t ctdbd_pid;
int tevent_common_loop_wait(struct tevent_context *ev,
const char *location)
{
static time_t t=0;
time_t new_t;
/*
* loop as long as we have events pending
@ -608,19 +606,6 @@ int tevent_common_loop_wait(struct tevent_context *ev,
ret, strerror(errno));
return ret;
}
if (getpid() == ctdbd_pid) {
new_t=time(NULL);
if (t != 0) {
if (t > new_t) {
tevent_debug(ev, TEVENT_DEBUG_FATAL, __location__ " ERROR Time skipped backward by %d seconds\n", (int)(t-new_t));
}
/* We assume here that we get at least one event every 3 seconds */
if (new_t > (t+3)) {
tevent_debug(ev, TEVENT_DEBUG_FATAL, __location__ " ERROR Time jumped forward by %d seconds\n", (int)(new_t-t));
}
}
t=new_t;
}
}
tevent_debug(ev, TEVENT_DEBUG_WARNING,

2
ctdb/lib/tevent/tevent_epoll.c
View File

@ -250,7 +250,9 @@ static int epoll_event_loop(struct epoll_event_context *epoll_ev, struct timeval
return 0;
}
tevent_before_wait(epoll_ev->ev);
ret = epoll_wait(epoll_ev->epoll_fd, events, MAXEVENTS, timeout);
tevent_after_wait(epoll_ev->ev);
if (ret == -1 && errno == EINTR && epoll_ev->ev->signal_events) {
if (tevent_common_check_signal(epoll_ev->ev)) {

2
ctdb/lib/tevent/tevent_select.c
View File

@ -157,7 +157,9 @@ static int select_event_loop_select(struct select_event_context *select_ev, stru
return 0;
}
tevent_before_wait(select_ev->ev);
selrtn = select(select_ev->maxfd+1, &r_fds, &w_fds, NULL, tvalp);
tevent_after_wait(select_ev->ev);
if (selrtn == -1 && errno == EINTR &&
select_ev->ev->signal_events) {

2
ctdb/lib/tevent/tevent_standard.c
View File

@ -261,7 +261,9 @@ static int epoll_event_loop(struct std_event_context *std_ev, struct timeval *tv
return 0;
}
tevent_before_wait(std_ev->ev);
ret = epoll_wait(std_ev->epoll_fd, events, MAXEVENTS, timeout);
tevent_after_wait(std_ev->ev);
if (ret == -1 && errno == EINTR && std_ev->ev->signal_events) {
if (tevent_common_check_signal(std_ev->ev)) {

51
ctdb/lib/tevent/tevent_util.c
View File

@ -88,3 +88,54 @@ int ev_set_blocking(int fd, bool set)
return fcntl( fd, F_SETFL, val);
#undef FLAG_TO_SET
}
static struct timeval tevent_before_wait_ts;
static struct timeval tevent_after_wait_ts;
/*
* measure the time difference between multiple arrivals
* to the point where we wait for new events to come in
*
* allows to measure how long it takes to work on a
* event
*/
void tevent_before_wait(struct event_context *ev) {
struct timeval diff;
struct timeval now = tevent_timeval_current();
if (!tevent_timeval_is_zero(&tevent_after_wait_ts)) {
diff = tevent_timeval_until(&tevent_after_wait_ts, &now);
if (diff.tv_sec > 3) {
tevent_debug(ev, TEVENT_DEBUG_FATAL, __location__
" Handling event took %d seconds!",
(int) diff.tv_sec);
}
}
tevent_before_wait_ts = tevent_timeval_current();
}
/*
* measure how long the select()/epoll() call took
*
* allows to measure how long we are waiting for new events
*/
void tevent_after_wait(struct event_context *ev) {
struct timeval diff;
struct timeval now = tevent_timeval_current();
if (!tevent_timeval_is_zero(&tevent_before_wait_ts)) {
diff = tevent_timeval_until(&tevent_before_wait_ts, &now);
if (diff.tv_sec > 3) {
tevent_debug(ev, TEVENT_DEBUG_FATAL, __location__
" No event for %d seconds!",
(int) diff.tv_sec);
}
}
tevent_after_wait_ts = tevent_timeval_current();
}

4
ctdb/lib/tevent/tevent_util.h
View File

@ -184,6 +184,10 @@ const char **ev_str_list_add(const char **list, const char *s);
int ev_set_blocking(int fd, bool set);
size_t ev_str_list_length(const char **list);
void tevent_before_wait(struct event_context *ev);
void tevent_after_wait(struct event_context *ev);
/* Defined here so we can build against older talloc versions that don't
* have this define yet. */
#ifndef TALLOC_FREE