From: pcarana Date: Tue, 15 Oct 2019 20:04:32 +0000 (-0500) Subject: Log additional information on start/end of validation cycle. X-Git-Tag: v1.2.0~69 X-Git-Url: http://git.ipfire.org/gitweb/gitweb.cgi?a=commitdiff_plain;h=90e17f1a9f5e2e36c576cdb4e2fe38a0a80d9907;p=thirdparty%2FFORT-validator.git Log additional information on start/end of validation cycle. +The information is printed at INFO level: - When a client starts/ends a connection, or when the connection is killed (print its address and an internal ID). - When a new validation cycle is started and finished (includes number of valid ROAs and Router Keys, current/new serial number, and real execution time). +Update function 'log_debug_enabled' and add 'log_info_enabled' function. +Add functions to get total ROAs and Router Keys from db_table struct. --- diff --git a/src/clients.h b/src/clients.h index 1a883155..18e00dd8 100644 --- a/src/clients.h +++ b/src/clients.h @@ -28,7 +28,7 @@ int clients_db_init(void); int clients_add(int, struct sockaddr_storage, pthread_t); void clients_update_serial(int, serial_t); void clients_forget(int); -typedef int (*clients_foreach_cb)(struct client const *, void *); +typedef int (*clients_foreach_cb)(struct client *, void *); int clients_foreach(clients_foreach_cb, void *); int clients_get_min_serial(serial_t *); int clients_get_addr(int, struct sockaddr_storage *); diff --git a/src/log.c b/src/log.c index ad87d2de..9a5a2144 100644 --- a/src/log.c +++ b/src/log.c @@ -188,7 +188,13 @@ pr_stream(int level, const char *format, va_list args) bool log_debug_enabled(void) { - return config_get_log_level() == LOG_DEBUG; + return config_get_log_level() >= LOG_DEBUG; +} + +bool +log_info_enabled(void) +{ + return config_get_log_level() >= LOG_INFO; } void diff --git a/src/log.h b/src/log.h index e490e087..75c5b675 100644 --- a/src/log.h +++ b/src/log.h @@ -49,8 +49,11 @@ void log_teardown(void); * error stack) cannot exceed 512 bytes at present. */ -/* Check if debug is enabled, useful to avoid boilerplate code */ +/* + * Check if debug or info are enabled, useful to avoid boilerplate code + */ bool log_debug_enabled(void); +bool log_info_enabled(void); /* Debug messages, useful for devs or to track a specific problem */ void pr_debug(const char *, ...) CHECK_FORMAT(1, 2); diff --git a/src/notify.c b/src/notify.c index 7d54ade3..c9f79fbe 100644 --- a/src/notify.c +++ b/src/notify.c @@ -8,7 +8,7 @@ #include "rtr/db/vrps.h" static int -send_notify(struct client const *client, void *arg) +send_notify(struct client *client, void *arg) { serial_t *serial = arg; int error; diff --git a/src/rtr/db/vrps.c b/src/rtr/db/vrps.c index aad6646a..46233733 100644 --- a/src/rtr/db/vrps.c +++ b/src/rtr/db/vrps.c @@ -260,8 +260,8 @@ vrps_purge(struct deltas **deltas) return resize_deltas_db(&state.deltas, group); } -int -vrps_update(bool *changed) +static int +__vrps_update(bool *changed) { struct db_table *old_base; struct db_table *new_base; @@ -358,6 +358,58 @@ revert_base: return error; } +int +vrps_update(bool *changed) +{ + time_t start, finish, exec_time; + serial_t serial; + int error; + + /* + * This wrapper is mainly for log informational data, so if there's no + * need don't do unnecessary calls + */ + if (!log_info_enabled()) + return __vrps_update(changed); + + pr_info("Starting validation."); + if (config_get_mode() == SERVER) { + error = get_last_serial_number(&serial); + if (!error) + pr_info("- Current serial number is %u.", serial); + } + + time(&start); + error = __vrps_update(changed); + time(&finish); + exec_time = finish - start; + + pr_info("Validation finished:"); + rwlock_read_lock(&state_lock); + do { + if (state.base == NULL) { + rwlock_unlock(&state_lock); + pr_info("- Valid ROAs: 0"); + pr_info("- Valid Router Keys: 0"); + if (config_get_mode() == SERVER) + pr_info("- No serial number."); + break; + } + + pr_info("- Valid ROAs: %u", db_table_roa_count(state.base)); + pr_info("- Valid Router Keys: %u", + db_table_router_key_count(state.base)); + if (config_get_mode() == SERVER) { + pr_info("- %s serial number is %u.", + serial == state.next_serial - 1 ? "Current" : "New", + state.next_serial - 1); + } + rwlock_unlock(&state_lock); + } while(0); + pr_info("- Real execution time: %ld secs.", exec_time); + + return error; +} /** * Please keep in mind that there is at least one errcode-aware caller. The most * important ones are diff --git a/src/rtr/rtr.c b/src/rtr/rtr.c index f505009f..95508d59 100644 --- a/src/rtr/rtr.c +++ b/src/rtr/rtr.c @@ -218,6 +218,14 @@ end_client(int fd) print_close_failure(errno, fd); } +static void +print_client_addr(struct sockaddr_storage *addr, char const *action, int fd) +{ + char buffer[INET6_ADDRSTRLEN]; + pr_info("Client %s [ID %d]: %s", action, fd, + sockaddr2str(addr, buffer)); +} + /* * The client socket threads' entry routine. * @arg must be released. @@ -250,6 +258,7 @@ client_thread_cb(void *arg) break; } + print_client_addr(¶m.addr, "closed", param.fd); end_client(param.fd); clients_forget(param.fd); @@ -288,11 +297,7 @@ handle_client_connections(int server_fd) return -EINVAL; } - if (log_debug_enabled()) { - char buffer[INET6_ADDRSTRLEN]; - pr_debug("Client accepted: %s", - sockaddr2str(&client_addr, buffer)); - } + print_client_addr(&client_addr, "accepted", client_fd); /* * Note: My gut says that errors from now on (even the unknown @@ -331,9 +336,10 @@ handle_client_connections(int server_fd) * Receive @arg to be called as a clients_foreach_cb */ static int -kill_client(struct client const *client, void *arg) +kill_client(struct client *client, void *arg) { end_client(client->fd); + print_client_addr(&(client->addr), "terminated", client->fd); /* Don't call clients_forget to avoid deadlock! */ return 0; } @@ -376,8 +382,6 @@ rtr_listen(void) if (error) pr_err("Error %d while trying to update the ROA database.", error); - else - pr_info("Validation finished."); goto revert_clients_db; /* Error 0 it's ok */ }