From 924b9229717b749e303f3fb161616bebf53b5cdc Mon Sep 17 00:00:00 2001 From: ajs Date: Sat, 16 Apr 2005 17:11:24 +0000 Subject: 2005-04-16 Andrew J. Schorr * configure.ac: Added AC_ARG_ENABLE(time-check). By default, warning messages will now be printed for threads or commands that take longer than 5 seconds, but this configure argument can be used to disable the checks or change the threshold. * thread.h (thread_consumed_time): Declare new function to calculate elapsed microseconds. * thread.c (thread_consumed_time): Must be global not static so we can call it from lib/vty.c:vty_command. (thread_should_yield): Surround with `#if 0' to make clear that this function is not currently being used anywhere. (thread_call): If CONSUMED_TIME_CHECK is defined, print a CPU HOG warning message if the thread takes more than CONSUMED_TIME_CHECK microseconds. * vty.c (vty_command): If CONSUMED_TIME_CHECK is defined, print a CPU HOG warning message if the command takes more than CONSUMED_TIME_CHECK microseconds. --- ChangeLog | 7 +++++++ configure.ac | 12 +++++++++++- lib/ChangeLog | 15 +++++++++++++++ lib/thread.c | 22 ++++++++++++++-------- lib/thread.h | 2 ++ lib/vty.c | 17 +++++++++++++++++ 6 files changed, 66 insertions(+), 9 deletions(-) diff --git a/ChangeLog b/ChangeLog index 0b10293b..7966cc47 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,10 @@ +2005-04-16 Andrew J. Schorr + + * configure.ac: Added AC_ARG_ENABLE(time-check). By default, + warning messages will now be printed for threads or commands that take + longer than 5 seconds, but this configure argument can be used + to disable the checks or change the threshold. + 2005-04-16 Paul Jakma * configure.ac: check for gawk, needed to build memtypes.h diff --git a/configure.ac b/configure.ac index 08b5214f..cbc95212 100755 --- a/configure.ac +++ b/configure.ac @@ -5,7 +5,7 @@ ## Copyright (c) 1996, 97, 98, 99, 2000 Kunihiro Ishiguro ## Portions Copyright (c) 2003 Paul Jakma ## -## $Id: configure.ac,v 1.103 2005/04/16 15:38:23 paul Exp $ +## $Id: configure.ac,v 1.104 2005/04/16 17:11:24 ajs Exp $ AC_PREREQ(2.53) AC_INIT(Quagga, 0.99.0, [http://bugzilla.quagga.net]) @@ -195,6 +195,8 @@ AC_ARG_ENABLE(gcc_ultra_verbose, [ --enable-gcc-ultra-verbose enable ultra verbose GCC warnings]) AC_ARG_ENABLE(gcc-rdynamic, [ --enable-gcc-rdynamic enable gcc linking with -rdynamic for better backtraces]) +AC_ARG_ENABLE(time-check, +[ --disable-time-check disable slow thread warning messages]) if test x"${enable_gcc_ultra_verbose}" = x"yes" ; then CFLAGS="${CFLAGS} -W -Wcast-qual -Wstrict-prototypes" @@ -207,6 +209,14 @@ if test x"${enable_gcc_rdynamic}" = x"yes" ; then LDFLAGS="${LDFLAGS} -rdynamic" fi +if test x"${enable_time_check}" != x"no" ; then + if test x"${enable_time_check}" = x"yes" -o x"${enable_time_check}" = x ; then + AC_DEFINE(CONSUMED_TIME_CHECK,5000000,Consumed Time Check) + else + AC_DEFINE_UNQUOTED(CONSUMED_TIME_CHECK,$enable_time_check,Consumed Time Check) + fi +fi + if test "${enable_broken_aliases}" = "yes"; then if test "${enable_netlink}" = "yes" then diff --git a/lib/ChangeLog b/lib/ChangeLog index e5ee5494..d8328499 100644 --- a/lib/ChangeLog +++ b/lib/ChangeLog @@ -1,3 +1,18 @@ +2005-04-16 Andrew J. Schorr + + * thread.h (thread_consumed_time): Declare new function to calculate + elapsed microseconds. + * thread.c (thread_consumed_time): Must be global not static so we + can call it from lib/vty.c:vty_command. + (thread_should_yield): Surround with `#if 0' to make clear that this + function is not currently being used anywhere. + (thread_call): If CONSUMED_TIME_CHECK is defined, print a CPU HOG + warning message if the thread takes more than CONSUMED_TIME_CHECK + microseconds. + * vty.c (vty_command): If CONSUMED_TIME_CHECK is defined, print a CPU + HOG warning message if the command takes more than CONSUMED_TIME_CHECK + microseconds. + 2005-04-16 Paul Jakma * memtypes.c: the comment about use of comments in the comments diff --git a/lib/thread.c b/lib/thread.c index 05212d85..d1c925c4 100644 --- a/lib/thread.c +++ b/lib/thread.c @@ -804,7 +804,7 @@ thread_fetch (struct thread_master *m, struct thread *fetch) } } -static unsigned long +unsigned long thread_consumed_time (RUSAGE_T *now, RUSAGE_T *start) { unsigned long thread_time; @@ -821,6 +821,10 @@ thread_consumed_time (RUSAGE_T *now, RUSAGE_T *start) return thread_time; } +#if 0 + +/* This function is not currently used: threads never yield! */ + /* We should aim to yield after THREAD_YIELD_TIME_SLOT milliseconds. */ int @@ -836,6 +840,8 @@ thread_should_yield (struct thread *thread) return 0; } +#endif + /* We check thread consumed time. If the system has getrusage, we'll use that to get indepth stats on the performance of the thread. If not - we'll use gettimeofday for some guestimation. */ @@ -864,20 +870,20 @@ thread_call (struct thread *thread) ++cpu->total_calls; cpu->types |= (1 << thread->add_type); -#ifdef THREAD_CONSUMED_TIME_CHECK - if (thread_time > 200000L) +#ifdef CONSUMED_TIME_CHECK + if (thread_time > CONSUMED_TIME_CHECK) { /* * We have a CPU Hog on our hands. * Whinge about it now, so we're aware this is yet another task * to fix. */ - zlog_err ("CPU HOG task %s (%lx) ran for %ldms", - thread->funcname, - (unsigned long) thread->func, - thread_time / 1000L); + zlog_warn ("CPU HOG: task %s (%lx) ran for %ldms", + thread->funcname, + (unsigned long) thread->func, + thread_time / 1000L); } -#endif /* THREAD_CONSUMED_TIME_CHECK */ +#endif /* CONSUMED_TIME_CHECK */ } /* Execute thread */ diff --git a/lib/thread.h b/lib/thread.h index 716a6a6c..4008ba72 100644 --- a/lib/thread.h +++ b/lib/thread.h @@ -158,4 +158,6 @@ unsigned long thread_timer_remain_second (struct thread *); extern struct cmd_element show_thread_cpu_cmd; +extern unsigned long thread_consumed_time(RUSAGE_T *after, RUSAGE_T *before); + #endif /* _ZEBRA_THREAD_H */ diff --git a/lib/vty.c b/lib/vty.c index 600c9fd8..ea74172c 100644 --- a/lib/vty.c +++ b/lib/vty.c @@ -395,8 +395,25 @@ vty_command (struct vty *vty, char *buf) if (vline == NULL) return CMD_SUCCESS; +#ifdef CONSUMED_TIME_CHECK + { + RUSAGE_T before; + RUSAGE_T after; + unsigned long cmdtime; + + GETRUSAGE(&before); +#endif /* CONSUMED_TIME_CHECK */ + ret = cmd_execute_command (vline, vty, NULL, 0); +#ifdef CONSUMED_TIME_CHECK + GETRUSAGE(&after); + if ((cmdtime = thread_consumed_time(&after, &before)) > CONSUMED_TIME_CHECK) + /* Warn about CPU hog that must be fixed. */ + zlog_warn("CPU HOG: command took %lums: %s", cmdtime/1000, buf); + } +#endif /* CONSUMED_TIME_CHECK */ + if (ret != CMD_SUCCESS) switch (ret) { -- cgit v1.2.1