From 8a2ec00d7f4bc34ca9111561699ec5ac03a3923e Mon Sep 17 00:00:00 2001 From: "Dr. David von Oheimb" Date: Sat, 28 May 2022 20:26:43 +0200 Subject: [PATCH] apps/lib/http_server.{c,h}: clean up logging and move it to log.{c,h} Reviewed-by: Tomas Mraz Reviewed-by: Dmitry Belyavskiy Reviewed-by: David von Oheimb (Merged from https://github.com/openssl/openssl/pull/18434) --- apps/include/http_server.h | 28 +-------- apps/include/log.h | 50 +++++++++++++++ apps/lib/build.info | 2 +- apps/lib/http_server.c | 126 +++++++++++-------------------------- apps/lib/log.c | 95 ++++++++++++++++++++++++++++ 5 files changed, 182 insertions(+), 119 deletions(-) create mode 100644 apps/include/log.h create mode 100644 apps/lib/log.c diff --git a/apps/include/http_server.h b/apps/include/http_server.h index e80e29d8c5f..4811e6be401 100644 --- a/apps/include/http_server.h +++ b/apps/include/http_server.h @@ -11,6 +11,7 @@ # define OSSL_HTTP_SERVER_H # include "apps.h" +# include "log.h" # ifndef HAVE_FORK # if defined(OPENSSL_SYS_VMS) || defined(OPENSSL_SYS_WINDOWS) @@ -31,37 +32,10 @@ # define HTTP_DAEMON # include # include -# include # include # define MAXERRLEN 1000 /* limit error text sent to syslog to 1000 bytes */ # endif -# undef LOG_TRACE -# undef LOG_DEBUG -# undef LOG_INFO -# undef LOG_WARNING -# undef LOG_ERR -# define LOG_TRACE 8 -# define LOG_DEBUG 7 -# define LOG_INFO 6 -# define LOG_WARNING 4 -# define LOG_ERR 3 - -/*- - * Output a message using the trace API with the given category - * if the category is >= 0 and tracing is enabled. - * Log the message to syslog if multi-threaded HTTP_DAEMON, else to bio_err - * if the verbosity is sufficient for the given level of severity. - * category: trace category as defined in trace.h, or -1 - * prog: the name of the current app, or NULL - * level: the severity of the message, e.g., LOG_ERR - * fmt: message format, which should not include a trailing newline - * ...: potential extra parameters like with printf() - * returns nothing - */ -void trace_log_message(int category, - const char *prog, int level, const char *fmt, ...); - # ifndef OPENSSL_NO_SOCK /*- * Initialize an HTTP server, setting up its listening BIO diff --git a/apps/include/log.h b/apps/include/log.h new file mode 100644 index 00000000000..1b8b58d41ac --- /dev/null +++ b/apps/include/log.h @@ -0,0 +1,50 @@ +/* + * Copyright 1995-2022 The OpenSSL Project Authors. All Rights Reserved. + * + * Licensed under the Apache License 2.0 (the "License"). You may not use + * this file except in compliance with the License. You can obtain a copy + * in the file LICENSE in the source distribution or at + * https://www.openssl.org/source/license.html + */ + +#ifndef OSSL_APPS_LOG_H +# define OSSL_APPS_LOG_H + +# include +# if !defined(OPENSSL_SYS_VMS) && !defined(OPENSSL_SYS_WINDOWS) \ + && !defined(OPENSSL_NO_SOCK) && !defined(OPENSSL_NO_POSIX_IO) +# include +# else +# define LOG_EMERG 0 +# define LOG_ALERT 1 +# define LOG_CRIT 2 +# define LOG_ERR 3 +# define LOG_WARNING 4 +# define LOG_NOTICE 5 +# define LOG_INFO 6 +# define LOG_DEBUG 7 +# endif + +# undef LOG_TRACE +# define LOG_TRACE (LOG_DEBUG + 1) + +int log_set_verbosity(const char *prog, int level); +int log_get_verbosity(void); + +/*- + * Output a message using the trace API with the given category + * if the category is >= 0 and tracing is enabled. + * Log the message to syslog if multi-threaded HTTP_DAEMON, else to bio_err + * if the verbosity is sufficient for the given level of severity. + * Yet cannot do both types of output in strict ANSI mode. + * category: trace category as defined in trace.h, or -1 + * prog: the name of the current app, or NULL + * level: the severity of the message, e.g., LOG_ERR + * fmt: message format, which should not include a trailing newline + * ...: potential extra parameters like with printf() + * returns nothing + */ +void trace_log_message(int category, + const char *prog, int level, const char *fmt, ...); + +#endif /* OSSL_APPS_LOG_H */ diff --git a/apps/lib/build.info b/apps/lib/build.info index 727d9247455..f0df6087340 100644 --- a/apps/lib/build.info +++ b/apps/lib/build.info @@ -8,7 +8,7 @@ IF[{- $config{target} =~ /^vms-/ -}] ENDIF # Source for libapps -$LIBAPPSSRC=apps.c apps_ui.c opt.c fmt.c s_cb.c s_socket.c app_rand.c \ +$LIBAPPSSRC=apps.c apps_ui.c log.c opt.c fmt.c s_cb.c s_socket.c app_rand.c \ columns.c app_params.c names.c app_provider.c app_x509.c http_server.c \ engine.c engine_loader.c app_libctx.c apps_opt_printf.c diff --git a/apps/lib/http_server.c b/apps/lib/http_server.c index 4b18e8fea47..3f9f884c69e 100644 --- a/apps/lib/http_server.c +++ b/apps/lib/http_server.c @@ -24,6 +24,7 @@ #include #include #include "s_apps.h" +#include "log.h" #if defined(__TANDEM) # if defined(OPENSSL_TANDEM_FLOSS) @@ -31,84 +32,25 @@ # endif #endif -static int verbosity = LOG_INFO; - #define HTTP_PREFIX "HTTP/" #define HTTP_VERSION_PATT "1." /* allow 1.x */ #define HTTP_PREFIX_VERSION HTTP_PREFIX""HTTP_VERSION_PATT #define HTTP_1_0 HTTP_PREFIX_VERSION"0" /* "HTTP/1.0" */ #define HTTP_VERSION_STR " "HTTP_PREFIX_VERSION -#ifdef HTTP_DAEMON - -int n_responders = 0; /* run multiple responder processes, set by ocsp.c */ -int acfd = (int) INVALID_SOCKET; - -static int print_syslog(const char *str, size_t len, void *levPtr) -{ - int level = *(int *)levPtr; - int ilen = len > MAXERRLEN ? MAXERRLEN : len; - - syslog(level, "%.*s", ilen, str); - - return ilen; -} -#endif - -static void log_with_prefix(const char *prog, const char *fmt, va_list ap) -{ - char prefix[80]; - BIO *bio, *pre = BIO_new(BIO_f_prefix()); - - (void)snprintf(prefix, sizeof(prefix), "%s: ", prog); - (void)BIO_set_prefix(pre, prefix); - bio = BIO_push(pre, bio_err); - (void)BIO_vprintf(bio, fmt, ap); - (void)BIO_printf(bio, "\n"); - (void)BIO_flush(bio); - (void)BIO_pop(pre); - BIO_free(pre); -} - -void trace_log_message(int category, - const char *prog, int level, const char *fmt, ...) -{ - va_list ap; - - va_start(ap, fmt); - if (category >= 0 && OSSL_trace_enabled(category)) { - va_list ap_copy; - BIO *out = OSSL_trace_begin(category); - - va_copy(ap_copy, ap); - (void)BIO_vprintf(out, fmt, ap_copy); - (void)BIO_printf(out, "\n"); - va_end(ap_copy); - OSSL_trace_end(category, out); - } - if (verbosity < level) { - va_end(ap); - return; - } -#ifdef HTTP_DAEMON - if (n_responders != 0) { - vsyslog(level, fmt, ap); - if (level <= LOG_ERR) - ERR_print_errors_cb(print_syslog, &level); - } else -#endif - log_with_prefix(prog, fmt, ap); - va_end(ap); -} - #define log_HTTP(prog, level, text) \ trace_log_message(OSSL_TRACE_CATEGORY_HTTP, prog, level, "%s", text) #define log_HTTP1(prog, level, fmt, arg) \ trace_log_message(OSSL_TRACE_CATEGORY_HTTP, prog, level, fmt, arg) #define log_HTTP2(prog, level, fmt, arg1, arg2) \ trace_log_message(OSSL_TRACE_CATEGORY_HTTP, prog, level, fmt, arg1, arg2) +#define log_HTTP3(prog, level, fmt, a1, a2, a3) \ + trace_log_message(OSSL_TRACE_CATEGORY_HTTP, prog, level, fmt, a1, a2, a3) #ifdef HTTP_DAEMON +int n_responders = 0; /* run multiple responder processes, set by ocsp.c */ +int acfd = (int)INVALID_SOCKET; + void socket_timeout(int signum) { if (acfd != (int)INVALID_SOCKET) @@ -149,8 +91,9 @@ void spawn_loop(const char *prog) openlog(prog, LOG_PID, LOG_DAEMON); if (setpgid(0, 0)) { - syslog(LOG_ERR, "fatal: error detaching from parent process group: %s", - strerror(errno)); + log_HTTP1(prog, LOG_ERR, + "fatal: error detaching from parent process group: %s", + strerror(errno)); exit(1); } kidpids = app_malloc(n_responders * sizeof(*kidpids), "child PID array"); @@ -177,27 +120,33 @@ void spawn_loop(const char *prog) } } if (i >= n_responders) { - syslog(LOG_ERR, "fatal: internal error: " - "no matching child slot for pid: %ld", - (long)fpid); + log_HTTP1(prog, LOG_ERR, "fatal: internal error: " + "no matching child slot for pid: %ld", + (long)fpid); killall(1, kidpids); } if (status != 0) { - if (WIFEXITED(status)) - syslog(LOG_WARNING, "child process: %ld, exit status: %d", - (long)fpid, WEXITSTATUS(status)); - else if (WIFSIGNALED(status)) - syslog(LOG_WARNING, "child process: %ld, term signal %d%s", - (long)fpid, WTERMSIG(status), + if (WIFEXITED(status)) { + log_HTTP2(prog, LOG_WARNING, + "child process: %ld, exit status: %d", + (long)fpid, WEXITSTATUS(status)); + } else if (WIFSIGNALED(status)) { + char *dumped = ""; + # ifdef WCOREDUMP - WCOREDUMP(status) ? " (core dumped)" : + if (WCOREDUMP(status)) + dumped = " (core dumped)"; # endif - ""); + log_HTTP3(prog, LOG_WARNING, + "child process: %ld, term signal %d%s", + (long)fpid, WTERMSIG(status), dumped); + } ossl_sleep(1000); } break; } else if (errno != EINTR) { - syslog(LOG_ERR, "fatal: waitpid(): %s", strerror(errno)); + log_HTTP1(prog, LOG_ERR, + "fatal: waitpid(): %s", strerror(errno)); killall(1, kidpids); } } @@ -216,7 +165,7 @@ void spawn_loop(const char *prog) if (termsig) _exit(0); if (RAND_poll() <= 0) { - syslog(LOG_ERR, "fatal: RAND_poll() failed"); + log_HTTP(prog, LOG_ERR, "fatal: RAND_poll() failed"); _exit(1); } return; @@ -229,7 +178,8 @@ void spawn_loop(const char *prog) } } if (i >= n_responders) { - syslog(LOG_ERR, "fatal: internal error: no free child slots"); + log_HTTP(prog, LOG_ERR, + "fatal: internal error: no free child slots"); killall(1, kidpids); } break; @@ -237,7 +187,7 @@ void spawn_loop(const char *prog) } /* The loop above can only break on termsig */ - syslog(LOG_INFO, "terminating on signal: %d", termsig); + log_HTTP1(prog, LOG_INFO, "terminating on signal: %d", termsig); killall(0, kidpids); } #endif @@ -249,14 +199,8 @@ BIO *http_server_init(const char *prog, const char *port, int verb) int asock; int port_num; - if (verb >= 0) { - if (verb > LOG_TRACE) { - log_HTTP1(prog, LOG_ERR, - "Logging verbosity level %d too high", verb); - return NULL; - } - verbosity = verb; - } + if (verb >= 0 && !log_set_verbosity(prog, verb)) + return NULL; bufbio = BIO_new(BIO_f_buffer()); if (bufbio == NULL) goto err; @@ -380,7 +324,7 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, if (((end = strchr(reqbuf, '\r')) != NULL && end[1] == '\n') || (end = strchr(reqbuf, '\n')) != NULL) *end = '\0'; - if (verbosity < LOG_TRACE) + if (log_get_verbosity() < LOG_TRACE) trace_log_message(-1, prog, LOG_INFO, "Received request, 1st line: %s", reqbuf); log_HTTP(prog, LOG_TRACE, "Received request header:"); @@ -571,7 +515,7 @@ int http_server_send_asn1_resp(const char *prog, BIO *cbio, int keep_alive, if (ret < 0 || (size_t)ret >= sizeof(buf)) return 0; - if (verbosity < LOG_TRACE && (p = strchr(buf, '\r')) != NULL) + if (log_get_verbosity() < LOG_TRACE && (p = strchr(buf, '\r')) != NULL) trace_log_message(-1, prog, LOG_INFO, "Sending response, 1st line: %.*s", (int)(p - buf), buf); diff --git a/apps/lib/log.c b/apps/lib/log.c new file mode 100644 index 00000000000..94a91949eab --- /dev/null +++ b/apps/lib/log.c @@ -0,0 +1,95 @@ +/* + * Copyright 2020-2022 The OpenSSL Project Authors. All Rights Reserved. + * + * Licensed under the Apache License 2.0 (the "License"). You may not use + * this file except in compliance with the License. You can obtain a copy + * in the file LICENSE in the source distribution or at + * https://www.openssl.org/source/license.html + */ + +#include +#include "apps.h" +#include "log.h" + +static int verbosity = LOG_INFO; + +int log_set_verbosity(const char *prog, int level) +{ + if (level < LOG_EMERG || level > LOG_TRACE) { + trace_log_message(-1, prog, LOG_ERR, + "Invalid verbosity level %d", level); + return 0; + } + verbosity = level; + return 1; +} + +int log_get_verbosity(void) +{ + return verbosity; +} + +#ifdef HTTP_DAEMON +static int print_syslog(const char *str, size_t len, void *levPtr) +{ + int level = *(int *)levPtr; + int ilen = len > MAXERRLEN ? MAXERRLEN : len; + + syslog(level, "%.*s", ilen, str); + + return ilen; +} +#endif + +static void log_with_prefix(const char *prog, const char *fmt, va_list ap) +{ + char prefix[80]; + BIO *bio, *pre = BIO_new(BIO_f_prefix()); + + (void)snprintf(prefix, sizeof(prefix), "%s: ", prog); + (void)BIO_set_prefix(pre, prefix); + bio = BIO_push(pre, bio_err); + (void)BIO_vprintf(bio, fmt, ap); + (void)BIO_printf(bio, "\n"); + (void)BIO_flush(bio); + (void)BIO_pop(pre); + BIO_free(pre); +} + +void trace_log_message(int category, + const char *prog, int level, const char *fmt, ...) +{ + va_list ap; + va_start(ap, fmt); +#ifdef __STRICT_ANSI__ /* unfortuantely, ANSI does not define va_copy */ + if (verbosity >= level) + category = -1; /* disabling trace output in addition to logging */ +#endif + if (category >= 0 && OSSL_trace_enabled(category)) { + BIO *out = OSSL_trace_begin(category); +#ifndef __STRICT_ANSI__ + va_list ap_copy; + + va_copy(ap_copy, ap); + (void)BIO_vprintf(out, fmt, ap_copy); + va_end(ap_copy); +#else + (void)BIO_vprintf(out, fmt, ap); +#endif + (void)BIO_printf(out, "\n"); + OSSL_trace_end(category, out); + } + if (verbosity < level) { + va_end(ap); + return; + } +#ifdef HTTP_DAEMON + if (n_responders != 0) { + vsyslog(level, fmt, ap); + if (level <= LOG_ERR) + ERR_print_errors_cb(print_syslog, &level); + } else +#endif + log_with_prefix(prog, fmt, ap); + va_end(ap); +} -- 2.47.2