From 7d5549581259fe1f20b732038cb2275af64e5e5f Mon Sep 17 00:00:00 2001 From: pcarana Date: Fri, 3 Jul 2020 16:56:04 -0500 Subject: [PATCH] Fix bug: error'd repositories weren't logged if a child repo was synced +If a parent repository wasn't successfully synced (eg. LACNIC) but a child repository was synced (eg. Brazil), the errors related to the parent repository weren't logged to the operation log. +Fix this by poping the working repository from the TA, since this was causing the error. All the repositories were erroneously related, so on success of any of them, the error logs were discarded. +Two additional updates are done: don't rsync when forcing the download of an URI whose ancestor had a previous error, and remove line breaks from stale repositories summary. +Rename some local variables to aid dev reading. --- src/object/certificate.c | 24 ++++++++++---------- src/object/tal.c | 1 + src/reqs_errors.c | 26 +++++++++++++++++++++- src/reqs_errors.h | 3 +++ src/rsync/rsync.c | 47 ++++++++++++++++++++++++++++++++++++---- 5 files changed, 85 insertions(+), 16 deletions(-) diff --git a/src/object/certificate.c b/src/object/certificate.c index 5c297cd5..4175cfb5 100644 --- a/src/object/certificate.c +++ b/src/object/certificate.c @@ -1912,7 +1912,7 @@ exec_rsync_method(struct sia_ca_uris *sia_uris) static int use_access_method(struct sia_ca_uris *sia_uris, access_method_exec rsync_cb, access_method_exec rrdp_cb, - bool *rsync_utilized) + bool *retry_repo_sync) { access_method_exec *cb_primary; access_method_exec *cb_secondary; @@ -1925,7 +1925,7 @@ use_access_method(struct sia_ca_uris *sia_uris, * rfc6487#section-4.8.8.1). If rsync is disabled, the cb will take * care of that. */ - (*rsync_utilized) = true; + (*retry_repo_sync) = true; if (sia_uris->rpkiNotify.uri == NULL || !config_get_rrdp_enabled()) { error = rsync_cb(sia_uris); goto verify_mft; @@ -1933,7 +1933,7 @@ use_access_method(struct sia_ca_uris *sia_uris, /* RSYNC disabled, and RRDP is present, use it */ if (!config_get_rsync_enabled()) { - (*rsync_utilized) = false; + (*retry_repo_sync) = false; error = rrdp_cb(sia_uris); goto verify_mft; } @@ -1955,7 +1955,7 @@ use_access_method(struct sia_ca_uris *sia_uris, error = db_rrdp_uris_get_request_status( uri_get_global(sia_uris->rpkiNotify.uri), &rrdp_req_status); if (error == 0 && rrdp_req_status == RRDP_URI_REQ_VISITED) { - (*rsync_utilized) = false; + (*retry_repo_sync) = false; return 0; } @@ -1973,7 +1973,7 @@ use_access_method(struct sia_ca_uris *sia_uris, /* Try with the preferred; in case of error, try with the next one */ error = cb_primary(sia_uris); if (!error) { - (*rsync_utilized) = !primary_rrdp; + (*retry_repo_sync) = !primary_rrdp; goto verify_mft; } @@ -1994,7 +1994,7 @@ use_access_method(struct sia_ca_uris *sia_uris, uri_get_global(sia_uris->rpkiNotify.uri)); } - (*rsync_utilized) = primary_rrdp; + (*retry_repo_sync) = primary_rrdp; error = cb_secondary(sia_uris); /* No need to remember the working repository anymore */ working_repo_pop(); @@ -2009,12 +2009,14 @@ use_access_method(struct sia_ca_uris *sia_uris, case EREQFAILED: /* Log that we'll try to work with a local copy */ pr_val_warn("Trying to work with the local cache files."); + (*retry_repo_sync) = false; break; case -EPERM: /* * Specific RRPD error: the URI error'd on the first try, so * we'll keep trying with the local files */ + (*retry_repo_sync) = false; break; default: return error; @@ -2136,7 +2138,7 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) enum rpki_policy policy; enum cert_type type; struct rpp *pp; - bool mft_retry; + bool repo_retry; int error; state = state_retrieve(); @@ -2245,9 +2247,9 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) * * Avoid to re-download the repo if the mft was fetched with RRDP. */ - mft_retry = true; + repo_retry = true; error = use_access_method(&sia_uris, exec_rsync_method, - exec_rrdp_method, &mft_retry); + exec_rrdp_method, &repo_retry); if (error) goto revert_uris; @@ -2261,7 +2263,7 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) cert = NULL; /* Ownership stolen */ error = handle_manifest(sia_uris.mft.uri, &pp); - if (error == 0 || !mft_retry) + if (error == 0 || !repo_retry) break; /* @@ -2283,7 +2285,7 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) if (error) goto revert_uris; - mft_retry = false; + repo_retry = false; } while (true); if (error) { diff --git a/src/object/tal.c b/src/object/tal.c index a94c1f2d..2c940d68 100644 --- a/src/object/tal.c +++ b/src/object/tal.c @@ -532,6 +532,7 @@ handle_tal_uri(struct tal *tal, struct rpki_uri *uri, void *arg) thread_arg->retry_local = false; if (thread_arg->sync_files && working_repo_peek() != NULL) reqs_errors_rem_uri(working_repo_peek()); + working_repo_pop(); pr_val_debug("TAL URI '%s' {", uri_val_get_printable(uri)); diff --git a/src/reqs_errors.c b/src/reqs_errors.c index f734f1d8..73df8194 100644 --- a/src/reqs_errors.c +++ b/src/reqs_errors.c @@ -203,6 +203,25 @@ reqs_errors_rem_uri(char const *uri) rwlock_unlock(&db_lock); } +int +reqs_errors_foreach(reqs_errors_cb cb, void *arg) +{ + struct error_uri *node, *tmp; + int error; + + rwlock_read_lock(&db_lock); + HASH_ITER(hh, err_uris_db, node, tmp) { + error = cb(node->uri, arg); + if (error) { + rwlock_unlock(&db_lock); + return error; + } + } + rwlock_unlock(&db_lock); + + return 0; +} + bool reqs_errors_log_uri(char const *uri) { @@ -246,6 +265,7 @@ reqs_errors_log_summary(void) /* Remove all the uris */ struct error_uri *node, *tmp; time_t now; + char *str_time; bool first; int error; @@ -263,8 +283,12 @@ reqs_errors_log_summary(void) pr_op_warn("The following repositories URIs couldn't be fetched (it can be a local issue or a server issue), please review previous log messages related to such URIs/servers:"); first = false; } + str_time = asctime(localtime(&node->first_attempt)); + if (strrchr(str_time, '\n') != NULL) { + *(str_time + strlen(str_time) - 1) = ' '; + } pr_op_warn("- '%s': can't be downloaded since %s", node->uri, - asctime(localtime(&node->first_attempt))); + str_time); } rwlock_unlock(&db_lock); diff --git a/src/reqs_errors.h b/src/reqs_errors.h index a7ec970d..b13e3285 100644 --- a/src/reqs_errors.h +++ b/src/reqs_errors.h @@ -11,6 +11,9 @@ void reqs_errors_rem_uri(char const *); bool reqs_errors_log_uri(char const *); +typedef int (reqs_errors_cb)(char const *, void *); +int reqs_errors_foreach(reqs_errors_cb, void *); + void reqs_errors_log_summary(void); #endif /* SRC_REQS_ERRORS_H_ */ diff --git a/src/rsync/rsync.c b/src/rsync/rsync.c index 1b1aef88..24e14c17 100644 --- a/src/rsync/rsync.c +++ b/src/rsync/rsync.c @@ -446,10 +446,9 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation) /* Happy path (but also sad path sometimes). */ error = WEXITSTATUS(child_status); pr_val_debug("Child terminated with error code %d.", error); - if (!error) { - reqs_errors_rem_uri(uri_get_global(uri)); + if (!error) goto release_args; - } + if (retries == config_get_rsync_retry_count()) { pr_val_warn("Max RSYNC retries (%u) reached on '%s', won't retry again.", retries, uri_get_global(uri)); @@ -496,6 +495,37 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation) return error; } +/* + * Returned values if the ancestor URI of @error_uri: + * 0 - didn't had a previous request error + * EEXIST - had a previous request error + * > 0 - nothing, just something bad happened + */ +static int +ancestor_error(char const *error_uri, void *arg) +{ + struct rpki_uri *search = arg; + struct rpki_uri *req_err_uri; + int error; + + req_err_uri = NULL; + error = uri_create_rsync_str(&req_err_uri, error_uri, + strlen(error_uri)); + switch(error) { + case 0: + break; + case ENOTRSYNC: + return 0; + default: + return ENSURE_NEGATIVE(error); + } + + error = is_descendant(req_err_uri, search) ? EEXIST : 0; + + free(req_err_uri); + return error; +} + /** * @is_ta: Are we rsync'ing the TA? * The TA rsync will not be recursive, and will force SYNC_STRICT @@ -535,8 +565,16 @@ download_files(struct rpki_uri *requested_uri, bool is_ta, bool force) if (!force) error = get_rsync_uri(requested_uri, is_ta, &rsync_uri); - else + else { + /* Validate if the ancestor URI error'd */ + error = reqs_errors_foreach(ancestor_error, requested_uri); + if (error < 0) + return error; + /* Return the requests error'd code */ + if (error == EEXIST) + return EREQFAILED; error = handle_strict_strategy(requested_uri, &rsync_uri); + } if (error) return error; @@ -550,6 +588,7 @@ download_files(struct rpki_uri *requested_uri, bool is_ta, bool force) /* Don't store when "force" and if its already downloaded */ if (!(force && is_already_downloaded(rsync_uri, visited_uris))) error = mark_as_downloaded(rsync_uri, visited_uris); + reqs_errors_rem_uri(uri_get_global(requested_uri)); break; case EREQFAILED: /* All attempts failed, avoid future requests */