From 6ed0b9885d246b8035e9cdd7f59a0d37152988ae Mon Sep 17 00:00:00 2001 From: Willy Tarreau Date: Wed, 3 May 2023 15:52:19 +0200 Subject: [PATCH] MINOR: activity: allow "show activity" to restart dumping on any line When using many threads, it's difficult to see the end of "show activity" due to the numerous columns which fill the buffer. For example a dump of a 256-thread, freshly booted process yields around 15kB. Here by arranging the dump in a loop around a switch/case block where each case checks the code line number against the current dump position, we have a restartable counter for free with a granularity of the line of code, without having to maintain a matching between states and specific lines. It just requires to reset the trash buffer for each line and to try to dump it after each line. Now dumping 256 threads after a few seconds of traffic happily emits 20kB. --- src/activity.c | 92 ++++++++++++++++++++++++++++---------------------- 1 file changed, 52 insertions(+), 40 deletions(-) diff --git a/src/activity.c b/src/activity.c index 52c9a4513..63decfe7d 100644 --- a/src/activity.c +++ b/src/activity.c @@ -35,6 +35,7 @@ struct show_prof_ctx { /* CLI context for the "show activity" command */ struct show_activity_ctx { int thr; /* thread ID to show or -1 for all */ + int line; /* line number being dumped */ }; #if defined(DEBUG_MEM_STATS) @@ -1027,14 +1028,13 @@ static int cli_io_handler_show_activity(struct appctx *appctx) struct show_activity_ctx *actctx = appctx->svcctx; int tgt = actctx->thr; // target thread, -1 for all, 0 for total only uint up_sec, up_usec; + int base_line; ullong up; /* FIXME: Don't watch the other side ! */ if (unlikely(sc_opposite(sc)->flags & SC_FL_SHUT_DONE)) return 1; - chunk_reset(&trash); - /* this macro is used below to dump values. The thread number is "thr", * and runs from 0 to nbt-1 when values are printed using the formula. */ @@ -1081,51 +1081,63 @@ static int cli_io_handler_show_activity(struct appctx *appctx) up_sec = ns_to_sec(up); up_usec = (up / 1000U) % 1000000U; - chunk_appendf(&trash, "thread_id: %u (%u..%u)\n", tid + 1, 1, global.nbthread); - chunk_appendf(&trash, "date_now: %lu.%06lu\n", (ulong)date.tv_sec, (ulong)date.tv_usec); - chunk_appendf(&trash, "uptime_now: %u.%06u\n", up_sec, up_usec); + /* iterate over all dump lines. It happily skips over holes so it's + * not a problem not to have an exact match, we just need to have + * stable and consistent lines during a dump. + */ + base_line = __LINE__; + do { + chunk_reset(&trash); - SHOW_VAL("ctxsw:", activity[thr].ctxsw, _tot); - SHOW_VAL("tasksw:", activity[thr].tasksw, _tot); - SHOW_VAL("empty_rq:", activity[thr].empty_rq, _tot); - SHOW_VAL("long_rq:", activity[thr].long_rq, _tot); - SHOW_VAL("loops:", activity[thr].loops, _tot); - SHOW_VAL("wake_tasks:", activity[thr].wake_tasks, _tot); - SHOW_VAL("wake_signal:", activity[thr].wake_signal, _tot); - SHOW_VAL("poll_io:", activity[thr].poll_io, _tot); - SHOW_VAL("poll_exp:", activity[thr].poll_exp, _tot); - SHOW_VAL("poll_drop_fd:", activity[thr].poll_drop_fd, _tot); - SHOW_VAL("poll_skip_fd:", activity[thr].poll_skip_fd, _tot); - SHOW_VAL("conn_dead:", activity[thr].conn_dead, _tot); - SHOW_VAL("stream_calls:", activity[thr].stream_calls, _tot); - SHOW_VAL("pool_fail:", activity[thr].pool_fail, _tot); - SHOW_VAL("buf_wait:", activity[thr].buf_wait, _tot); - SHOW_VAL("cpust_ms_tot:", activity[thr].cpust_total / 2, _tot); - SHOW_VAL("cpust_ms_1s:", read_freq_ctr(&activity[thr].cpust_1s) / 2, _tot); - SHOW_VAL("cpust_ms_15s:", read_freq_ctr_period(&activity[thr].cpust_15s, 15000) / 2, _tot); - SHOW_VAL("avg_cpu_pct:", (100 - ha_thread_ctx[thr].idle_pct), (_tot + _nbt/2) / _nbt); - SHOW_VAL("avg_loop_us:", swrate_avg(activity[thr].avg_loop_us, TIME_STATS_SAMPLES), (_tot + _nbt/2) / _nbt); - SHOW_VAL("accepted:", activity[thr].accepted, _tot); - SHOW_VAL("accq_pushed:", activity[thr].accq_pushed, _tot); - SHOW_VAL("accq_full:", activity[thr].accq_full, _tot); + switch (actctx->line + base_line) { + case __LINE__: chunk_appendf(&trash, "thread_id: %u (%u..%u)\n", tid + 1, 1, global.nbthread); break; + case __LINE__: chunk_appendf(&trash, "date_now: %lu.%06lu\n", (ulong)date.tv_sec, (ulong)date.tv_usec); break; + case __LINE__: chunk_appendf(&trash, "uptime_now: %u.%06u\n", up_sec, up_usec); break; + case __LINE__: SHOW_VAL("ctxsw:", activity[thr].ctxsw, _tot); break; + case __LINE__: SHOW_VAL("tasksw:", activity[thr].tasksw, _tot); break; + case __LINE__: SHOW_VAL("empty_rq:", activity[thr].empty_rq, _tot); break; + case __LINE__: SHOW_VAL("long_rq:", activity[thr].long_rq, _tot); break; + case __LINE__: SHOW_VAL("loops:", activity[thr].loops, _tot); break; + case __LINE__: SHOW_VAL("wake_tasks:", activity[thr].wake_tasks, _tot); break; + case __LINE__: SHOW_VAL("wake_signal:", activity[thr].wake_signal, _tot); break; + case __LINE__: SHOW_VAL("poll_io:", activity[thr].poll_io, _tot); break; + case __LINE__: SHOW_VAL("poll_exp:", activity[thr].poll_exp, _tot); break; + case __LINE__: SHOW_VAL("poll_drop_fd:", activity[thr].poll_drop_fd, _tot); break; + case __LINE__: SHOW_VAL("poll_skip_fd:", activity[thr].poll_skip_fd, _tot); break; + case __LINE__: SHOW_VAL("conn_dead:", activity[thr].conn_dead, _tot); break; + case __LINE__: SHOW_VAL("stream_calls:", activity[thr].stream_calls, _tot); break; + case __LINE__: SHOW_VAL("pool_fail:", activity[thr].pool_fail, _tot); break; + case __LINE__: SHOW_VAL("buf_wait:", activity[thr].buf_wait, _tot); break; + case __LINE__: SHOW_VAL("cpust_ms_tot:", activity[thr].cpust_total / 2, _tot); break; + case __LINE__: SHOW_VAL("cpust_ms_1s:", read_freq_ctr(&activity[thr].cpust_1s) / 2, _tot); break; + case __LINE__: SHOW_VAL("cpust_ms_15s:", read_freq_ctr_period(&activity[thr].cpust_15s, 15000) / 2, _tot); break; + case __LINE__: SHOW_VAL("avg_cpu_pct:", (100 - ha_thread_ctx[thr].idle_pct), (_tot + _nbt/2) / _nbt); break; + case __LINE__: SHOW_VAL("avg_loop_us:", swrate_avg(activity[thr].avg_loop_us, TIME_STATS_SAMPLES), (_tot + _nbt/2) / _nbt); break; + case __LINE__: SHOW_VAL("accepted:", activity[thr].accepted, _tot); break; + case __LINE__: SHOW_VAL("accq_pushed:", activity[thr].accq_pushed, _tot); break; + case __LINE__: SHOW_VAL("accq_full:", activity[thr].accq_full, _tot); break; #ifdef USE_THREAD - SHOW_VAL("accq_ring:", accept_queue_ring_len(&accept_queue_rings[thr]), _tot); - SHOW_VAL("fd_takeover:", activity[thr].fd_takeover, _tot); + case __LINE__: SHOW_VAL("accq_ring:", accept_queue_ring_len(&accept_queue_rings[thr]), _tot); break; + case __LINE__: SHOW_VAL("fd_takeover:", activity[thr].fd_takeover, _tot); break; #endif #if defined(DEBUG_DEV) - /* keep these ones at the end */ - SHOW_VAL("ctr0:", activity[thr].ctr0, _tot); - SHOW_VAL("ctr1:", activity[thr].ctr1, _tot); - SHOW_VAL("ctr2:", activity[thr].ctr2, _tot); + /* keep these ones at the end */ + case __LINE__: SHOW_VAL("ctr0:", activity[thr].ctr0, _tot); break; + case __LINE__: SHOW_VAL("ctr1:", activity[thr].ctr1, _tot); break; + case __LINE__: SHOW_VAL("ctr2:", activity[thr].ctr2, _tot); break; #endif - - if (applet_putchk(appctx, &trash) == -1) { - chunk_reset(&trash); - chunk_printf(&trash, "[output too large, cannot dump]\n"); - } - + } #undef SHOW_VAL + + if (applet_putchk(appctx, &trash) == -1) { + /* buffer full, retry later */ + return 0; + } + /* line was dumped, let's commit it */ + actctx->line++; + } while (actctx->line + base_line < __LINE__); + /* dump complete */ return 1; }