From: Alberto Leiva Popper <ydahhrk@gmail.com>
Date: Fri, 28 May 2021 00:51:23 +0000 (-0500)
Subject: Scatter lots of debugging messages near the bug
X-Git-Tag: v1.5.1~20
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=92c3cf85b091cea05a6edaffc0aeb96f2c77d881;p=thirdparty%2FFORT-validator.git

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 b52ad6ba..21f0c7b4 100644
--- 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 2bc6ba04..e2094463 100644
--- 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 e3c04380..1d11af3a 100644
--- 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 1efb9d7d..b527da04 100644
--- 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;
 }