print out stats in a hokey format

we can always change it later

diff --git a/src/include/features-h b/src/include/features-h
index 1b0c4606b035c987225e82f24bae90e288a28f2e..deff87643ddd44734c104e9f198c6dd2cd915659 100644 (file)
--- a/src/include/features-h
+++ b/src/include/features-h
@@ -22,3 +22,10 @@
 #    endif
 #  endif
 #endif
+
+/*
+ *     Unlang performance stats
+ */
+#ifndef WITHOUT_PERF
+#define WITH_PERF
+#endif

diff --git a/src/lib/unlang/base.h b/src/lib/unlang/base.h
index 9344383a32a67b5d8b2d3732a8eb1e162abae9b5..5f5e82b073a68f680c7868ca9b9224b09e080411 100644 (file)
--- a/src/lib/unlang/base.h
+++ b/src/lib/unlang/base.h
@@ -42,6 +42,10 @@ void                 unlang_free_global(void);
 
 int                    unlang_thread_instantiate(TALLOC_CTX *ctx) CC_HINT(nonnull);
 
+#ifdef WITH_PERF
+void                   unlang_perf_virtual_server(fr_log_t *log, char const *name);
+#endif
+
 #ifdef __cplusplus
 }
 #endif

diff --git a/src/lib/unlang/compile.c b/src/lib/unlang/compile.c
index 39472aca42f0b2bab79c0d194594e7a4657e484e..8ca326b3f1965d7b1eabc8a688c796582761b908 100644 (file)
--- a/src/lib/unlang/compile.c
+++ b/src/lib/unlang/compile.c
@@ -4094,3 +4094,135 @@ int unlang_thread_instantiate(TALLOC_CTX *ctx)
 
        return 0;
 }
+
+#ifdef WITH_PERF
+void unlang_frame_perf_init(unlang_t const *instruction)
+{
+       unlang_thread_t *t;
+
+       if (!instruction->number) return;
+
+       t = &unlang_thread_array[instruction->number];
+
+       t->use_count++;
+
+       t->enter = fr_time();
+
+}
+
+void unlang_frame_perf_cleanup(unlang_t const *instruction)
+{
+       unlang_thread_t *t;
+
+       if (!instruction->number) return;
+
+       t = &unlang_thread_array[instruction->number];
+
+       t->cpu_time += (fr_time() - t->enter);
+}
+
+
+static void unlang_perf_dump(fr_log_t *log, unlang_t const *instruction, int depth)
+{
+       unlang_group_t const *g;
+       unlang_thread_t *t;
+       char const *file;
+       int line;
+
+       if (!instruction || !instruction->number) return;
+
+       /*
+        *      These are generally pushed onto the stack, and therefore ignored.
+        */
+       if (instruction->type == UNLANG_TYPE_TMPL) return;
+
+       /*
+        *      Everything else is an unlang_group_t;
+        */
+       g = unlang_generic_to_group(instruction);
+
+       if (!g->cs) return;
+
+       file = cf_filename(g->cs);
+       line = cf_lineno(g->cs);
+
+       if (depth) {
+               fr_log(log, L_DBG, file, line, "%.*s", depth, unlang_spaces);
+       }
+
+       if (unlang_ops[instruction->type].debug_braces) {
+               fr_log(log, L_DBG, file, line, "%s { #", instruction->debug_name);
+       } else {
+               fr_log(log, L_DBG, file, line, "%s #", instruction->debug_name);
+       }
+
+       t = &unlang_thread_array[instruction->number];
+
+       fr_log(log, L_DBG, file, line, "count=%llu cpu_time=%llu\n", t->use_count, t->cpu_time);
+
+       if (g->children) {
+               unlang_t *child;
+
+               for (child = g->children; child != NULL; child = child->next) {
+                       unlang_perf_dump(log, child, depth + 1);
+               }
+       }
+
+       if (unlang_ops[instruction->type].debug_braces) {
+               if (depth) {
+                       fr_log(log, L_DBG, file, line, "%.*s", depth, unlang_spaces);
+               }
+
+               fr_log(log, L_DBG, file, line, "}\n");
+       }
+}
+
+void unlang_perf_virtual_server(fr_log_t *log, char const *name)
+{
+       CONF_SECTION *cs = virtual_server_find(name);
+       CONF_ITEM *ci;
+       char const *file;
+       int line;
+
+       if (!cs) return;
+
+       file = cf_filename(cs);
+       line = cf_lineno(cs);
+
+       fr_log(log, L_DBG, file, line, " server %s {\n", name);
+
+       /*
+        *      Loop over the children of the virtual server, checking for unlang_t;
+        */
+       for (ci = cf_item_next(cs, NULL);
+            ci != NULL;
+            ci = cf_item_next(cs, ci)) {
+               char const *name1, *name2;
+               unlang_t *instruction;
+               CONF_SECTION *subcs;
+
+               if (!cf_item_is_section(ci)) continue;
+
+               instruction = (unlang_t *)cf_data_value(cf_data_find(ci, unlang_group_t, NULL));
+               if (!instruction) continue;
+
+               subcs = cf_item_to_section(ci);
+               name1 = cf_section_name1(subcs);
+               name2 = cf_section_name2(subcs);
+               file = cf_filename(ci);
+               line = cf_lineno(ci);
+
+               if (!name2) {
+                       fr_log(log, L_DBG, file, line, " %s {\n", name1);
+               } else {
+                       fr_log(log, L_DBG, file, line, " %s %s {\n", name1, name2);
+               }
+
+               unlang_perf_dump(log, instruction, 2);
+
+               fr_log(log, L_DBG, file, line, " }\n");
+       }
+
+       fr_log(log, L_DBG, file, line, "}\n");
+}
+#endif

diff --git a/src/lib/unlang/unlang_priv.h b/src/lib/unlang/unlang_priv.h
index 85b62d86d721ad8d0be31ead615233cc7cb46c23..92a8a37ce60b912e1a0081906a79573824f959c7 100644 (file)
--- a/src/lib/unlang/unlang_priv.h
+++ b/src/lib/unlang/unlang_priv.h
@@ -229,11 +229,23 @@ typedef struct {
 typedef struct {
        unlang_t const          *instruction;                   //!< instruction which we're executing
        void                    *thread_inst;                   //!< thread-specific instance data
-       /*
-        *      And various other stats
-        */
+#ifdef WITH_PERF
+       uint64_t                use_count;
+       fr_time_t               enter;
+
+       fr_time_delta_t         cpu_time;
+#endif
 } unlang_thread_t;
 
+#ifdef WITH_PERF
+void           unlang_frame_perf_init(unlang_t const *instruction);
+
+void           unlang_frame_perf_cleanup(unlang_t const *instruction);
+#else
+#define                unlang_frame_perf_init(_x)
+#define                unlang_frame_perf_cleanup(_x)
+#endif
+
 typedef struct {
        request_t               *request;
        int                     depth;                          //!< of this retry structure
@@ -372,6 +384,8 @@ static inline void frame_state_init(unlang_stack_t *stack, unlang_stack_frame_t
        unlang_op_t     *op;
        char const      *name;
 
+       unlang_frame_perf_init(frame->instruction);
+
        op = &unlang_ops[instruction->type];
        name = op->frame_state_name ? op->frame_state_name : __location__;
 
@@ -422,6 +436,8 @@ static inline void frame_cleanup(unlang_stack_frame_t *frame)
                talloc_free_children(frame->state); /* *(ev->parent) = NULL in event.c */
                TALLOC_FREE(frame->state);
        }
+
+       unlang_frame_perf_cleanup(frame->instruction);
 }
 
 /** Advance to the next sibling instruction