diff --git a/libknet/logging.c b/libknet/logging.c index fe409565..5ea14176 100644 --- a/libknet/logging.c +++ b/libknet/logging.c @@ -1,261 +1,261 @@ /* * Copyright (C) 2010-2018 Red Hat, Inc. All rights reserved. * * Author: Fabio M. Di Nitto * * This software licensed under GPL-2.0+, LGPL-2.0+ */ #include "config.h" #include #include #include #include #include #include #include #include "internals.h" #include "logging.h" #include "threads_common.h" struct pretty_names { const char *name; uint8_t val; }; static struct pretty_names subsystem_names[] = { { "common", KNET_SUB_COMMON }, { "handle", KNET_SUB_HANDLE }, { "host", KNET_SUB_HOST }, { "listener", KNET_SUB_LISTENER }, { "link", KNET_SUB_LINK }, { "transport", KNET_SUB_TRANSPORT }, { "crypto", KNET_SUB_CRYPTO }, { "compress", KNET_SUB_COMPRESS }, { "filter", KNET_SUB_FILTER }, { "dstcache", KNET_SUB_DSTCACHE }, { "heartbeat", KNET_SUB_HEARTBEAT }, { "pmtud", KNET_SUB_PMTUD }, { "tx", KNET_SUB_TX }, { "rx", KNET_SUB_RX }, { "loopback", KNET_SUB_TRANSP_LOOPBACK }, { "udp", KNET_SUB_TRANSP_UDP }, { "sctp", KNET_SUB_TRANSP_SCTP }, { "nsscrypto", KNET_SUB_NSSCRYPTO }, { "opensslcrypto", KNET_SUB_OPENSSLCRYPTO }, { "zlibcomp", KNET_SUB_ZLIBCOMP }, { "lz4comp", KNET_SUB_LZ4COMP }, { "lz4hccomp", KNET_SUB_LZ4HCCOMP }, { "lzo2comp", KNET_SUB_LZO2COMP }, { "lzmacomp", KNET_SUB_LZMACOMP }, { "bzip2comp", KNET_SUB_BZIP2COMP }, { "unknown", KNET_SUB_UNKNOWN } /* unknown MUST always be last in this array */ }; const char *knet_log_get_subsystem_name(uint8_t subsystem) { unsigned int i; for (i = 0; i < KNET_MAX_SUBSYSTEMS; i++) { if (subsystem_names[i].val == KNET_SUB_UNKNOWN) { break; } if (subsystem_names[i].val == subsystem) { return subsystem_names[i].name; } } return "unknown"; } uint8_t knet_log_get_subsystem_id(const char *name) { unsigned int i; for (i = 0; i < KNET_MAX_SUBSYSTEMS; i++) { if (subsystem_names[i].val == KNET_SUB_UNKNOWN) { break; } if (strcasecmp(name, subsystem_names[i].name) == 0) { return subsystem_names[i].val; } } return KNET_SUB_UNKNOWN; } static int is_valid_subsystem(uint8_t subsystem) { unsigned int i; for (i = 0; i < KNET_MAX_SUBSYSTEMS; i++) { if ((subsystem != KNET_SUB_UNKNOWN) && (subsystem_names[i].val == KNET_SUB_UNKNOWN)) { break; } if (subsystem_names[i].val == subsystem) { return 0; } } return -1; } static struct pretty_names loglevel_names[] = { { "ERROR", KNET_LOG_ERR }, { "WARNING", KNET_LOG_WARN }, { "info", KNET_LOG_INFO }, { "debug", KNET_LOG_DEBUG } }; const char *knet_log_get_loglevel_name(uint8_t level) { unsigned int i; for (i = 0; i <= KNET_LOG_DEBUG; i++) { if (loglevel_names[i].val == level) { return loglevel_names[i].name; } } return "ERROR"; } uint8_t knet_log_get_loglevel_id(const char *name) { unsigned int i; for (i = 0; i <= KNET_LOG_DEBUG; i++) { if (strcasecmp(name, loglevel_names[i].name) == 0) { return loglevel_names[i].val; } } return KNET_LOG_ERR; } int knet_log_set_loglevel(knet_handle_t knet_h, uint8_t subsystem, uint8_t level) { int savederrno = 0; if (!knet_h) { errno = EINVAL; return -1; } if (is_valid_subsystem(subsystem) < 0) { errno = EINVAL; return -1; } if (level > KNET_LOG_DEBUG) { errno = EINVAL; return -1; } savederrno = get_global_wrlock(knet_h); if (savederrno) { log_err(knet_h, subsystem, "Unable to get write lock: %s", strerror(savederrno)); errno = savederrno; return -1; } knet_h->log_levels[subsystem] = level; pthread_rwlock_unlock(&knet_h->global_rwlock); return 0; } int knet_log_get_loglevel(knet_handle_t knet_h, uint8_t subsystem, uint8_t *level) { int savederrno = 0; if (!knet_h) { errno = EINVAL; return -1; } if (is_valid_subsystem(subsystem) < 0) { errno = EINVAL; return -1; } if (!level) { errno = EINVAL; return -1; } savederrno = pthread_rwlock_rdlock(&knet_h->global_rwlock); if (savederrno) { log_err(knet_h, subsystem, "Unable to get write lock: %s", strerror(savederrno)); errno = savederrno; return -1; } *level = knet_h->log_levels[subsystem]; pthread_rwlock_unlock(&knet_h->global_rwlock); return 0; } void log_msg(knet_handle_t knet_h, uint8_t subsystem, uint8_t msglevel, const char *fmt, ...) { va_list ap; struct knet_log_msg msg; size_t byte_cnt = 0; int len, err; if ((!knet_h) || (subsystem == KNET_MAX_SUBSYSTEMS) || (msglevel > knet_h->log_levels[subsystem])) return; /* * most logging calls will take place with locking in place. * if we get an EINVAL and locking is initialized, then * we are getting a real error and we need to stop */ err = pthread_rwlock_tryrdlock(&knet_h->global_rwlock); if ((err == EAGAIN) && (knet_h->lock_init_done)) return; if (knet_h->logfd <= 0) goto out_unlock; memset(&msg, 0, sizeof(struct knet_log_msg)); msg.subsystem = subsystem; msg.msglevel = msglevel; va_start(ap, fmt); #ifdef __clang__ #pragma clang diagnostic push #pragma clang diagnostic ignored "-Wformat-nonliteral" #endif - vsnprintf(msg.msg, sizeof msg.msg, fmt, ap); + vsnprintf(msg.msg, sizeof(msg.msg), fmt, ap); #ifdef __clang__ #pragma clang diagnostic pop #endif va_end(ap); while (byte_cnt < sizeof(struct knet_log_msg)) { len = write(knet_h->logfd, &msg, sizeof(struct knet_log_msg) - byte_cnt); if (len <= 0) { goto out_unlock; } byte_cnt += len; } out_unlock: /* * unlock only if we are holding the lock */ if (!err) pthread_rwlock_unlock(&knet_h->global_rwlock); return; } diff --git a/libknet/tests/test-common.c b/libknet/tests/test-common.c index 0dba3392..f01f8320 100644 --- a/libknet/tests/test-common.c +++ b/libknet/tests/test-common.c @@ -1,494 +1,494 @@ /* * Copyright (C) 2016-2018 Red Hat, Inc. All rights reserved. * * Author: Fabio M. Di Nitto * * This software licensed under GPL-2.0+, LGPL-2.0+ */ #include "config.h" #include #include #include #include #include #include #include #include #include #include #include "libknet.h" #include "test-common.h" static pthread_mutex_t log_mutex = PTHREAD_MUTEX_INITIALIZER; static int log_init = 0; static pthread_mutex_t log_thread_mutex = PTHREAD_MUTEX_INITIALIZER; static pthread_t log_thread; static int log_thread_init = 0; static int log_fds[2]; struct log_thread_data { int logfd; FILE *std; }; static struct log_thread_data data; static pthread_mutex_t shutdown_mutex = PTHREAD_MUTEX_INITIALIZER; static int shutdown_in_progress = 0; static int _read_pipe(int fd, char **file, size_t *length) { char buf[4096]; int n; int done = 0; *file = NULL; *length = 0; memset(buf, 0, sizeof(buf)); while (!done) { n = read(fd, buf, sizeof(buf)); if (n < 0) { if (errno == EINTR) continue; if (*file) free(*file); return n; } if (n == 0 && (!*length)) return 0; if (n == 0) done = 1; if (*file) *file = realloc(*file, (*length) + n + done); else *file = malloc(n + done); if (!*file) return -1; memmove((*file) + (*length), buf, n); *length += (done + n); } /* Null terminator */ (*file)[(*length) - 1] = 0; return 0; } int execute_shell(const char *command, char **error_string) { pid_t pid; int status, err = 0; int fd[2]; size_t size = 0; if ((command == NULL) || (!error_string)) { errno = EINVAL; return FAIL; } *error_string = NULL; err = pipe(fd); if (err) goto out_clean; pid = fork(); if (pid < 0) { err = pid; goto out_clean; } if (pid) { /* parent */ close(fd[1]); err = _read_pipe(fd[0], error_string, &size); if (err) goto out_clean0; waitpid(pid, &status, 0); if (!WIFEXITED(status)) { err = -1; goto out_clean0; } if (WIFEXITED(status) && WEXITSTATUS(status) != 0) { err = WEXITSTATUS(status); goto out_clean0; } goto out_clean0; } else { /* child */ close(0); close(1); close(2); close(fd[0]); dup2(fd[1], 1); dup2(fd[1], 2); close(fd[1]); execlp("/bin/sh", "/bin/sh", "-c", command, NULL); exit(FAIL); } out_clean: close(fd[1]); out_clean0: close(fd[0]); return err; } int is_memcheck(void) { char *val; val = getenv("KNETMEMCHECK"); if (val) { if (!strncmp(val, "yes", 3)) { return 1; } } return 0; } int is_helgrind(void) { char *val; val = getenv("KNETHELGRIND"); if (val) { if (!strncmp(val, "yes", 3)) { return 1; } } return 0; } void set_scheduler(int policy) { struct sched_param sched_param; int err; err = sched_get_priority_max(policy); if (err < 0) { printf("Could not get maximum scheduler priority\n"); exit(FAIL); } sched_param.sched_priority = err; err = sched_setscheduler(0, policy, &sched_param); if (err < 0) { printf("Could not set priority\n"); exit(FAIL); } return; } int setup_logpipes(int *logfds) { if (pipe2(logfds, O_CLOEXEC | O_NONBLOCK) < 0) { printf("Unable to setup logging pipe\n"); exit(FAIL); } return PASS; } void close_logpipes(int *logfds) { close(logfds[0]); logfds[0] = 0; close(logfds[1]); logfds[1] = 0; } void flush_logs(int logfd, FILE *std) { while (1) { struct knet_log_msg msg; - for (size_t bytes_read = 0; bytes_read < sizeof msg; ) { + for (size_t bytes_read = 0; bytes_read < sizeof(msg); ) { int len = read(logfd, &msg + bytes_read, - sizeof msg - bytes_read); + sizeof(msg) - bytes_read); if (len <= 0) { return; } bytes_read += len; } fprintf(std, "[knet]: [%s] %s: %.*s\n", knet_log_get_loglevel_name(msg.msglevel), knet_log_get_subsystem_name(msg.subsystem), KNET_MAX_LOG_MSG_SIZE, msg.msg); } } static void *_logthread(void *args) { while (1) { int num; struct timeval tv = { 60, 0 }; fd_set rfds; FD_ZERO(&rfds); FD_SET(data.logfd, &rfds); num = select(FD_SETSIZE, &rfds, NULL, NULL, &tv); if (num < 0) { fprintf(data.std, "Unable select over logfd!\nHALTING LOGTHREAD!\n"); return NULL; } if (num == 0) { fprintf(data.std, "[knet]: No logs in the last 60 seconds\n"); continue; } if (FD_ISSET(data.logfd, &rfds)) { flush_logs(data.logfd, data.std); } } } int start_logthread(int logfd, FILE *std) { int savederrno = 0; savederrno = pthread_mutex_lock(&log_thread_mutex); if (savederrno) { printf("Unable to get log_thread mutex lock\n"); return -1; } if (!log_thread_init) { data.logfd = logfd; data.std = std; savederrno = pthread_create(&log_thread, 0, _logthread, NULL); if (savederrno) { printf("Unable to start logging thread: %s\n", strerror(savederrno)); pthread_mutex_unlock(&log_thread_mutex); return -1; } log_thread_init = 1; } pthread_mutex_unlock(&log_thread_mutex); return 0; } int stop_logthread(void) { int savederrno = 0; void *retval; savederrno = pthread_mutex_lock(&log_thread_mutex); if (savederrno) { printf("Unable to get log_thread mutex lock\n"); return -1; } if (log_thread_init) { pthread_cancel(log_thread); pthread_join(log_thread, &retval); log_thread_init = 0; } pthread_mutex_unlock(&log_thread_mutex); return 0; } static void stop_logging(void) { stop_logthread(); flush_logs(log_fds[0], stdout); close_logpipes(log_fds); } int start_logging(FILE *std) { int savederrno = 0; savederrno = pthread_mutex_lock(&log_mutex); if (savederrno) { printf("Unable to get log_mutex lock\n"); return -1; } if (!log_init) { setup_logpipes(log_fds); if (atexit(&stop_logging) != 0) { printf("Unable to register atexit handler to stop logging: %s\n", strerror(errno)); exit(FAIL); } if (start_logthread(log_fds[0], std) < 0) { exit(FAIL); } log_init = 1; } pthread_mutex_unlock(&log_mutex); return log_fds[1]; } knet_handle_t knet_handle_start(int logfds[2], uint8_t log_level) { knet_handle_t knet_h = knet_handle_new_ex(1, logfds[1], log_level, 0); if (knet_h) { return knet_h; } else { printf("knet_handle_new failed: %s\n", strerror(errno)); flush_logs(logfds[0], stdout); close_logpipes(logfds); exit(FAIL); } } int knet_handle_stop(knet_handle_t knet_h) { int savederrno; size_t i, j; knet_node_id_t host_ids[KNET_MAX_HOST]; uint8_t link_ids[KNET_MAX_LINK]; size_t host_ids_entries = 0, link_ids_entries = 0; struct knet_link_status status; savederrno = pthread_mutex_lock(&shutdown_mutex); if (savederrno) { printf("Unable to get shutdown mutex lock\n"); return -1; } if (shutdown_in_progress) { pthread_mutex_unlock(&shutdown_mutex); errno = EINVAL; return -1; } shutdown_in_progress = 1; pthread_mutex_unlock(&shutdown_mutex); if (!knet_h) { errno = EINVAL; return -1; } if (knet_host_get_host_list(knet_h, host_ids, &host_ids_entries) < 0) { printf("knet_host_get_host_list failed: %s\n", strerror(errno)); return -1; } for (i = 0; i < host_ids_entries; i++) { if (knet_link_get_link_list(knet_h, host_ids[i], link_ids, &link_ids_entries)) { printf("knet_link_get_link_list failed: %s\n", strerror(errno)); return -1; } for (j = 0; j < link_ids_entries; j++) { if (knet_link_get_status(knet_h, host_ids[i], link_ids[j], &status, sizeof(struct knet_link_status))) { printf("knet_link_get_status failed: %s\n", strerror(errno)); return -1; } if (status.enabled) { if (knet_link_set_enable(knet_h, host_ids[i], j, 0)) { printf("knet_link_set_enable failed: %s\n", strerror(errno)); return -1; } } knet_link_clear_config(knet_h, host_ids[i], j); } if (knet_host_remove(knet_h, host_ids[i]) < 0) { printf("knet_host_remove failed: %s\n", strerror(errno)); return -1; } } if (knet_handle_free(knet_h)) { printf("knet_handle_free failed: %s\n", strerror(errno)); return -1; } return 0; } int make_local_sockaddr(struct sockaddr_storage *lo, uint16_t offset) { uint32_t port; char portstr[32]; /* Use the pid if we can. but makes sure its in a sensible range */ port = (uint32_t)getpid() + offset; if (port < 1024) { port += 1024; } if (port > 65536) { port = port & 0xFFFF; } sprintf(portstr, "%u", port); memset(lo, 0, sizeof(struct sockaddr_storage)); printf("Using port %u\n", port); return knet_strtoaddr("127.0.0.1", portstr, lo, sizeof(struct sockaddr_storage)); } int wait_for_host(knet_handle_t knet_h, uint16_t host_id, int seconds, int logfd, FILE *std) { int i = 0; if (is_memcheck() || is_helgrind()) { printf("Test suite is running under valgrind, adjusting wait_for_host timeout\n"); seconds = seconds * 16; } while (i < seconds) { flush_logs(logfd, std); if (knet_h->host_index[host_id]->status.reachable == 1) { return 0; } printf("waiting host %u to be reachable for %d more seconds\n", host_id, seconds - i); sleep(1); i++; } return -1; } int wait_for_packet(knet_handle_t knet_h, int seconds, int datafd) { fd_set rfds; struct timeval tv; int err = 0; if (is_memcheck() || is_helgrind()) { printf("Test suite is running under valgrind, adjusting wait_for_packet timeout\n"); seconds = seconds * 16; } FD_ZERO(&rfds); FD_SET(datafd, &rfds); tv.tv_sec = seconds; tv.tv_usec = 0; err = select(datafd+1, &rfds, NULL, NULL, &tv); if ((err > 0) && (FD_ISSET(datafd, &rfds))) { return 0; } return -1; }