]> git.ipfire.org Git - thirdparty/bind9.git/commitdiff
Add detailed tracing when TASKMGR_TRACE is defined
authorOndřej Surý <ondrej@isc.org>
Sat, 26 Mar 2022 13:37:38 +0000 (14:37 +0100)
committerOndřej Surý <ondrej@isc.org>
Tue, 19 Apr 2022 12:25:23 +0000 (14:25 +0200)
When TASKMGR_TRACE=1 is defined, the task and event objects have
detailed tracing information about function, file, line, and
backtrace (to the extent tracked by gcc) where it was created.

At exit, when there are unfinished tasks, they will be printed along
with the detailed information.

lib/isc/event.c
lib/isc/include/isc/event.h
lib/isc/include/isc/task.h
lib/isc/task.c

index 547c839bb95c61c9d01a8bb54e08b5fce233f3bc..294da352548654dff55b51da088475c35e27953b 100644 (file)
@@ -31,8 +31,9 @@ destroy(isc_event_t *event) {
 }
 
 isc_event_t *
-isc_event_allocate(isc_mem_t *mctx, void *sender, isc_eventtype_t type,
-                  isc_taskaction_t action, void *arg, size_t size) {
+isc__event_allocate(isc_mem_t *mctx, void *sender, isc_eventtype_t type,
+                   isc_taskaction_t action, void *arg,
+                   size_t size ISC__EVENT_FLARG) {
        isc_event_t *event;
 
        REQUIRE(size >= sizeof(struct isc_event));
@@ -40,8 +41,8 @@ isc_event_allocate(isc_mem_t *mctx, void *sender, isc_eventtype_t type,
 
        event = isc_mem_get(mctx, size);
 
-       ISC_EVENT_INIT(event, size, 0, NULL, type, action, arg, sender, destroy,
-                      mctx);
+       ISC_EVENT_INIT_PASS(event, size, 0, NULL, type, action, arg, sender,
+                           destroy, mctx);
 
        return (event);
 }
index 8d7048cd52bd9e1531dd40064ea935ab0eb88c52..c3db54064862e7586a6314cd6767c5c9f59ab0a4 100644 (file)
 
 /*! \file isc/event.h */
 
+#include <isc/backtrace.h>
 #include <isc/lang.h>
+#include <isc/string.h>
 #include <isc/types.h>
+#include <isc/util.h>
 
 /*****
 ***** Events.
 
 typedef void (*isc_eventdestructor_t)(isc_event_t *);
 
+#if TASKMGR_TRACE
+#define ISC__EVENT_TRACE_SIZE 8
+#define ISC__EVENT_FILELINE   , __func__, __FILE__, __LINE__
+#define ISC__EVENT_FLARG      , const char *func, const char *file, unsigned int line
+
+#define ISC_EVENT_COMMON(ltype)                                 \
+       size_t                ev_size;                          \
+       unsigned int          ev_attributes;                    \
+       void                 *ev_tag;                           \
+       isc_eventtype_t       ev_type;                          \
+       isc_taskaction_t      ev_action;                        \
+       void                 *ev_arg;                           \
+       void                 *ev_sender;                        \
+       isc_eventdestructor_t ev_destroy;                       \
+       void                 *ev_destroy_arg;                   \
+       void                 *backtrace[ISC__EVENT_TRACE_SIZE]; \
+       int                   backtrace_size;                   \
+       char                  func[PATH_MAX];                   \
+       char                  file[PATH_MAX];                   \
+       unsigned int          line;                             \
+       ISC_LINK(ltype) ev_link;                                \
+       ISC_LINK(ltype) ev_ratelink
+
+#define ISC_EVENT_INIT(event, sz, at, ta, ty, ac, ar, sn, df, da)            \
+       ISC__EVENT_INIT(event, sz, at, ta, ty, ac, ar, sn, df, da, __func__, \
+                       __FILE__, __LINE__)
+
+#define ISC_EVENT_INIT_PASS(event, sz, at, ta, ty, ac, ar, sn, df, da)         \
+       ISC__EVENT_INIT(event, sz, at, ta, ty, ac, ar, sn, df, da, func, file, \
+                       line)
+
+#define ISC__EVENT_INIT(event, sz, at, ta, ty, ac, ar, sn, df, da, fn, fl, ln) \
+       {                                                                      \
+               (event)->ev_size = (sz);                                       \
+               (event)->ev_attributes = (at);                                 \
+               (event)->ev_tag = (ta);                                        \
+               (event)->ev_type = (ty);                                       \
+               (event)->ev_action = (ac);                                     \
+               (event)->ev_arg = (ar);                                        \
+               (event)->ev_sender = (sn);                                     \
+               (event)->ev_destroy = (df);                                    \
+               (event)->ev_destroy_arg = (da);                                \
+               ISC_LINK_INIT((event), ev_link);                               \
+               ISC_LINK_INIT((event), ev_ratelink);                           \
+               strlcpy((event)->func, fn, sizeof((event)->func));             \
+               strlcpy((event)->file, fl, sizeof((event)->file));             \
+               (event)->line = ln;                                            \
+               (event)->backtrace_size = isc_backtrace(                       \
+                       (event)->backtrace, ISC__EVENT_TRACE_SIZE);            \
+       }
+
+#else
+#define ISC__EVENT_FILELINE
+#define ISC__EVENT_FLARG
+#define ISC__EVENT_FLARG_PASS
+
 #define ISC_EVENT_COMMON(ltype)               \
        size_t                ev_size;        \
        unsigned int          ev_attributes;  \
@@ -37,6 +96,25 @@ typedef void (*isc_eventdestructor_t)(isc_event_t *);
        ISC_LINK(ltype) ev_link;              \
        ISC_LINK(ltype) ev_ratelink
 
+#define ISC_EVENT_INIT(event, sz, at, ta, ty, ac, ar, sn, df, da) \
+       {                                                         \
+               (event)->ev_size = (sz);                          \
+               (event)->ev_attributes = (at);                    \
+               (event)->ev_tag = (ta);                           \
+               (event)->ev_type = (ty);                          \
+               (event)->ev_action = (ac);                        \
+               (event)->ev_arg = (ar);                           \
+               (event)->ev_sender = (sn);                        \
+               (event)->ev_destroy = (df);                       \
+               (event)->ev_destroy_arg = (da);                   \
+               ISC_LINK_INIT((event), ev_link);                  \
+               ISC_LINK_INIT((event), ev_ratelink);              \
+       }
+
+#define ISC_EVENT_INIT_PASS ISC_EVENT_INIT
+
+#endif
+
 /*%
  * Attributes matching a mask of 0x000000ff are reserved for the task library's
  * definition.  Attributes of 0xffffff00 may be used by the application
@@ -52,21 +130,6 @@ typedef void (*isc_eventdestructor_t)(isc_event_t *);
  */
 #define ISC_EVENTATTR_CANCELED 0x00000002
 
-#define ISC_EVENT_INIT(event, sz, at, ta, ty, ac, ar, sn, df, da) \
-       do {                                                      \
-               (event)->ev_size = (sz);                          \
-               (event)->ev_attributes = (at);                    \
-               (event)->ev_tag = (ta);                           \
-               (event)->ev_type = (ty);                          \
-               (event)->ev_action = (ac);                        \
-               (event)->ev_arg = (ar);                           \
-               (event)->ev_sender = (sn);                        \
-               (event)->ev_destroy = (df);                       \
-               (event)->ev_destroy_arg = (da);                   \
-               ISC_LINK_INIT((event), ev_link);                  \
-               ISC_LINK_INIT((event), ev_ratelink);              \
-       } while (0)
-
 /*%
  * This structure is public because "subclassing" it may be useful when
  * defining new event types.
@@ -79,9 +142,14 @@ struct isc_event {
 
 ISC_LANG_BEGINDECLS
 
+#define isc_event_allocate(mctx, sender, type, action, arg, size) \
+       isc__event_allocate(mctx, sender, type, action, arg,      \
+                           size ISC__EVENT_FILELINE)
+
 isc_event_t *
-isc_event_allocate(isc_mem_t *mctx, void *sender, isc_eventtype_t type,
-                  isc_taskaction_t action, void *arg, size_t size);
+isc__event_allocate(isc_mem_t *mctx, void *sender, isc_eventtype_t type,
+                   isc_taskaction_t action, void *arg,
+                   size_t size ISC__EVENT_FLARG);
 /*%<
  * Allocate an event structure.
  *
index 3a64dad52a72b1f53c81f7cd3933425b7ffd76c6..a7ba30441305808a000ad814d7275de2b816e40a 100644 (file)
 #include <isc/netmgr.h>
 #include <isc/stdtime.h>
 #include <isc/types.h>
+#include <isc/util.h>
+
+#if TASKMGR_TRACE
+#define ISC__TASKTRACE_SIZE 8
+#define ISC__TASKFILELINE   , __func__, __FILE__, __LINE__
+#define ISC__TASKFLARG     , const char *func, const char *file, unsigned int line
+
+#else
+#define ISC__TASKFILELINE
+#define ISC__TASKFLARG
+#endif
 
 #define ISC_TASKEVENT_SHUTDOWN (ISC_EVENTCLASS_TASK + 0)
 #define ISC_TASKEVENT_TEST     (ISC_EVENTCLASS_TASK + 1)
@@ -81,12 +92,14 @@ ISC_LANG_BEGINDECLS
  *** Types
  ***/
 
+#define isc_task_create(m, q, t) \
+       isc__task_create_bound(m, q, t, -1 ISC__TASKFILELINE)
+#define isc_task_create_bound(m, q, t, i) \
+       isc__task_create_bound(m, q, t, i ISC__TASKFILELINE)
+
 isc_result_t
-isc_task_create(isc_taskmgr_t *manager, unsigned int quantum,
-               isc_task_t **taskp);
-isc_result_t
-isc_task_create_bound(isc_taskmgr_t *manager, unsigned int quantum,
-                     isc_task_t **taskp, int tid);
+isc__task_create_bound(isc_taskmgr_t *manager, unsigned int quantum,
+                      isc_task_t **taskp, int tid ISC__TASKFLARG);
 /*%<
  * Create a task, optionally bound to a particular tid.
  *
index fb40c1f7a9d937cc0292f88929f9d74f8cd5d93d..f61b46fd5d71ae5fe3f1cc40d05c808c6e543d4c 100644 (file)
 
 #include <stdbool.h>
 #include <unistd.h>
+#include <uv.h>
 
 #include <isc/app.h>
 #include <isc/atomic.h>
+#include <isc/backtrace.h>
 #include <isc/condition.h>
 #include <isc/event.h>
 #include <isc/log.h>
@@ -47,6 +49,7 @@
 #include <json_object.h>
 #endif /* HAVE_JSON_C */
 
+#include "netmgr/uv-compat.h"
 #include "task_p.h"
 
 /*
@@ -95,6 +98,11 @@ static const char *statenames[] = {
 #define TASK_MAGIC    ISC_MAGIC('T', 'A', 'S', 'K')
 #define VALID_TASK(t) ISC_MAGIC_VALID(t, TASK_MAGIC)
 
+#if TASKMGR_TRACE
+void
+isc__taskmgr_dump_active(isc_taskmgr_t *taskmgr);
+#endif
+
 struct isc_task {
        /* Not locked. */
        unsigned int magic;
@@ -117,6 +125,13 @@ struct isc_task {
        /* Protected by atomics */
        atomic_bool shuttingdown;
        /* Locked by task manager lock. */
+#if TASKMGR_TRACE
+       char func[PATH_MAX];
+       char file[PATH_MAX];
+       unsigned int line;
+       void *backtrace[ISC__TASKTRACE_SIZE];
+       int backtrace_size;
+#endif
        LINK(isc_task_t) link;
 };
 
@@ -190,14 +205,8 @@ task_finished(isc_task_t *task) {
 }
 
 isc_result_t
-isc_task_create(isc_taskmgr_t *manager, unsigned int quantum,
-               isc_task_t **taskp) {
-       return (isc_task_create_bound(manager, quantum, taskp, -1));
-}
-
-isc_result_t
-isc_task_create_bound(isc_taskmgr_t *manager, unsigned int quantum,
-                     isc_task_t **taskp, int tid) {
+isc__task_create_bound(isc_taskmgr_t *manager, unsigned int quantum,
+                      isc_task_t **taskp, int tid ISC__TASKFLARG) {
        isc_task_t *task = NULL;
        bool exiting;
 
@@ -209,6 +218,14 @@ isc_task_create_bound(isc_taskmgr_t *manager, unsigned int quantum,
        task = isc_mem_get(manager->mctx, sizeof(*task));
        *task = (isc_task_t){ 0 };
 
+#if TASKMGR_TRACE
+       strlcpy(task->func, func, sizeof(task->func));
+       strlcpy(task->file, file, sizeof(task->file));
+       task->line = line;
+       task->backtrace_size = isc_backtrace(task->backtrace,
+                                            ISC__TASKTRACE_SIZE);
+#endif
+
        isc_taskmgr_attach(manager, &task->manager);
 
        if (tid == -1) {
@@ -909,20 +926,24 @@ void
 isc__taskmgr_destroy(isc_taskmgr_t **managerp) {
        REQUIRE(managerp != NULL && VALID_MANAGER(*managerp));
        XTHREADTRACE("isc_taskmgr_destroy");
-
-#ifdef ISC_TASK_TRACE
        int counter = 0;
+
        while (isc_refcount_current(&(*managerp)->references) > 1 &&
               counter++ < 1000) {
-               usleep(10 * 1000);
+               uv_sleep(10);
        }
-       INSIST(counter < 1000);
-#else
-       while (isc_refcount_current(&(*managerp)->references) > 1) {
-               usleep(10 * 1000);
+
+#if TASKMGR_TRACE
+       if (isc_refcount_current(&(*managerp)->references) > 1) {
+               isc__taskmgr_dump_active(*managerp);
        }
+       INSIST(isc_refcount_current(&(*managerp)->references) == 1);
 #endif
 
+       while (isc_refcount_current(&(*managerp)->references) > 1) {
+               uv_sleep(10);
+       }
+
        isc_taskmgr_detach(managerp);
 }
 
@@ -1215,3 +1236,55 @@ error:
        return (result);
 }
 #endif /* ifdef HAVE_JSON_C */
+
+#if TASKMGR_TRACE
+
+static void
+event_dump(isc_event_t *event) {
+       fprintf(stderr, "  - event: %p\n", event);
+       fprintf(stderr, "    func: %s\n", event->func);
+       fprintf(stderr, "    file: %s\n", event->file);
+       fprintf(stderr, "    line: %u\n", event->line);
+       fprintf(stderr, "    backtrace: |\n");
+       isc_backtrace_symbols_fd(event->backtrace, event->backtrace_size,
+                                STDERR_FILENO);
+}
+
+static void
+task_dump(isc_task_t *task) {
+       LOCK(&task->lock);
+       fprintf(stderr, "- task: %p\n", task);
+       fprintf(stderr, "  tid: %" PRIu32 "\n", task->tid);
+       fprintf(stderr, "  nevents: %u\n", task->nevents);
+       fprintf(stderr, "    func: %s\n", task->func);
+       fprintf(stderr, "    file: %s\n", task->file);
+       fprintf(stderr, "    line: %u\n", task->line);
+       fprintf(stderr, "  backtrace: |\n");
+       isc_backtrace_symbols_fd(task->backtrace, task->backtrace_size,
+                                STDERR_FILENO);
+       fprintf(stderr, "\n");
+
+       for (isc_event_t *event = ISC_LIST_HEAD(task->events); event != NULL;
+            event = ISC_LIST_NEXT(event, ev_link))
+       {
+               event_dump(event);
+       }
+
+       UNLOCK(&task->lock);
+}
+
+void
+isc__taskmgr_dump_active(isc_taskmgr_t *taskmgr) {
+       LOCK(&taskmgr->lock);
+       fprintf(stderr, "- taskmgr: %p\n", taskmgr);
+
+       for (isc_task_t *task = ISC_LIST_HEAD(taskmgr->tasks); task != NULL;
+            task = ISC_LIST_NEXT(task, link))
+       {
+               task_dump(task);
+       }
+
+       UNLOCK(&taskmgr->lock);
+}
+
+#endif