Typo
[freeradius.git] / src / lib / debug.c
index 60589c7..1947325 100644 (file)
 #include <freeradius-devel/libradius.h>
 #include <sys/stat.h>
 
+#if defined(HAVE_MALLOPT) && defined(HAVE_MALLOC_H)
+#  include <malloc.h>
+#endif
+
 /*
  *     runtime backtrace functions are not POSIX but are included in
  *     glibc, OSX >= 10.5 and various BSDs
@@ -78,11 +82,15 @@ static int fr_fault_log_fd = STDERR_FILENO;         //!< Where to write debug output.
 
 static int fr_debugger_present = -1;                   //!< Whether were attached to by a debugger.
 
-
 #ifdef HAVE_SYS_RESOURCE_H
 static struct rlimit core_limits;
 #endif
 
+static TALLOC_CTX *talloc_null_ctx;
+static TALLOC_CTX *talloc_autofree_ctx;
+
+#define FR_FAULT_LOG(fmt, ...) fr_fault_log(fmt "\n", ## __VA_ARGS__)
+
 /** Stub callback to see if the SIGTRAP handler is overriden
  *
  * @param signum signal raised.
@@ -112,28 +120,6 @@ void fr_debug_break(void)
 }
 
 #ifdef HAVE_EXECINFO
-/** Generate a backtrace for an object during destruction
- *
- * If this is the first entry being inserted
- */
-static int _fr_do_bt(fr_bt_marker_t *marker)
-{
-       fr_bt_info_t *bt;
-
-       if (!fr_assert(marker->obj) || !fr_assert(marker->cbuff)) {
-               return -1;
-       }
-
-       bt = talloc_zero(marker->cbuff, fr_bt_info_t);
-       if (!bt) {
-               return -1;
-       }
-       bt->count = backtrace(bt->frames, MAX_BT_FRAMES);
-       fr_cbuff_rp_insert(marker->cbuff, bt);
-
-       return 0;
-}
-
 /** Print backtrace entry for a given object
  *
  * @param cbuff to search in.
@@ -143,23 +129,13 @@ void backtrace_print(fr_cbuff_t *cbuff, void *obj)
 {
        fr_bt_info_t *p;
        bool found = false;
-       int i = 0;
-       char **frames;
 
        while ((p = fr_cbuff_rp_next(cbuff, NULL))) {
-               if ((p == obj) || !obj) {
+               if ((p->obj == obj) || !obj) {
                        found = true;
-                       frames = backtrace_symbols(p->frames, p->count);
-
-                       fprintf(stderr, "Stacktrace for: %p\n", p);
-                       for (i = 0; i < p->count; i++) {
-                               fprintf(stderr, "%s\n", frames[i]);
-                       }
 
-                       /* We were only asked to look for one */
-                       if (obj) {
-                               return;
-                       }
+                       fprintf(stderr, "Stacktrace for: %p\n", p->obj);
+                       backtrace_symbols_fd(p->frames, p->count, STDERR_FILENO);
                }
        };
 
@@ -168,6 +144,27 @@ void backtrace_print(fr_cbuff_t *cbuff, void *obj)
        }
 }
 
+/** Generate a backtrace for an object
+ *
+ * If this is the first entry being inserted
+ */
+int fr_backtrace_do(fr_bt_marker_t *marker)
+{
+       fr_bt_info_t *bt;
+
+       if (!fr_assert(marker->obj) || !fr_assert(marker->cbuff)) return -1;
+
+       bt = talloc_zero(NULL, fr_bt_info_t);
+       if (!bt) return -1;
+
+       bt->obj = marker->obj;
+       bt->count = backtrace(bt->frames, MAX_BT_FRAMES);
+
+       fr_cbuff_rp_insert(marker->cbuff, bt);
+
+       return 0;
+}
+
 /** Inserts a backtrace marker into the provided context
  *
  * Allows for maximum laziness and will initialise a circular buffer if one has not already been created.
@@ -175,7 +172,7 @@ void backtrace_print(fr_cbuff_t *cbuff, void *obj)
  * Code augmentation should look something like:
 @verbatim
        // Create a static cbuffer pointer, the first call to backtrace_attach will initialise it
-       static fr_cbuff *my_obj_bt;
+       static fr_cbuff_t *my_obj_bt;
 
        my_obj_t *alloc_my_obj(TALLOC_CTX *ctx) {
                my_obj_t *this;
@@ -207,12 +204,7 @@ fr_bt_marker_t *fr_backtrace_attach(fr_cbuff_t **cbuff, TALLOC_CTX *obj)
        if (*cbuff == NULL) {
                PTHREAD_MUTEX_LOCK(&fr_debug_init);
                /* Check again now we hold the mutex - eww*/
-               if (*cbuff == NULL) {
-                       TALLOC_CTX *ctx;
-
-                       ctx = fr_autofree_ctx();
-                       *cbuff = fr_cbuff_alloc(ctx, MAX_BT_CBUFF, true);
-               }
+               if (*cbuff == NULL) *cbuff = fr_cbuff_alloc(NULL, MAX_BT_CBUFF, true);
                PTHREAD_MUTEX_UNLOCK(&fr_debug_init);
        }
 
@@ -224,7 +216,12 @@ fr_bt_marker_t *fr_backtrace_attach(fr_cbuff_t **cbuff, TALLOC_CTX *obj)
        marker->obj = (void *) obj;
        marker->cbuff = *cbuff;
 
-       talloc_set_destructor(marker, _fr_do_bt);
+       fprintf(stderr, "Backtrace attached to %s %p\n", talloc_get_name(obj), obj);
+       /*
+        *      Generate the backtrace for memory allocation
+        */
+       fr_backtrace_do(marker);
+       talloc_set_destructor(marker, fr_backtrace_do);
 
        return marker;
 }
@@ -240,6 +237,25 @@ fr_bt_marker_t *fr_backtrace_attach(UNUSED fr_cbuff_t **cbuff, UNUSED TALLOC_CTX
 }
 #endif /* ifdef HAVE_EXECINFO */
 
+static int _panic_on_free(UNUSED char *foo)
+{
+       fr_fault(SIGUSR1);
+       return -1;      /* this should make the free fail */
+}
+
+/** Insert memory into the context of another talloc memory chunk which
+ * causes a panic when freed.
+ *
+ * @param ctx TALLOC_CTX to monitor for frees.
+ */
+void fr_panic_on_free(TALLOC_CTX *ctx)
+{
+       char *ptr;
+
+       ptr = talloc(ctx, char);
+       talloc_set_destructor(ptr, _panic_on_free);
+}
+
 /** Set the dumpable flag, also controls whether processes can PATTACH
  *
  * @param dumpable whether we should allow core dumping
@@ -258,10 +274,40 @@ static int fr_set_dumpable_flag(bool dumpable)
 #else
 static int fr_set_dumpable_flag(UNUSED bool dumpable)
 {
-       return 0;
+       fr_strerror_printf("Changing value of PR_DUMPABLE not supported on this system");
+       return -2;
 }
 #endif
 
+/** Get the processes dumpable flag
+ *
+ */
+#if defined(HAVE_SYS_PRCTL_H) && defined(PR_GET_DUMPABLE)
+static int fr_get_dumpable_flag(void)
+{
+       int ret;
+
+       ret = prctl(PR_GET_DUMPABLE);
+       if (ret < 0) {
+               fr_strerror_printf("Cannot get dumpable flag: %s", fr_syserror(errno));
+               return -1;
+       }
+
+       /*
+        *  Linux is crazy and prctl sometimes returns 2 for disabled
+        */
+       if (ret != 1) return 0;
+       return 1;
+}
+#else
+static int fr_get_dumpable_flag(void)
+{
+       fr_strerror_printf("Getting value of PR_DUMPABLE not supported on this system");
+       return -2;
+}
+#endif
+
+
 /** Get the current maximum for core files
  *
  * Do this before anything else so as to ensure it's properly initialized.
@@ -324,7 +370,8 @@ int fr_set_dumpable(bool allow_core_dumps)
 static int fr_fault_check_permissions(void)
 {
        char const *p, *q;
-       char *filename = NULL;
+       size_t len;
+       char filename[256];
        struct stat statbuf;
 
        /*
@@ -335,7 +382,15 @@ static int fr_fault_check_permissions(void)
         *      quotes.
         */
        if ((q = strchr(panic_action, ' '))) {
-               (void) asprintf(&filename, "%.*s", (int)(q - panic_action), panic_action);
+               /*
+                *      need to use a static buffer, because mallocing memory in a signal handler
+                *      is a bad idea and can result in deadlock.
+                */
+               len = snprintf(filename, sizeof(filename), "%.*s", (int)(q - panic_action), panic_action);
+               if (is_truncated(len, sizeof(filename))) {
+                       fr_strerror_printf("Failed writing panic_action to temporary buffer (truncated)");
+                       return -1;
+               }
                p = filename;
        } else {
                p = panic_action;
@@ -350,8 +405,6 @@ static int fr_fault_check_permissions(void)
 #endif
        }
 
-       free(filename);
-
        return 0;
 }
 
@@ -370,13 +423,18 @@ void fr_fault(int sig)
 
        int code;
 
-       fr_fault_log("CAUGHT SIGNAL: %s\n", strsignal(sig));
+       /*
+        *      Makes the backtraces slightly cleaner
+        */
+       memset(cmd, 0, sizeof(cmd));
+
+       FR_FAULT_LOG("CAUGHT SIGNAL: %s", strsignal(sig));
 
        /*
         *      Check for administrator sanity.
         */
        if (fr_fault_check_permissions() < 0) {
-               fr_fault_log("Refusing to execute panic action: %s\n", fr_strerror());
+               FR_FAULT_LOG("Refusing to execute panic action: %s", fr_strerror());
                goto finish;
        }
 
@@ -388,8 +446,12 @@ void fr_fault(int sig)
        /*
         *      Produce a simple backtrace - They've very basic but at least give us an
         *      idea of the area of the code we hit the issue in.
+        *
+        *      See below in fr_fault_setup() and
+        *      https://sourceware.org/bugzilla/show_bug.cgi?id=16159
+        *      for why we only print backtraces in debug builds if we're using GLIBC.
         */
-#ifdef HAVE_EXECINFO
+#if defined(HAVE_EXECINFO) && (!defined(NDEBUG) || !defined(__GNUC__))
        {
                size_t frame_count, i;
                void *stack[MAX_BT_FRAMES];
@@ -397,18 +459,29 @@ void fr_fault(int sig)
 
                frame_count = backtrace(stack, MAX_BT_FRAMES);
 
-               fr_fault_log("Backtrace of last %zu frames:\n", frame_count);
-               strings = backtrace_symbols(stack, frame_count);
-               for (i = 0; i < frame_count; i++) {
-                       fr_fault_log("%s\n", strings[i]);
+               FR_FAULT_LOG("Backtrace of last %zu frames:", frame_count);
+
+               /*
+                *      Only use backtrace_symbols() if we don't have a logging fd.
+                *      If the server has experienced memory corruption, there's
+                *      a high probability that calling backtrace_symbols() which
+                *      mallocs more memory, will fail.
+                */
+               if (fr_fault_log_fd < 0) {
+                       strings = backtrace_symbols(stack, frame_count);
+                       for (i = 0; i < frame_count; i++) {
+                               FR_FAULT_LOG("%s", strings[i]);
+                       }
+                       free(strings);
+               } else {
+                       backtrace_symbols_fd(stack, frame_count, fr_fault_log_fd);
                }
-               free(strings);
        }
 #endif
 
        /* No panic action set... */
        if (panic_action[0] == '\0') {
-               fr_fault_log("No panic action set\n");
+               FR_FAULT_LOG("No panic action set");
                goto finish;
        }
 
@@ -417,7 +490,7 @@ void fr_fault(int sig)
                out += ret = snprintf(out, left, "%.*s%d", (int) (q - p), p, (int) getpid());
                if (left <= ret) {
                oob:
-                       fr_fault_log("Panic action too long");
+                       FR_FAULT_LOG("Panic action too long");
                        fr_exit_now(1);
                }
                left -= ret;
@@ -426,9 +499,43 @@ void fr_fault(int sig)
        if (strlen(p) >= left) goto oob;
        strlcpy(out, p, left);
 
-       fr_fault_log("Calling: %s\n", cmd);
-       code = system(cmd);
-       fr_fault_log("Panic action exited with %i\n", code);
+       FR_FAULT_LOG("Calling: %s", cmd);
+
+       {
+               bool disable = false;
+
+               /*
+                *      Here we temporarily enable the dumpable flag so if GBD or LLDB
+                *      is called in the panic_action, they can pattach tot he running
+                *      process.
+                */
+               if (fr_get_dumpable_flag() == 0) {
+                       if ((fr_set_dumpable_flag(true) < 0) || !fr_get_dumpable_flag()) {
+                               FR_FAULT_LOG("Failed setting dumpable flag, pattach may not work: %s", fr_strerror());
+                       } else {
+                               disable = true;
+                       }
+                       FR_FAULT_LOG("Temporarily setting PR_DUMPABLE to 1");
+               }
+
+               code = system(cmd);
+
+               /*
+                *      We only want to error out here, if dumpable was originally disabled
+                *      and we managed to change the value to enabled, but failed
+                *      setting it back to disabled.
+                */
+               if (disable) {
+                       FR_FAULT_LOG("Resetting PR_DUMPABLE to 0");
+                       if (fr_set_dumpable_flag(false) < 0) {
+                               FR_FAULT_LOG("Failed reseting dumpable flag to off: %s", fr_strerror());
+                               FR_FAULT_LOG("Exiting due to insecure process state");
+                               fr_exit_now(1);
+                       }
+               }
+       }
+
+       FR_FAULT_LOG("Panic action exited with %i", code);
 
 finish:
 #ifdef SIGUSR1
@@ -466,7 +573,6 @@ static void _fr_talloc_log(char const *msg)
 int fr_log_talloc_report(TALLOC_CTX *ctx)
 {
        FILE *log;
-       char const *null_ctx = NULL;
        int i = 0;
        int fd;
 
@@ -477,22 +583,27 @@ int fr_log_talloc_report(TALLOC_CTX *ctx)
        }
        log = fdopen(fd, "w");
        if (!log) {
+               close(fd);
                fr_strerror_printf("Couldn't write memory report, fdopen failed: %s", fr_syserror(errno));
                return -1;
        }
 
-       fprintf(log, "Current state of talloced memory:\n");
-       if (ctx) {
-               null_ctx = talloc_get_name(NULL);
-       }
-
        if (!ctx) {
-               talloc_report_full(NULL, log);
-       } else do {
-               fprintf(log, "Context level %i", i++);
-
-               talloc_report_full(ctx, log);
-       } while ((ctx = talloc_parent(ctx)) && (talloc_get_name(ctx) != null_ctx));  /* Stop before we hit NULL ctx */
+               fprintf(log, "Current state of talloced memory:\n");
+               talloc_report_full(talloc_null_ctx, log);
+       } else {
+               fprintf(log, "Talloc chunk lineage:\n");
+               fprintf(log, "%p (%s)", ctx, talloc_get_name(ctx));
+               while ((ctx = talloc_parent(ctx))) fprintf(log, " < %p (%s)", ctx, talloc_get_name(ctx));
+               fprintf(log, "\n");
+
+               do {
+                       fprintf(log, "Talloc context level %i:\n", i++);
+                       talloc_report_full(ctx, log);
+               } while ((ctx = talloc_parent(ctx)) &&
+                        (talloc_parent(ctx) != talloc_autofree_ctx) && /* Stop before we hit the autofree ctx */
+                        (talloc_parent(ctx) != talloc_null_ctx));      /* Stop before we hit NULL ctx */
+       }
 
        fclose(log);
 
@@ -510,6 +621,12 @@ static void _fr_fault_mem_report(int sig)
        if (fr_log_talloc_report(NULL) < 0) fr_perror("memreport");
 }
 
+static int _fr_disable_null_tracking(UNUSED bool *p)
+{
+       talloc_disable_null_tracking();
+       return 0;
+}
+
 /** Registers signal handlers to execute panic_action on fatal signal
  *
  * May be called multiple time to change the panic_action/program.
@@ -553,11 +670,6 @@ int fr_fault_setup(char const *cmd, char const *program)
         */
        if (fr_fault_check_permissions() < 0) return -1;
 
-       /*
-        *      This is required on some systems to be able to PATTACH to the process.
-        */
-       fr_set_dumpable_flag(true);
-
        /* Unsure what the side effects of changing the signal handler mid execution might be */
        if (!setup) {
 #ifdef SIGSEGV
@@ -595,7 +707,48 @@ int fr_fault_setup(char const *cmd, char const *program)
                /*
                 *  Needed for memory reports
                 */
-               talloc_enable_null_tracking();
+               {
+                       TALLOC_CTX *tmp;
+                       bool *marker;
+
+                       tmp = talloc(NULL, bool);
+                       talloc_null_ctx = talloc_parent(tmp);
+                       talloc_free(tmp);
+
+                       /*
+                        *  Disable null tracking on exit, else valgrind complains
+                        */
+                       talloc_autofree_ctx = talloc_autofree_context();
+                       marker = talloc(talloc_autofree_ctx, bool);
+                       talloc_set_destructor(marker, _fr_disable_null_tracking);
+               }
+
+#if defined(HAVE_MALLOPT) && !defined(NDEBUG)
+               /*
+                *  If were using glibc malloc > 2.4 this scribbles over
+                *  uninitialised and freed memory, to make memory issues easier
+                *  to track down.
+                */
+               if (!getenv("TALLOC_FREE_FILL")) mallopt(M_PERTURB, 0x42);
+               mallopt(M_CHECK_ACTION, 3);
+#endif
+
+#if defined(HAVE_EXECINFO) && defined(__GNUC__) && !defined(NDEBUG)
+              /*
+               *  We need to pre-load lgcc_s, else we can get into a deadlock
+               *  in fr_fault, as backtrace() attempts to dlopen it.
+               *
+               *  Apparently there's a performance impact of loading lgcc_s,
+               *  so only do it if this is a debug build.
+               *
+               *  See: https://sourceware.org/bugzilla/show_bug.cgi?id=16159
+               */
+               {
+                       void *stack[10];
+
+                       backtrace(stack, 10);
+               }
+#endif
        }
        setup = true;
 
@@ -649,8 +802,14 @@ void fr_fault_set_log_fd(int fd)
 /*
  *     Verify a VALUE_PAIR
  */
-inline void fr_verify_vp(VALUE_PAIR const *vp)
+inline void fr_verify_vp(char const *file, int line, VALUE_PAIR const *vp)
 {
+       if (!vp) {
+               fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR pointer was NULL", file, line);
+               fr_assert(0);
+               fr_exit_now(0);
+       }
+
        (void) talloc_get_type_abort(vp, VALUE_PAIR);
 
        if (vp->data.ptr) switch (vp->da->type) {
@@ -658,15 +817,28 @@ inline void fr_verify_vp(VALUE_PAIR const *vp)
        case PW_TYPE_TLV:
        {
                size_t len;
+               TALLOC_CTX *parent;
 
                if (!talloc_get_type(vp->data.ptr, uint8_t)) {
-                       fr_perror("Type check failed for attribute \"%s\"", vp->da->name);
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" data buffer type should be "
+                               "uint8_t but is %s\n", file, line, vp->da->name, talloc_get_name(vp->data.ptr));
                        (void) talloc_get_type_abort(vp->data.ptr, uint8_t);
                }
 
                len = talloc_array_length(vp->vp_octets);
-               if (vp->length != len) {
-                       fr_perror("VALUE_PAIR length %zu does not equal uint8_t buffer length %zu", vp->length, len);
+               if (vp->length > len) {
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" length %zu is greater than "
+                               "uint8_t data buffer length %zu\n", file, line, vp->da->name, vp->length, len);
+                       fr_assert(0);
+                       fr_exit_now(1);
+               }
+
+               parent = talloc_parent(vp->data.ptr);
+               if (parent != vp) {
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" char buffer is not "
+                               "parented by VALUE_PAIR %p, instead parented by %p (%s)\n",
+                               file, line, vp->da->name,
+                               vp, parent, parent ? talloc_get_name(parent) : "NULL");
                        fr_assert(0);
                        fr_exit_now(1);
                }
@@ -676,21 +848,35 @@ inline void fr_verify_vp(VALUE_PAIR const *vp)
        case PW_TYPE_STRING:
        {
                size_t len;
+               TALLOC_CTX *parent;
 
                if (!talloc_get_type(vp->data.ptr, char)) {
-                       fr_perror("Type check failed for attribute \"%s\"", vp->da->name);
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" data buffer type should be "
+                               "char but is %s\n", file, line, vp->da->name, talloc_get_name(vp->data.ptr));
                        (void) talloc_get_type_abort(vp->data.ptr, char);
                }
 
                len = (talloc_array_length(vp->vp_strvalue) - 1);
                if (vp->length > len) {
-                       fr_perror("VALUE_PAIR %s length %zu is too small for char buffer length %zu",
-                                 vp->da->name, vp->length, len);
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" length %zu is greater than "
+                               "char buffer length %zu\n", file, line, vp->da->name, vp->length, len);
                        fr_assert(0);
                        fr_exit_now(1);
                }
+
                if (vp->vp_strvalue[vp->length] != '\0') {
-                       fr_perror("VALUE_PAIR %s buffer not \\0 terminated", vp->da->name);
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" char buffer not \\0 "
+                               "terminated\n", file, line, vp->da->name);
+                       fr_assert(0);
+                       fr_exit_now(1);
+               }
+
+               parent = talloc_parent(vp->data.ptr);
+               if (parent != vp) {
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: VALUE_PAIR \"%s\" uint8_t buffer is not "
+                               "parented by VALUE_PAIR %p, instead parented by %p (%s)\n",
+                               file, line, vp->da->name,
+                               vp, parent, parent ? talloc_get_name(parent) : "NULL");
                        fr_assert(0);
                        fr_exit_now(1);
                }
@@ -705,7 +891,7 @@ inline void fr_verify_vp(VALUE_PAIR const *vp)
 /*
  *     Verify a pair list
  */
-void fr_verify_list(TALLOC_CTX *expected, VALUE_PAIR *vps)
+void fr_verify_list(char const *file, int line, TALLOC_CTX *expected, VALUE_PAIR *vps)
 {
        vp_cursor_t cursor;
        VALUE_PAIR *vp;
@@ -718,11 +904,11 @@ void fr_verify_list(TALLOC_CTX *expected, VALUE_PAIR *vps)
 
                parent = talloc_parent(vp);
                if (expected && (parent != expected)) {
-                       fr_perror("Expected VALUE_PAIR (%s) to be parented by %p (%s), "
-                                 "but parented by %p (%s)",
-                                 vp->da->name,
-                                 expected, talloc_get_name(expected),
-                                 parent, parent ? talloc_get_name(parent) : "NULL");
+                       fprintf(stderr, "CONSISTENCY CHECK FAILED %s[%u]: Expected VALUE_PAIR \"%s\" to be parented "
+                               "by %p (%s), instead parented by %p (%s)\n",
+                               file, line, vp->da->name,
+                               expected, talloc_get_name(expected),
+                               parent, parent ? talloc_get_name(parent) : "NULL");
 
                        fr_log_talloc_report(expected);
                        if (parent) fr_log_talloc_report(parent);