2005-04-16 Andrew J. Schorr <ajschorr@alumni.princeton.edu>

* 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.
This commit is contained in:
ajs 2005-04-16 17:11:24 +00:00
parent dc830cbfac
commit 924b922971
6 changed files with 66 additions and 9 deletions

View File

@ -1,3 +1,10 @@
2005-04-16 Andrew J. Schorr <ajschorr@alumni.princeton.edu>
* 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 <paul.jakma@sun.com>
* configure.ac: check for gawk, needed to build memtypes.h

View File

@ -5,7 +5,7 @@
## Copyright (c) 1996, 97, 98, 99, 2000 Kunihiro Ishiguro <kunihiro@zebra.org>
## Portions Copyright (c) 2003 Paul Jakma <paul@dishone.st>
##
## $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

View File

@ -1,3 +1,18 @@
2005-04-16 Andrew J. Schorr <ajschorr@alumni.princeton.edu>
* 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 <paul@dishone.st>
* memtypes.c: the comment about use of comments in the comments

View File

@ -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 */

View File

@ -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 */

View File

@ -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)
{