Scatter lots of debugging messages near the bug

Wasted too much time looking for the stack trace, and still got
nothing. It's time for some old-fashioned college style debugging.

diff --git a/src/log.c b/src/log.c
index b52ad6ba82b9fdfe4a334dd7ee5aabc50045757a..21f0c7b4447bb7e0f756d4aed0a64d97540c5bb3 100644 (file)
--- a/src/log.c
+++ b/src/log.c
@@ -135,9 +135,9 @@ log_setup(void)
 
        DBG.stream = stdout;
        INF.stream = stdout;
-       WRN.stream = stderr;
-       ERR.stream = stderr;
-       CRT.stream = stderr;
+       WRN.stream = stdout;
+       ERR.stream = stdout;
+       CRT.stream = stdout;
        UNK.stream = stdout;
 
        openlog("fort", LOG_CONS | LOG_PID, LOG_DAEMON);

diff --git a/src/object/tal.c b/src/object/tal.c
index 2bc6ba049220a57c62391299b8042b36fc89c110..e209446392629f5a56d4d861d744ef8a42425a5d 100644 (file)
--- a/src/object/tal.c
+++ b/src/object/tal.c
@@ -519,24 +519,36 @@ handle_tal_uri(struct tal *tal, struct rpki_uri *uri, void *arg)
        struct deferred_cert deferred;
        int error;
 
+       PR_DEBUG;
+
        validation_handler.handle_roa_v4 = handle_roa_v4;
        validation_handler.handle_roa_v6 = handle_roa_v6;
        validation_handler.handle_router_key = handle_router_key;
        validation_handler.arg = thread_arg->arg;
 
+       PR_DEBUG;
+
        error = validation_prepare(&state, tal, &validation_handler);
-       if (error)
+       if (error) {
+               PR_DEBUG_MSG("%d", error);
                return ENSURE_NEGATIVE(error);
+       }
+
+       PR_DEBUG;
 
        if (thread_arg->sync_files) {
+               PR_DEBUG;
+
                if (uri_is_rsync(uri)) {
                        if (!config_get_rsync_enabled()) {
+                               PR_DEBUG;
                                validation_destroy(state);
                                return 0; /* Try some other TAL URI */
                        }
                        error = rsync_download_files(uri, true, false);
                } else /* HTTPS */ {
                        if (!config_get_http_enabled()) {
+                               PR_DEBUG;
                                validation_destroy(state);
                                return 0; /* Try some other TAL URI */
                        }
@@ -544,21 +556,33 @@ handle_tal_uri(struct tal *tal, struct rpki_uri *uri, void *arg)
                            reqs_errors_log_uri(uri_get_global(uri)));
                }
 
+               PR_DEBUG;
+
                /* Reminder: there's a positive error: EREQFAILED */
                if (error) {
+                       PR_DEBUG_MSG("%d", error);
+
                        working_repo_push(uri_get_global(uri));
                        validation_destroy(state);
                        return pr_val_warn(
                            "TAL URI '%s' could not be downloaded.",
                            uri_val_get_printable(uri));
                }
+
+               PR_DEBUG;
+
        } else {
+               PR_DEBUG;
+
                /* Look for local files */
                if (!valid_file_or_dir(uri_get_local(uri), true, false,
                    __pr_val_err)) {
+                       PR_DEBUG;
                        validation_destroy(state);
                        return 0; /* Error already logged */
                }
+
+               PR_DEBUG;
        }
 
        /* At least one URI was sync'd */
@@ -640,6 +664,8 @@ __handle_tal_uri_sync(struct tal *tal, struct rpki_uri *uri, void *arg)
 {
        int error;
 
+       PR_DEBUG;
+
        error = handle_tal_uri(tal, uri, arg);
        if (error)
                return error;
@@ -661,25 +687,40 @@ do_file_validation(void *thread_arg)
        struct tal *tal;
        int error;
 
+       PR_DEBUG;
+
        fnstack_init();
        fnstack_push(thread->tal_file);
 
+       PR_DEBUG;
+
        working_repo_init();
 
+       PR_DEBUG;
+
        error = tal_load(thread->tal_file, &tal);
        if (error)
                goto end;
 
+       PR_DEBUG;
+
        error = tal_order_uris(tal);
        if (error)
                goto destroy_tal;
 
+       PR_DEBUG;
+
        error = foreach_uri(tal, __handle_tal_uri_sync, thread_arg);
        if (error > 0) {
+               PR_DEBUG_MSG("error: %d", error);
                error = 0;
                goto destroy_tal;
-       } else if (error < 0)
+       } else if (error < 0) {
+               PR_DEBUG_MSG("error: %d", error);
                goto destroy_tal;
+       }
+
+       PR_DEBUG;
 
        if (!thread->retry_local) {
                error = pr_op_err("None of the URIs of the TAL '%s' yielded a successful traversal.",

diff --git a/src/thread/thread_pool.c b/src/thread/thread_pool.c
index e3c04380f025b04a337171a2dd48ec1328a873aa..1d11af3ac971c7cacdb5505a34dcd1ecebd76f5a 100644 (file)
--- a/src/thread/thread_pool.c
+++ b/src/thread/thread_pool.c
@@ -215,6 +215,7 @@ tasks_poll(void *arg)
                mutex_unlock(pool);
 
                if (task != NULL) {
+                       PR_DEBUG;
                        task->cb(task->arg);
                        pr_op_debug("Thread %s.%u: Task '%s' ended", pool->name,
                            thread_id, task->name);

diff --git a/src/validation_run.c b/src/validation_run.c
index 1efb9d7d4fd85551fbc02b651d9760af2bcde813..b527da042dc5aab476e8df5acc1eef0dc701546d 100644 (file)
--- a/src/validation_run.c
+++ b/src/validation_run.c
@@ -18,7 +18,7 @@ validation_run_first(void)
        if (config_get_mode() == SERVER)
                pr_op_warn("First validation cycle has begun, wait until the next notification to connect your router(s)");
        else
-               pr_op_info("The validation has begun.");
+               pr_op_warn("The validation has begun.");
 
        error = vrps_update(NULL);
        if (error)
@@ -27,7 +27,7 @@ validation_run_first(void)
        if (config_get_mode() == SERVER)
                pr_op_warn("First validation cycle successfully ended, now you can connect your router(s)");
        else
-               pr_op_info("The validation has successfully ended.");
+               pr_op_warn("The validation has successfully ended.");
 
        return 0;
 }