TEVENT: Add back tracking of long runnig events to the local copy of tevent library

(This used to be ctdb commit 5aba53e6adcfcd7edbdac9e30aa5fcba176aca00)

5 files changed, 66 insertions, 0 deletions

diff --git a/ctdb/lib/tevent/tevent_epoll.c b/ctdb/lib/tevent/tevent_epoll.c
index f5a69ddc50c..7c09dd7449c 100644
--- a/ctdb/lib/tevent/tevent_epoll.c
+++ b/ctdb/lib/tevent/tevent_epoll.c
@@ -242,6 +242,8 @@ static void epoll_change_event(struct epoll_event_context *epoll_ev, struct teve
 	}
 }
 
+extern pid_t ctdbd_pid;
+
 /*
   event loop handling using epoll
 */
@@ -264,7 +266,9 @@ static int epoll_event_loop(struct epoll_event_context *epoll_ev, struct timeval
 		return 0;
 	}
 
+	if (getpid() == ctdbd_pid) tevent_before_wait(epoll_ev->ev);
 	ret = epoll_wait(epoll_ev->epoll_fd, events, MAXEVENTS, timeout);
+	if (getpid() == ctdbd_pid) tevent_after_wait(epoll_ev->ev);
 
 	if (ret == -1 && errno == EINTR && epoll_ev->ev->signal_events) {
 		if (tevent_common_check_signal(epoll_ev->ev)) {
diff --git a/ctdb/lib/tevent/tevent_internal.h b/ctdb/lib/tevent/tevent_internal.h
index 7f1d8766ca9..707bfab0540 100644
--- a/ctdb/lib/tevent/tevent_internal.h
+++ b/ctdb/lib/tevent/tevent_internal.h
@@ -313,3 +313,5 @@ bool tevent_poll_init(void);
 #ifdef HAVE_EPOLL
 bool tevent_epoll_init(void);
 #endif
+void tevent_before_wait(struct tevent_context *ev);
+void tevent_after_wait(struct tevent_context *ev);
diff --git a/ctdb/lib/tevent/tevent_select.c b/ctdb/lib/tevent/tevent_select.c
index 51c1dec4a6f..6fa38cebc04 100644
--- a/ctdb/lib/tevent/tevent_select.c
+++ b/ctdb/lib/tevent/tevent_select.c
@@ -130,6 +130,8 @@ static struct tevent_fd *select_event_add_fd(struct tevent_context *ev, TALLOC_C
 	return fde;
 }
 
+extern pid_t ctdbd_pid;
+
 /*
   event loop handling using select()
 */
@@ -167,7 +169,9 @@ static int select_event_loop_select(struct select_event_context *select_ev, stru
 		return 0;
 	}
 
+	if (getpid() == ctdbd_pid) tevent_before_wait(select_ev->ev);
 	selrtn = select(select_ev->maxfd+1, &r_fds, &w_fds, NULL, tvalp);
+	if (getpid() == ctdbd_pid) tevent_after_wait(select_ev->ev);
 
 	if (selrtn == -1 && errno == EINTR &&
 	    select_ev->ev->signal_events) {
diff --git a/ctdb/lib/tevent/tevent_standard.c b/ctdb/lib/tevent/tevent_standard.c
index 534576c108d..4041b6a9037 100644
--- a/ctdb/lib/tevent/tevent_standard.c
+++ b/ctdb/lib/tevent/tevent_standard.c
@@ -256,6 +256,8 @@ static void epoll_change_event(struct std_event_context *std_ev, struct tevent_f
 	}
 }
 
+extern pid_t ctdbd_pid;
+
 /*
   event loop handling using epoll
 */
@@ -278,7 +280,9 @@ static int epoll_event_loop(struct std_event_context *std_ev, struct timeval *tv
 		return 0;
 	}
 
+	if (getpid() == ctdbd_pid) tevent_before_wait(std_ev->ev);
 	ret = epoll_wait(std_ev->epoll_fd, events, MAXEVENTS, timeout);
+	if (getpid() == ctdbd_pid) tevent_after_wait(std_ev->ev);
 
 	if (ret == -1 && errno == EINTR && std_ev->ev->signal_events) {
 		if (tevent_common_check_signal(std_ev->ev)) {
diff --git a/ctdb/lib/tevent/tevent_util.c b/ctdb/lib/tevent/tevent_util.c
index 16af8f3b908..e3a1605b263 100644
--- a/ctdb/lib/tevent/tevent_util.c
+++ b/ctdb/lib/tevent/tevent_util.c
@@ -105,3 +105,55 @@ bool ev_set_close_on_exec(int fd)
 #endif
 	return false;
 }
+
+
+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 tevent_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_ERROR,  __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 tevent_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();
+
+}