From: pcarana Date: Mon, 18 May 2020 22:54:42 +0000 (-0500) Subject: Log only communication errors on first level RPKI servers X-Git-Tag: v1.3.0~19 X-Git-Url: http://git.ipfire.org/gitweb/gitweb.cgi?a=commitdiff_plain;h=0277abac44303485dce53664de7dec41304ab580;p=thirdparty%2FFORT-validator.git Log only communication errors on first level RPKI servers --- diff --git a/src/cert_stack.c b/src/cert_stack.c index 724dc09e..a9198a46 100644 --- a/src/cert_stack.c +++ b/src/cert_stack.c @@ -62,6 +62,18 @@ struct metadata_node { SLIST_HEAD(metadata_stack, metadata_node); +/** + * Certificate repository "level". This aims to identify if the + * certificate is located at a distinct server than its father (common + * case when the RIRs delegate RPKI repositories). + */ +struct repo_level_node { + unsigned int level; + SLIST_ENTRY(repo_level_node) next; +}; + +SLIST_HEAD(repo_level_stack, repo_level_node); + /** * This is the foundation through which we pull off our iterative traversal, * as opposed to a stack-threatening recursive one. @@ -97,6 +109,12 @@ struct cert_stack { * seemingly not intended to be used outside of its library.) */ struct metadata_stack metas; + + /** + * Stacked data to store the repository "levels" (each level is a + * delegation of an RPKI server). + */ + struct repo_level_stack levels; }; int @@ -116,6 +134,7 @@ certstack_create(struct cert_stack **result) SLIST_INIT(&stack->defers); SLIST_INIT(&stack->metas); + SLIST_INIT(&stack->levels); *result = stack; return 0; @@ -166,6 +185,7 @@ certstack_destroy(struct cert_stack *stack) unsigned int stack_size; struct metadata_node *meta; struct defer_node *post; + struct repo_level_node *level; stack_size = 0; while (!SLIST_EMPTY(&stack->defers)) { @@ -188,6 +208,15 @@ certstack_destroy(struct cert_stack *stack) } pr_debug("Deleted %u metadatas.", stack_size); + stack_size = 0; + while (!SLIST_EMPTY(&stack->levels)) { + level = SLIST_FIRST(&stack->levels); + SLIST_REMOVE_HEAD(&stack->levels, next); + free(level); + stack_size++; + } + pr_debug("Deleted %u stacked levels.", stack_size); + free(stack); } @@ -213,6 +242,7 @@ x509stack_pop(struct cert_stack *stack) { X509 *cert; struct metadata_node *meta; + struct repo_level_node *repo; cert = sk_X509_pop(stack->x509s); if (cert == NULL) @@ -224,6 +254,12 @@ x509stack_pop(struct cert_stack *stack) pr_crit("Attempted to pop empty metadata stack"); SLIST_REMOVE_HEAD(&stack->metas, next); meta_destroy(meta); + + repo = SLIST_FIRST(&stack->levels); + if (repo == NULL) + pr_crit("Attempted to pop empty repo level stack"); + SLIST_REMOVE_HEAD(&stack->levels, next); + free(repo); } /** @@ -267,14 +303,30 @@ x509stack_push(struct cert_stack *stack, struct rpki_uri *uri, X509 *x509, enum rpki_policy policy, enum cert_type type) { struct metadata_node *meta; + struct repo_level_node *repo, *head_repo; struct defer_node *defer_separator; + unsigned int work_repo_level; int ok; int error; - meta = malloc(sizeof(struct metadata_node)); - if (meta == NULL) + repo = malloc(sizeof(struct repo_level_node)); + if (repo == NULL) return pr_enomem(); + repo->level = 0; + work_repo_level = working_repo_peek_level(); + head_repo = SLIST_FIRST(&stack->levels); + if (head_repo != NULL && work_repo_level > head_repo->level) + repo->level = work_repo_level; + + SLIST_INSERT_HEAD(&stack->levels, repo, next); + + meta = malloc(sizeof(struct metadata_node)); + if (meta == NULL) { + error = pr_enomem(); + goto end3; + } + meta->uri = uri; uri_refget(uri); serial_numbers_init(&meta->serials); @@ -326,6 +378,7 @@ end4: subjects_cleanup(&meta->subjects, subject_cleanup); serial_numbers_cleanup(&meta->serials, serial_cleanup); uri_refput(meta->uri); free(meta); +end3: free(repo); return error; } @@ -333,7 +386,7 @@ end4: subjects_cleanup(&meta->subjects, subject_cleanup); * This one is intended to revert a recent x509 push. * Reverts that particular push. * - * (x509 stack elements are otherwise indirecly popped through + * (x509 stack elements are otherwise indirectly popped through * deferstack_pop().) */ void @@ -371,6 +424,13 @@ x509stack_peek_resources(struct cert_stack *stack) return (meta != NULL) ? meta->resources : NULL; } +unsigned int +x509stack_peek_level(struct cert_stack *stack) +{ + struct repo_level_node *repo = SLIST_FIRST(&stack->levels); + return (repo != NULL) ? repo->level : 0; +} + static int get_current_file_name(char **_result) { diff --git a/src/cert_stack.h b/src/cert_stack.h index 6c64783c..631573ae 100644 --- a/src/cert_stack.h +++ b/src/cert_stack.h @@ -2,6 +2,7 @@ #define SRC_CERT_STACK_H_ #include +#include #include "resource.h" #include "uri.h" #include "object/certificate.h" @@ -47,6 +48,7 @@ void x509stack_cancel(struct cert_stack *); X509 *x509stack_peek(struct cert_stack *); struct rpki_uri *x509stack_peek_uri(struct cert_stack *); struct resources *x509stack_peek_resources(struct cert_stack *); +unsigned int x509stack_peek_level(struct cert_stack *); int x509stack_store_serial(struct cert_stack *, BIGNUM *); typedef int (*subject_pk_check_cb)(bool *, char const *, void *); int x509stack_store_subject(struct cert_stack *, struct rfc5280_name *, diff --git a/src/http/http.c b/src/http/http.c index 9f15a8b7..919d236e 100644 --- a/src/http/http.c +++ b/src/http/http.c @@ -143,12 +143,12 @@ http_fetch(struct http_handler *handler, char const *uri, long *response_code, return pr_err("Error requesting URL %s (received HTTP code %ld): %s", uri, *response_code, curl_err_string(handler, res)); - /* FIXME (NOW) Always log to validation log */ - pr_err("[VALIDATION] Error requesting URL %s: %s", uri, + /* FIXME (NOW) Always log this to validation log */ + pr_err("Error requesting URL %s: %s", uri, curl_err_string(handler, res)); /* FIXME (NOW) and send to operation log when requested */ if (log_operation) - pr_err("[OPERATION] Error requesting URL %s: %s", uri, + pr_err("Error requesting URL %s: %s", uri, curl_err_string(handler, res)); return EREQFAILED; diff --git a/src/object/certificate.c b/src/object/certificate.c index 35a79771..24ec82ba 100644 --- a/src/object/certificate.c +++ b/src/object/certificate.c @@ -2009,6 +2009,102 @@ use_access_method(struct sia_ca_uris *sia_uris, return error; } +/* + * Get the rsync server part from an rsync URI. + * + * If the URI is: + * rsync:/// + * This will return: + * rsync:// + */ +static int +get_rsync_server_uri(struct rpki_uri *src, char **result, size_t *result_len) +{ + char const *global; + char *tmp; + size_t global_len; + unsigned int slashes; + size_t i; + + global = uri_get_global(src); + global_len = uri_get_global_len(src); + slashes = 0; + + for (i = 0; i < global_len; i++) { + if (global[i] == '/') { + slashes++; + if (slashes == 3) + break; + } + } + + tmp = malloc(i + 1); + if (tmp == NULL) + return pr_enomem(); + + strncpy(tmp, global, i); + tmp[i] = '\0'; + + *result_len = i; + *result = tmp; + + return 0; +} + +static int +set_repository_level(bool is_ta, struct validation *state, + struct rpki_uri *cert_uri, struct sia_ca_uris *sia_uris) +{ + char *parent_server, *current_server; + size_t parent_server_len, current_server_len; + unsigned int new_level; + bool update; + int error; + + new_level = 0; + if (is_ta || cert_uri == NULL) { + working_repo_push_level(new_level); + return 0; + } + + /* Warning killer */ + parent_server = NULL; + current_server = NULL; + parent_server_len = 0; + current_server_len = 0; + + /* Both are rsync URIs, check the server part */ + error = get_rsync_server_uri(cert_uri, &parent_server, + &parent_server_len); + if (error) + return error; + + error = get_rsync_server_uri(sia_uris->caRepository.uri, + ¤t_server, ¤t_server_len); + if (error) { + free(parent_server); + return error; + } + + if (parent_server_len != current_server_len) { + update = true; + goto end; + } + + update = (strcmp(parent_server, current_server) != 0); +end: + new_level = x509stack_peek_level(validation_certstack(state)); + if (update) + new_level++; + + working_repo_push_level(new_level); + + free(parent_server); + free(current_server); + + return 0; +} + /** Boilerplate code for CA certificate validation and recursive traversal. */ int certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) @@ -2119,6 +2215,11 @@ certificate_traverse(struct rpp *rpp_parent, struct rpki_uri *cert_uri) goto revert_refs; } + /* Identify if this is a new repository before fetching it */ + error = set_repository_level(IS_TA, state, cert_uri, &sia_uris); + if (error) + goto revert_uris; + /* * RFC 6481 section 5: "when the repository publication point contents * are updated, a repository operator cannot assure RPs that the diff --git a/src/reqs_errors.c b/src/reqs_errors.c index 42b2f4bd..ace84a3f 100644 --- a/src/reqs_errors.c +++ b/src/reqs_errors.c @@ -8,6 +8,22 @@ #include "log.h" #include "thread_var.h" +/* + * Only log messages of repositories whose level is less than or equal to this. + * + * Level 0 is "top level", mostly used by the root CAs (trust anchors) and RIRs + * before RPKI servers delegation. + * + * Eg. The URIs will have this level (data according to current RPKI state): + * rsync://repository.lacnic.net/ [level 0] + * rsync://rpki-repo.registro.br/ [level 1] + * + * rsync://rpki.ripe.net/ [level 0] + * rsync://ca.rg.net/ [level 1] + * rsync://cc.rg.net/ [level 2] + */ +#define LOG_REPO_LEVEL 0 + struct error_uri { /* Key */ char *uri; @@ -15,6 +31,10 @@ struct error_uri { time_t first_attempt; /* Related URI (points to a key of another element) */ char *uri_related; + /* Refered by (where this.uri == that.uri_related) */ + char *ref_by; + /* Log the summary */ + bool log_summary; UT_hash_handle hh; }; @@ -46,6 +66,10 @@ error_uri_create(char const *uri, struct error_uri **err_uri) if (error) goto release_uri; + tmp->log_summary = false; + tmp->uri_related = NULL; + tmp->ref_by = NULL; + *err_uri = tmp; return 0; release_uri: @@ -108,7 +132,6 @@ set_working_repo(struct error_uri *err_uri) struct error_uri *ref; char const *work_uri; - err_uri->uri_related = NULL; work_uri = working_repo_peek(); if (work_uri == NULL) return; @@ -118,6 +141,7 @@ set_working_repo(struct error_uri *err_uri) return; err_uri->uri_related = ref->uri; + ref->ref_by = err_uri->uri; } int @@ -138,6 +162,14 @@ reqs_errors_add_uri(char const *uri) set_working_repo(new_uri); + /* + * Check if this will always be logged, in that case the summary will + * be logged also if the level must be logged. + */ + if (config_get_stale_repository_period() == 0) + new_uri->log_summary = + (working_repo_peek_level() <= LOG_REPO_LEVEL); + rwlock_write_lock(&db_lock); HASH_ADD_KEYPTR(hh, err_uris_db, new_uri->uri, strlen(new_uri->uri), new_uri); @@ -150,18 +182,24 @@ void reqs_errors_rem_uri(char const *uri) { struct error_uri *found_uri; + char *ref_uri; found_uri = find_error_uri(uri); if (found_uri == NULL) return; - /* Remove also its related repository */ - if (found_uri->uri_related != NULL) - reqs_errors_rem_uri(found_uri->uri_related); + while (found_uri->uri_related != NULL) + found_uri = find_error_uri(uri); rwlock_write_lock(&db_lock); - HASH_DELETE(hh, err_uris_db, found_uri); - error_uri_destroy(found_uri); + do { + ref_uri = found_uri->ref_by; + HASH_DELETE(hh, err_uris_db, found_uri); + error_uri_destroy(found_uri); + if (ref_uri == NULL) + break; + HASH_FIND_STR(err_uris_db, ref_uri, found_uri); + } while (true); rwlock_unlock(&db_lock); } @@ -170,23 +208,34 @@ reqs_errors_log_uri(char const *uri) { struct error_uri *node; time_t now; + unsigned int config_period; int error; - now = 0; - error = get_current_time(&now); - if (error) + if (working_repo_peek_level() > LOG_REPO_LEVEL) return false; + /* Log always? Don't care if the URI exists yet or not */ + config_period = config_get_stale_repository_period(); + if (config_period == 0) + return true; + node = find_error_uri(uri); if (node == NULL) return false; - return difftime(now, node->first_attempt) >= - (double)config_get_stale_repository_period(); + now = 0; + error = get_current_time(&now); + if (error) + return false; + + node->log_summary = (difftime(now, node->first_attempt) >= + (double)config_period); + + return node->log_summary; } /* - * Logs the repository errors and return the number of current errors. + * Log a summary of the error'd servers. */ void reqs_errors_log_summary(void) @@ -203,15 +252,9 @@ reqs_errors_log_summary(void) if (error) return; - /* - * FIXME (NOW) Log a friendly warning, listing the URIs that error'd. - * The time diff (difftime) must be from the same date when - * reqs_errors_log_uri was called. - */ rwlock_read_lock(&db_lock); HASH_ITER(hh, err_uris_db, node, tmp) { - if (difftime(now, node->first_attempt) < - (double)config_get_stale_repository_period()) + if (!node->log_summary) continue; if (first) { /* FIXME (NOW) Send to operation log */ diff --git a/src/rrdp/rrdp_loader.c b/src/rrdp/rrdp_loader.c index e5ae490d..8ea25f50 100644 --- a/src/rrdp/rrdp_loader.c +++ b/src/rrdp/rrdp_loader.c @@ -220,10 +220,11 @@ upd_end: upd_error = reqs_errors_add_uri(uri_get_global(uri)); if (upd_error) return upd_error; + } else { + /* Reset RSYNC visited URIs, this may force the update */ + reset_downloaded(); } - /* Reset RSYNC visited URIs, this may force the update */ - reset_downloaded(); upd_error = mark_rrdp_uri_request_err(uri_get_global(uri)); if (upd_error) return upd_error; diff --git a/src/rsync/rsync.c b/src/rsync/rsync.c index 52c94481..e2b47454 100644 --- a/src/rsync/rsync.c +++ b/src/rsync/rsync.c @@ -276,15 +276,15 @@ log_buffer(char const *buffer, ssize_t read, int type, bool log_operation) if (type == 0) { /* FIXME (NOW) Send to operation log if requested */ if (log_operation) - pr_err(PRE_RSYNC " [OPERATION]: %s", cur); - /* FIXME (NOW) Always send to validation log */ - pr_err(PRE_RSYNC " [VALIDATION]: %s", cur); + pr_err(PRE_RSYNC "%s", cur); + /* FIXME (NOW) Always send this to validation log */ + pr_err(PRE_RSYNC "%s", cur); } else { /* FIXME (NOW) Send to operation log if requested */ if (log_operation) - pr_info(PRE_RSYNC " [OPERATION]: %s", cur); - /* FIXME (NOW) Always send to validation log */ - pr_info(PRE_RSYNC " [VALIDATION]: %s", cur); + pr_info(PRE_RSYNC "%s", cur); + /* FIXME (NOW) Always send this to validation log */ + pr_info(PRE_RSYNC "%s", cur); } cur = tmp + 1; } diff --git a/src/thread_var.c b/src/thread_var.c index e1f18a90..85875fd1 100644 --- a/src/thread_var.c +++ b/src/thread_var.c @@ -23,6 +23,7 @@ struct filename_stack { struct working_repo { char const *uri; + unsigned int level; }; static void @@ -229,6 +230,7 @@ working_repo_init(void) return; repo->uri = NULL; + repo->level = 0; error = pthread_setspecific(repository_key, repo); if (error) @@ -268,6 +270,24 @@ working_repo_push(char const *location) repo->uri = location; } +/* + * Set the current repository level, must be called before trying to fetch the + * repository. + * + * The level "calculation" must be done by the caller. + */ +void +working_repo_push_level(unsigned int level) +{ + struct working_repo *repo; + + repo = pthread_getspecific(repository_key); + if (repo == NULL) + return; + + repo->level = level; +} + char const * working_repo_peek(void) { @@ -278,6 +298,16 @@ working_repo_peek(void) return repo == NULL ? NULL : repo->uri; } +unsigned int +working_repo_peek_level(void) +{ + struct working_repo *repo; + + repo = pthread_getspecific(repository_key); + + return repo->level; +} + /* * Call once the certificate's repositories were downloaded (either successful * or erroneously). @@ -292,6 +322,7 @@ working_repo_pop(void) return; repo->uri = NULL; + repo->level = 0; } static char const * diff --git a/src/thread_var.h b/src/thread_var.h index 0c19e2ca..dff85381 100644 --- a/src/thread_var.h +++ b/src/thread_var.h @@ -20,7 +20,9 @@ void working_repo_init(void); void working_repo_cleanup(void); void working_repo_push(char const *); +void working_repo_push_level(unsigned int); char const *working_repo_peek(void); +unsigned int working_repo_peek_level(void); void working_repo_pop(void); /* Please remember that these functions can only be used during validations. */