Skip to content

Commit

Permalink
apps/lib/http_server.{c,h}: clean up logging and move it to log.{c,h}
Browse files Browse the repository at this point in the history 
Reviewed-by: Tomas Mraz <[email protected]>
Reviewed-by: Dmitry Belyavskiy <[email protected]>
Reviewed-by: David von Oheimb <[email protected]>
(Merged from openssl#18434)
  • Loading branch information
@DDvO
DDvO committed Sep 7, 2022
1 parent 5e87fdd commit 8a2ec00
Show file tree
Hide file tree
Showing 5 changed files with 182 additions and 119 deletions.
28 changes: 1 addition & 27 deletions apps/include/http_server.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand All @@ -31,37 +32,10 @@
# define HTTP_DAEMON
# include <sys/types.h>
# include <sys/wait.h>
# include <syslog.h>
# include <signal.h>
# 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
Expand Down
50 changes: 50 additions & 0 deletions apps/include/log.h
View file
Original file line number Diff line number Diff line change
@@ -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 <openssl/bio.h>
# if !defined(OPENSSL_SYS_VMS) && !defined(OPENSSL_SYS_WINDOWS) \
&& !defined(OPENSSL_NO_SOCK) && !defined(OPENSSL_NO_POSIX_IO)
# include <syslog.h>
# 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 */
2 changes: 1 addition & 1 deletion apps/lib/build.info
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down
126 changes: 35 additions & 91 deletions apps/lib/http_server.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,91 +24,33 @@
#include <openssl/trace.h>
#include <openssl/rand.h>
#include "s_apps.h"
#include "log.h"

#if defined(__TANDEM)
# if defined(OPENSSL_TANDEM_FLOSS)
# include <floss.h(floss_fork)>
# 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)
Expand Down Expand Up @@ -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");
Expand All @@ -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);
}
}
Expand All @@ -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;
Expand All @@ -229,15 +178,16 @@ 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;
}
}

/* 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
Expand All @@ -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;
Expand Down Expand Up @@ -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:");
Expand Down Expand Up @@ -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);
Expand Down
Loading

0 comments on commit 8a2ec00

Please sign in to comment.