summaryrefslogtreecommitdiff
path: root/lib/thread.c
diff options
context:
space:
mode:
Diffstat (limited to 'lib/thread.c')
-rw-r--r--lib/thread.c120
1 files changed, 107 insertions, 13 deletions
diff --git a/lib/thread.c b/lib/thread.c
index 77e34f48f3..90074b3d89 100644
--- a/lib/thread.c
+++ b/lib/thread.c
@@ -138,11 +138,12 @@ static void cpu_record_hash_free(void *a)
static void vty_out_cpu_thread_history(struct vty *vty,
struct cpu_thread_history *a)
{
- vty_out(vty, "%5zu %10zu.%03zu %9zu %8zu %9zu %8zu %9zu %9zu %9zu",
+ vty_out(vty,
+ "%5zu %10zu.%03zu %9zu %8zu %9zu %8zu %9zu %9zu %9zu %10zu",
a->total_active, a->cpu.total / 1000, a->cpu.total % 1000,
a->total_calls, (a->cpu.total / a->total_calls), a->cpu.max,
(a->real.total / a->total_calls), a->real.max,
- a->total_cpu_warn, a->total_wall_warn);
+ a->total_cpu_warn, a->total_wall_warn, a->total_starv_warn);
vty_out(vty, " %c%c%c%c%c %s\n",
a->types & (1 << THREAD_READ) ? 'R' : ' ',
a->types & (1 << THREAD_WRITE) ? 'W' : ' ',
@@ -168,6 +169,8 @@ static void cpu_record_hash_print(struct hash_bucket *bucket, void *args[])
atomic_load_explicit(&a->total_cpu_warn, memory_order_seq_cst);
copy.total_wall_warn =
atomic_load_explicit(&a->total_wall_warn, memory_order_seq_cst);
+ copy.total_starv_warn = atomic_load_explicit(&a->total_starv_warn,
+ memory_order_seq_cst);
copy.cpu.total =
atomic_load_explicit(&a->cpu.total, memory_order_seq_cst);
copy.cpu.max = atomic_load_explicit(&a->cpu.max, memory_order_seq_cst);
@@ -186,6 +189,7 @@ static void cpu_record_hash_print(struct hash_bucket *bucket, void *args[])
totals->total_calls += copy.total_calls;
totals->total_cpu_warn += copy.total_cpu_warn;
totals->total_wall_warn += copy.total_wall_warn;
+ totals->total_starv_warn += copy.total_starv_warn;
totals->real.total += copy.real.total;
if (totals->real.max < copy.real.max)
totals->real.max = copy.real.max;
@@ -231,7 +235,8 @@ static void cpu_record_print(struct vty *vty, uint8_t filter)
vty_out(vty,
"Active Runtime(ms) Invoked Avg uSec Max uSecs");
vty_out(vty, " Avg uSec Max uSecs");
- vty_out(vty, " CPU_Warn Wall_Warn Type Thread\n");
+ vty_out(vty,
+ " CPU_Warn Wall_Warn Starv_Warn Type Thread\n");
if (m->cpu_record->count)
hash_iterate(
@@ -493,6 +498,41 @@ DEFUN (clear_thread_cpu,
return CMD_SUCCESS;
}
+static void show_thread_timers_helper(struct vty *vty, struct thread_master *m)
+{
+ const char *name = m->name ? m->name : "main";
+ char underline[strlen(name) + 1];
+ struct thread *thread;
+
+ memset(underline, '-', sizeof(underline));
+ underline[sizeof(underline) - 1] = '\0';
+
+ vty_out(vty, "\nShowing timers for %s\n", name);
+ vty_out(vty, "-------------------%s\n", underline);
+
+ frr_each (thread_timer_list, &m->timer, thread) {
+ vty_out(vty, " %-50s%pTH\n", thread->hist->funcname, thread);
+ }
+}
+
+DEFPY_NOSH (show_thread_timers,
+ show_thread_timers_cmd,
+ "show thread timers",
+ SHOW_STR
+ "Thread information\n"
+ "Show all timers and how long they have in the system\n")
+{
+ struct listnode *node;
+ struct thread_master *m;
+
+ frr_with_mutex (&masters_mtx) {
+ for (ALL_LIST_ELEMENTS_RO(masters, node, m))
+ show_thread_timers_helper(vty, m);
+ }
+
+ return CMD_SUCCESS;
+}
+
void thread_cmd_init(void)
{
install_element(VIEW_NODE, &show_thread_cpu_cmd);
@@ -504,6 +544,8 @@ void thread_cmd_init(void)
install_element(CONFIG_NODE, &no_service_cputime_warning_cmd);
install_element(CONFIG_NODE, &service_walltime_warning_cmd);
install_element(CONFIG_NODE, &no_service_walltime_warning_cmd);
+
+ install_element(VIEW_NODE, &show_thread_timers_cmd);
}
/* CLI end ------------------------------------------------------------------ */
@@ -768,7 +810,7 @@ char *thread_timer_to_hhmmss(char *buf, int buf_size,
/* Get new thread. */
static struct thread *thread_get(struct thread_master *m, uint8_t type,
- int (*func)(struct thread *), void *arg,
+ void (*func)(struct thread *), void *arg,
const struct xref_threadsched *xref)
{
struct thread *thread = thread_list_pop(&m->unuse);
@@ -787,6 +829,7 @@ static struct thread *thread_get(struct thread_master *m, uint8_t type,
thread->arg = arg;
thread->yield = THREAD_YIELD_TIME_SLOT; /* default */
thread->ref = NULL;
+ thread->ignore_timer_late = false;
/*
* So if the passed in funcname is not what we have
@@ -924,7 +967,7 @@ done:
/* Add new read thread. */
void _thread_add_read_write(const struct xref_threadsched *xref,
struct thread_master *m,
- int (*func)(struct thread *), void *arg, int fd,
+ void (*func)(struct thread *), void *arg, int fd,
struct thread **t_ptr)
{
int dir = xref->thread_type;
@@ -1004,7 +1047,7 @@ void _thread_add_read_write(const struct xref_threadsched *xref,
static void _thread_add_timer_timeval(const struct xref_threadsched *xref,
struct thread_master *m,
- int (*func)(struct thread *), void *arg,
+ void (*func)(struct thread *), void *arg,
struct timeval *time_relative,
struct thread **t_ptr)
{
@@ -1046,12 +1089,18 @@ static void _thread_add_timer_timeval(const struct xref_threadsched *xref,
if (thread_timer_list_first(&m->timer) == thread)
AWAKEN(m);
}
+#define ONEYEAR2SEC (60 * 60 * 24 * 365)
+ if (time_relative->tv_sec > ONEYEAR2SEC)
+ flog_err(
+ EC_LIB_TIMER_TOO_LONG,
+ "Timer: %pTHD is created with an expiration that is greater than 1 year",
+ thread);
}
/* Add timer event thread. */
void _thread_add_timer(const struct xref_threadsched *xref,
- struct thread_master *m, int (*func)(struct thread *),
+ struct thread_master *m, void (*func)(struct thread *),
void *arg, long timer, struct thread **t_ptr)
{
struct timeval trel;
@@ -1067,8 +1116,8 @@ void _thread_add_timer(const struct xref_threadsched *xref,
/* Add timer event thread with "millisecond" resolution */
void _thread_add_timer_msec(const struct xref_threadsched *xref,
struct thread_master *m,
- int (*func)(struct thread *), void *arg, long timer,
- struct thread **t_ptr)
+ void (*func)(struct thread *), void *arg,
+ long timer, struct thread **t_ptr)
{
struct timeval trel;
@@ -1082,15 +1131,16 @@ void _thread_add_timer_msec(const struct xref_threadsched *xref,
/* Add timer event thread with "timeval" resolution */
void _thread_add_timer_tv(const struct xref_threadsched *xref,
- struct thread_master *m, int (*func)(struct thread *),
- void *arg, struct timeval *tv, struct thread **t_ptr)
+ struct thread_master *m,
+ void (*func)(struct thread *), void *arg,
+ struct timeval *tv, struct thread **t_ptr)
{
_thread_add_timer_timeval(xref, m, func, arg, tv, t_ptr);
}
/* Add simple event thread. */
void _thread_add_event(const struct xref_threadsched *xref,
- struct thread_master *m, int (*func)(struct thread *),
+ struct thread_master *m, void (*func)(struct thread *),
void *arg, int val, struct thread **t_ptr)
{
struct thread *thread = NULL;
@@ -1651,12 +1701,35 @@ static void thread_process_io(struct thread_master *m, unsigned int num)
static unsigned int thread_process_timers(struct thread_master *m,
struct timeval *timenow)
{
+ struct timeval prev = *timenow;
+ bool displayed = false;
struct thread *thread;
unsigned int ready = 0;
while ((thread = thread_timer_list_first(&m->timer))) {
if (timercmp(timenow, &thread->u.sands, <))
break;
+ prev = thread->u.sands;
+ prev.tv_sec += 4;
+ /*
+ * If the timer would have popped 4 seconds in the
+ * past then we are in a situation where we are
+ * really getting behind on handling of events.
+ * Let's log it and do the right thing with it.
+ */
+ if (timercmp(timenow, &prev, >)) {
+ atomic_fetch_add_explicit(
+ &thread->hist->total_starv_warn, 1,
+ memory_order_seq_cst);
+ if (!displayed && !thread->ignore_timer_late) {
+ flog_warn(
+ EC_LIB_STARVE_THREAD,
+ "Thread Starvation: %pTHD was scheduled to pop greater than 4s ago",
+ thread);
+ displayed = true;
+ }
+ }
+
thread_timer_list_pop(&m->timer);
thread->type = THREAD_READY;
thread_list_add_tail(&m->ready, thread);
@@ -1811,6 +1884,27 @@ unsigned long thread_consumed_time(RUSAGE_T *now, RUSAGE_T *start,
unsigned long *cputime)
{
#ifdef HAVE_CLOCK_THREAD_CPUTIME_ID
+
+#ifdef __FreeBSD__
+ /*
+ * FreeBSD appears to have an issue when calling clock_gettime
+ * with CLOCK_THREAD_CPUTIME_ID really close to each other
+ * occassionally the now time will be before the start time.
+ * This is not good and FRR is ending up with CPU HOG's
+ * when the subtraction wraps to very large numbers
+ *
+ * What we are going to do here is cheat a little bit
+ * and notice that this is a problem and just correct
+ * it so that it is impossible to happen
+ */
+ if (start->cpu.tv_sec == now->cpu.tv_sec &&
+ start->cpu.tv_nsec > now->cpu.tv_nsec)
+ now->cpu.tv_nsec = start->cpu.tv_nsec + 1;
+ else if (start->cpu.tv_sec > now->cpu.tv_sec) {
+ now->cpu.tv_sec = start->cpu.tv_sec;
+ now->cpu.tv_nsec = start->cpu.tv_nsec + 1;
+ }
+#endif
*cputime = (now->cpu.tv_sec - start->cpu.tv_sec) * TIMER_SECOND_MICRO
+ (now->cpu.tv_nsec - start->cpu.tv_nsec) / 1000;
#else
@@ -1979,7 +2073,7 @@ void thread_call(struct thread *thread)
/* Execute thread */
void _thread_execute(const struct xref_threadsched *xref,
- struct thread_master *m, int (*func)(struct thread *),
+ struct thread_master *m, void (*func)(struct thread *),
void *arg, int val)
{
struct thread *thread;
generated by cgit v1.2.3 (git 2.39.1) at 2025-12-12 22:21:48 +0000