Add more debug messages to track thread/xlat allocations

diff --git a/src/lib/io/schedule.c b/src/lib/io/schedule.c
index 5fb85714f9cb72837e78f0c258e427ea3902321f..6cbebbf3ed0efe2896dfcf979e6ff66df52fae41 100644 (file)
--- a/src/lib/io/schedule.c
+++ b/src/lib/io/schedule.c
@@ -139,6 +139,16 @@ struct fr_schedule_t {
        fr_schedule_network_t *sn;              //!< pointer to the (one) network thread
 };
 
+static _Thread_local int worker_id;            //!< Internal ID of the current worker thread.
+
+/** Return the worker id for the current thread
+ *
+ * @return worker ID
+ */
+int fr_schedule_worker_id(void)
+{
+       return worker_id;
+}
 
 /** Initialize and run the worker thread.
  *
@@ -153,6 +163,8 @@ static void *fr_schedule_worker_thread(void *arg)
        fr_schedule_child_status_t status = FR_CHILD_FAIL;
        char buffer[32];
 
+       worker_id = sw->id;             /* Store the current worker ID */
+
        sw->ctx = ctx = talloc_init("worker %d", sw->id);
        if (!ctx) {
                fr_log(sc->log, L_ERR, "Worker %d - Failed allocating memory", sw->id);
@@ -235,7 +247,7 @@ fail:
 static void *fr_schedule_network_thread(void *arg)
 {
        TALLOC_CTX                      *ctx;
-       fr_schedule_network_t           *sn = arg;
+       fr_schedule_network_t           *sn = talloc_get_type_abort(arg, fr_schedule_network_t);
        fr_schedule_t                   *sc = sn->sc;
        fr_schedule_child_status_t      status = FR_CHILD_FAIL;
        fr_event_list_t                 *el;

diff --git a/src/lib/io/schedule.h b/src/lib/io/schedule.h
index dca1202dd6703d155a90926ecfac196d14cf8051..0524b4b0f38fe207b9d7a08c3a680c4dbaef92f5 100644 (file)
--- a/src/lib/io/schedule.h
+++ b/src/lib/io/schedule.h
@@ -36,6 +36,8 @@ extern "C" {
 typedef struct fr_schedule_t fr_schedule_t;
 typedef int (*fr_schedule_thread_instantiate_t)(void *ctx, fr_event_list_t *el);
 
+int                    fr_schedule_worker_id(void);
+
 fr_schedule_t          *fr_schedule_create(TALLOC_CTX *ctx, fr_event_list_t *el, fr_log_t *log, fr_log_lvl_t lvl,
                                            int max_inputs, int max_workers,
                                            fr_schedule_thread_instantiate_t worker_thread_instantiate,

diff --git a/src/lib/io/worker.c b/src/lib/io/worker.c
index 08e7ef39f6a0b47b6afae53d65166a00fbb5802c..fbec58ebb6101b7fce85aa29f63b274cce66a026 100644 (file)
--- a/src/lib/io/worker.c
+++ b/src/lib/io/worker.c
@@ -65,6 +65,7 @@ RCSID("$Id$")
 #include <freeradius-devel/io/channel.h>
 #include <freeradius-devel/io/message.h>
 #include <freeradius-devel/io/listen.h>
+#include <freeradius-devel/io/schedule.h>
 
 /**
  *  Track things by priority and time.
@@ -660,7 +661,7 @@ static void worker_reset_timer(fr_worker_t *worker)
        worker->next_cleanup = cleanup;
        fr_time_to_timeval(&when, cleanup);
 
-       DEBUG2("Resetting worker cleanup timer to +%ds", worker->max_request_time);
+       DEBUG2("Resetting worker %i cleanup timer to +%ds", worker->max_request_time, fr_schedule_worker_id());
        if (fr_event_timer_insert(worker, worker->el, &worker->ev_cleanup,
                                  &when, fr_worker_max_request_time, worker) < 0) {
                ERROR("Failed inserting max_request_time timer.");
@@ -768,7 +769,7 @@ static REQUEST *fr_worker_get_request(fr_worker_t *worker, fr_time_t now)
         */
        request = fr_heap_pop(worker->runnable);
        if (request) {
-               DEBUG3("Worker found runnable request.");
+               DEBUG3("Worker %i found runnable request", fr_schedule_worker_id());
                REQUEST_VERIFY(request);
                rad_assert(request->runnable_id < 0);
                fr_time_tracking_resume(&request->async->tracking, now);
@@ -785,11 +786,11 @@ static REQUEST *fr_worker_get_request(fr_worker_t *worker, fr_time_t now)
                        WORKER_HEAP_POP(to_decode, cd, request.list);
                }
                if (!cd) {
-                       DEBUG3("Worker localized and decode lists are empty.");
+                       DEBUG3("Worker %i localized and decode lists are empty", fr_schedule_worker_id());
                        return NULL;
                }
 
-               DEBUG3("Worker found request to decode.");
+               DEBUG3("Worker %i found request to decode", fr_schedule_worker_id());
                worker->num_decoded++;
        } while (!cd);
 
@@ -1103,7 +1104,7 @@ static int fr_worker_pre_event(void *ctx, struct timeval *wake)
         *      are still sleeping.
         */
        if (worker->was_sleeping) {
-               DEBUG3("\tworker was sleeping, not re-signaling");
+               DEBUG3("Worker %i was sleeping, not re-signaling", fr_schedule_worker_id());
                return 0;
        }
 
@@ -1460,7 +1461,7 @@ void fr_worker(fr_worker_t *worker)
                 */
                wait_for_event = (fr_heap_num_elements(worker->runnable) == 0);
                if (wait_for_event) {
-                       DEBUG("Ready to process requests.");
+                       INFO("Worker %i ready to process requests", fr_schedule_worker_id());
                }
 
                /*

diff --git a/src/main/module.c b/src/main/module.c
index 26589d79722ad17fe064a7a8a3cf64e653b412ef..f34cf3e9c678218e22bd781ffd578a19fad50cd6 100644 (file)
--- a/src/main/module.c
+++ b/src/main/module.c
@@ -492,7 +492,8 @@ static void _module_thread_instance_free(void *to_free)
 {
        module_thread_instance_t *ti = talloc_get_type_abort(to_free, module_thread_instance_t);
 
-       DEBUG3("Worker cleaning up %s thread instance data (%p/%p)", ti->module->name, ti, ti->data);
+       DEBUG4("Worker %i cleaning up %s thread instance data (%p/%p)",
+              fr_schedule_worker_id(), ti->module->name, ti, ti->data);
        if (ti->module->thread_detach) (void) ti->module->thread_detach(ti->el, ti->data);
 
        talloc_free(ti);
@@ -506,7 +507,7 @@ static void _module_thread_inst_tree_free(void *to_free)
 {
        rbtree_t *thread_inst_tree = talloc_get_type_abort(to_free , rbtree_t);
 
-       DEBUG3("Worker cleaning up thread instance tree");
+       DEBUG4("Worker %i cleaning up thread instance tree", fr_schedule_worker_id());
 
        talloc_free(thread_inst_tree);
 }
@@ -566,7 +567,8 @@ static int _module_thread_instantiate(void *instance, void *ctx)
                talloc_free(type_name);
        }
 
-       DEBUG3("Worker alloced %s thread instance data (%p/%p)", ti->module->name, ti, ti->data);
+       DEBUG4("Worker %i alloced %s thread instance data (%p/%p)",
+              fr_schedule_worker_id(), ti->module->name, ti, ti->data);
        if (mi->module->thread_instantiate) {
                ret = mi->module->thread_instantiate(mi->dl_inst->conf, mi->dl_inst->data,
                                                     thread_inst_ctx->el, ti->data);

diff --git a/src/main/xlat_inst.c b/src/main/xlat_inst.c
index 6bd27fc8cfde60bac178ab6192e8ba371fd27515..354bfc799710d3c06fa8d2144b7b02a2b6ae1990 100644 (file)
--- a/src/main/xlat_inst.c
+++ b/src/main/xlat_inst.c
@@ -27,6 +27,7 @@ RCSID("$Id$")
 
 #include <freeradius-devel/radiusd.h>
 #include <freeradius-devel/rad_assert.h>
+#include <freeradius-devel/io/schedule.h>
 
 #include <ctype.h>
 
@@ -97,6 +98,10 @@ static int _xlat_thread_inst_detach(xlat_thread_inst_t *thread_inst)
 static void _xlat_thread_inst_free(void *to_free)
 {
        xlat_thread_inst_t *thread_inst = talloc_get_type_abort(to_free, xlat_thread_inst_t);
+
+       DEBUG4("Worker %i cleaning up xlat thread instance (%p/%p)", fr_schedule_worker_id(),
+              thread_inst, thread_inst->data);
+
        talloc_free(thread_inst);
 }
 
@@ -108,7 +113,7 @@ static void _xlat_thread_inst_tree_free(void *to_free)
 {
        rbtree_t *thread_inst_tree = talloc_get_type_abort(to_free , rbtree_t);
 
-       DEBUG3("Worker cleaning up xlat thread instance tree");
+       DEBUG4("Worker %i cleaning up xlat thread instance tree", fr_schedule_worker_id());
        talloc_free(thread_inst_tree);
 }
 
@@ -156,6 +161,9 @@ static xlat_thread_inst_t *xlat_thread_inst_alloc(TALLOC_CTX *ctx, xlat_inst_t *
 #endif
        }
 
+       DEBUG4("Worker %i alloced xlat thread instance (%p/%p)", fr_schedule_worker_id(),
+              thread_inst, thread_inst->data);
+
        return thread_inst;
 }