From b23f04260bf46caf1f2c76af97d77511291851c6 Mon Sep 17 00:00:00 2001 From: Willy Tarreau Date: Tue, 16 Feb 2021 18:44:00 +0100 Subject: [PATCH] MINOR: tasks: add DEBUG_TASK to report caller info in a task The idea is to know who woke a task up, by recording the last two callers in a rotating mode. For now it's trivial with task_wakeup() but tasklet_wakeup_on() will require quite some more changes. This typically gives this from the debugger: (gdb) p t->debug $2 = { caller_file = {0x0, 0x8c0d80 "src/task.c"}, caller_line = {0, 260}, caller_idx = 1 } or this: (gdb) p t->debug $6 = { caller_file = {0x7fffe40329e0 "", 0x885feb "src/stream.c"}, caller_line = {284, 284}, caller_idx = 1 } But it also provides a trivial macro allowing to simply place a call in a task/tasklet handler that needs to be observed: DEBUG_TASK_PRINT_CALLER(t); Then starting haproxy this way would trivially yield such info: $ ./haproxy -db -f test.cfg | sort | uniq -c | sort -nr 199992 h1_io_cb woken up from src/sock.c:797 51764 h1_io_cb woken up from src/mux_h1.c:3634 65 h1_io_cb woken up from src/connection.c:169 45 h1_io_cb woken up from src/sock.c:777 --- Makefile | 3 ++- include/haproxy/task-t.h | 13 +++++++++++ include/haproxy/task.h | 49 ++++++++++++++++++++++++++++++++-------- 3 files changed, 54 insertions(+), 11 deletions(-) diff --git a/Makefile b/Makefile index 613067f75..a21f738e8 100644 --- a/Makefile +++ b/Makefile @@ -224,7 +224,8 @@ SMALL_OPTS = # without appearing here. Currently defined DEBUG macros include DEBUG_FULL, # DEBUG_MEM_STATS, DEBUG_DONT_SHARE_POOLS, DEBUG_NO_LOCKLESS_POOLS, DEBUG_FD, # DEBUG_NO_LOCAL_POOLS, DEBUG_FAIL_ALLOC, DEBUG_STRICT_NOCRASH, DEBUG_HPACK, -# DEBUG_AUTH, DEBUG_SPOE, DEBUG_UAF, DEBUG_THREAD, DEBUG_STRICT, DEBUG_DEV. +# DEBUG_AUTH, DEBUG_SPOE, DEBUG_UAF, DEBUG_THREAD, DEBUG_STRICT, DEBUG_DEV, +# DEBUG_TASK. DEBUG = #### Trace options diff --git a/include/haproxy/task-t.h b/include/haproxy/task-t.h index 38dd3ec1d..4bc88beb4 100644 --- a/include/haproxy/task-t.h +++ b/include/haproxy/task-t.h @@ -84,6 +84,18 @@ struct task_per_thread { __attribute__((aligned(64))) char end[0]; }; + +#ifdef DEBUG_TASK +#define TASK_DEBUG_STORAGE \ + struct { \ + const char *caller_file[2]; \ + int caller_line[2]; \ + int caller_idx; \ + } debug +#else +#define TASK_DEBUG_STORAGE +#endif + /* This part is common between struct task and struct tasklet so that tasks * can be used as-is as tasklets. */ @@ -94,6 +106,7 @@ struct task_per_thread { unsigned int calls; /* number of times process was called */ \ struct task *(*process)(struct task *t, void *ctx, unsigned short state); /* the function which processes the task */ \ void *context; /* the task's context */ \ + TASK_DEBUG_STORAGE; \ } /* The base for all tasks */ diff --git a/include/haproxy/task.h b/include/haproxy/task.h index a02fd2fcf..abe923d32 100644 --- a/include/haproxy/task.h +++ b/include/haproxy/task.h @@ -172,9 +172,12 @@ static inline int thread_has_tasks(void) /* puts the task in run queue with reason flags , and returns */ /* This will put the task in the local runqueue if the task is only runnable - * by the current thread, in the global runqueue otherwies. + * by the current thread, in the global runqueue otherwies. With DEBUG_TASK, + * the : from the call place are stored into the task for tracing + * purposes. */ -static inline void task_wakeup(struct task *t, unsigned int f) +#define task_wakeup(t, f) _task_wakeup(t, f, __FILE__, __LINE__) +static inline void _task_wakeup(struct task *t, unsigned int f, const char *file, int line) { unsigned short state; @@ -192,6 +195,11 @@ static inline void task_wakeup(struct task *t, unsigned int f) state = _HA_ATOMIC_OR(&t->state, f); while (!(state & (TASK_RUNNING | TASK_QUEUED))) { if (_HA_ATOMIC_CAS(&t->state, &state, state | TASK_QUEUED)) { +#ifdef DEBUG_TASK + t->debug.caller_idx = !t->debug.caller_idx; + t->debug.caller_file[t->debug.caller_idx] = file; + t->debug.caller_line[t->debug.caller_idx] = line; +#endif __task_wakeup(t, root); break; } @@ -324,9 +332,12 @@ static inline struct task *task_unlink_rq(struct task *t) /* schedules tasklet to run onto thread or the current thread if * is negative. Note that it is illegal to wakeup a foreign tasklet if * its tid is negative and it is illegal to self-assign a tasklet that was - * at least once scheduled on a specific thread. + * at least once scheduled on a specific thread. With DEBUG_TASK, the + * : from the call place are stored into the tasklet for tracing + * purposes. */ -static inline void tasklet_wakeup_on(struct tasklet *tl, int thr) +#define tasklet_wakeup_on(tl, thr) _tasklet_wakeup_on(tl, thr, __FILE__, __LINE__) +static inline void _tasklet_wakeup_on(struct tasklet *tl, int thr, const char *file, int line) { unsigned short state = tl->state; @@ -336,7 +347,12 @@ static inline void tasklet_wakeup_on(struct tasklet *tl, int thr) return; } while (!_HA_ATOMIC_CAS(&tl->state, &state, state | TASK_IN_LIST)); - /* at this pint we're the first ones to add this task to the list */ + /* at this point we're the first ones to add this task to the list */ +#ifdef DEBUG_TASK + tl->debug.caller_idx = !tl->debug.caller_idx; + tl->debug.caller_file[tl->debug.caller_idx] = file; + tl->debug.caller_line[tl->debug.caller_idx] = line; +#endif if (likely(thr < 0)) { /* this tasklet runs on the caller thread */ @@ -369,12 +385,25 @@ static inline void tasklet_wakeup_on(struct tasklet *tl, int thr) } /* schedules tasklet to run onto the thread designated by tl->tid, which - * is either its owner thread if >= 0 or the current thread if < 0. + * is either its owner thread if >= 0 or the current thread if < 0. When + * DEBUG_TASK is set, the : from the call place are stored into the + * task for tracing purposes. */ -static inline void tasklet_wakeup(struct tasklet *tl) -{ - tasklet_wakeup_on(tl, tl->tid); -} +#define tasklet_wakeup(tl) _tasklet_wakeup_on(tl, (tl)->tid, __FILE__, __LINE__) + +/* This macro shows the current function name and the last known caller of the + * task (or tasklet) wakeup. + */ +#ifdef DEBUG_TASK +#define DEBUG_TASK_PRINT_CALLER(t) do { \ + printf("%s woken up from %s:%d\n", __FUNCTION__, \ + (t)->debug.caller_file[(t)->debug.caller_idx], \ + (t)->debug.caller_line[(t)->debug.caller_idx]); \ +} while (0) +#else +#define DEBUG_TASK_PRINT_CALLER(t) +#endif + /* Try to remove a tasklet from the list. This call is inherently racy and may * only be performed on the thread that was supposed to dequeue this tasklet.