diff options
Diffstat (limited to 'apps/lib/http_server.c')
-rw-r--r-- | apps/lib/http_server.c | 229 |
1 files changed, 142 insertions, 87 deletions
diff --git a/apps/lib/http_server.c b/apps/lib/http_server.c index 8783221e39..ba72a6c14a 100644 --- a/apps/lib/http_server.c +++ b/apps/lib/http_server.c @@ -21,6 +21,7 @@ #include "http_server.h" #include "internal/sockets.h" #include <openssl/err.h> +#include <openssl/trace.h> #include <openssl/rand.h> #include "s_apps.h" @@ -40,7 +41,7 @@ static int verbosity = LOG_INFO; #ifdef HTTP_DAEMON -int multi = 0; /* run multiple responder processes */ +int multi = 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) @@ -54,33 +55,59 @@ static int print_syslog(const char *str, size_t len, void *levPtr) } #endif -void log_message(const char *prog, int level, const char *fmt, ...) +static void log_with_prefix(const char *prog, const char *fmt, va_list ap) { - 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); +} - if (verbosity < level) - return; +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 (multi) { - char buf[1024]; - - if (vsnprintf(buf, sizeof(buf), fmt, ap) > 0) - syslog(level, "%s", buf); + if (multi != 0) { + vsyslog(level, fmt, ap); if (level <= LOG_ERR) ERR_print_errors_cb(print_syslog, &level); } else #endif - { - BIO_printf(bio_err, "%s: ", prog); - BIO_vprintf(bio_err, fmt, ap); - BIO_printf(bio_err, "\n"); - (void)BIO_flush(bio_err); - } + 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) + #ifdef HTTP_DAEMON void socket_timeout(int signum) { @@ -152,7 +179,7 @@ void spawn_loop(const char *prog) if (i >= multi) { syslog(LOG_ERR, "fatal: internal error: " "no matching child slot for pid: %ld", - (long) fpid); + (long)fpid); killall(1, kidpids); } if (status != 0) { @@ -224,8 +251,8 @@ BIO *http_server_init(const char *prog, const char *port, int verb) if (verb >= 0) { if (verb > LOG_TRACE) { - log_message(prog, LOG_ERR, - "Logging verbosity level %d too high", verb); + log_HTTP1(prog, LOG_ERR, + "Logging verbosity level %d too high", verb); return NULL; } verbosity = verb; @@ -237,14 +264,14 @@ BIO *http_server_init(const char *prog, const char *port, int verb) if (acbio == NULL || BIO_set_bind_mode(acbio, BIO_BIND_REUSEADDR) < 0 || BIO_set_accept_port(acbio, port /* may be "0" */) < 0) { - log_message(prog, LOG_ERR, "Error setting up accept BIO"); + log_HTTP(prog, LOG_ERR, "Error setting up accept BIO"); goto err; } BIO_set_accept_bios(acbio, bufbio); bufbio = NULL; if (BIO_do_accept(acbio) <= 0) { - log_message(prog, LOG_ERR, "Error starting accept"); + log_HTTP(prog, LOG_ERR, "Error starting accept"); goto err; } @@ -252,7 +279,7 @@ BIO *http_server_init(const char *prog, const char *port, int verb) BIO_get_fd(acbio, &asock); port_num = report_server_accept(bio_out, asock, 1, 1); if (port_num == 0) { - log_message(prog, LOG_ERR, "Error printing ACCEPT string"); + log_HTTP(prog, LOG_ERR, "Error printing ACCEPT string"); goto err; } @@ -311,11 +338,11 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, get_sock_info_address(BIO_get_fd(acbio, NULL), NULL, &port); if (port == NULL) { - log_message(prog, LOG_ERR, "Cannot get port listening on"); + log_HTTP(prog, LOG_ERR, "Cannot get port listening on"); goto fatal; } - log_message(prog, LOG_DEBUG, - "Awaiting new connection on port %s ...", port); + log_HTTP1(prog, LOG_DEBUG, + "Awaiting new connection on port %s ...", port); OPENSSL_free(port); if (BIO_do_accept(acbio) <= 0) @@ -324,10 +351,10 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, *pcbio = cbio = BIO_pop(acbio); } else { - log_message(prog, LOG_DEBUG, "Awaiting next request ..."); + log_HTTP(prog, LOG_DEBUG, "Awaiting next request ..."); } if (cbio == NULL) { - /* Cannot call http_server_send_status(cbio, ...) */ + /* Cannot call http_server_send_status(..., cbio, ...) */ ret = -1; goto out; } @@ -345,14 +372,25 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, return ret; ret = 1; if (len < 0) { - log_message(prog, LOG_WARNING, "Request line read error"); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP(prog, LOG_WARNING, "Request line read error"); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } - if ((end = strchr(reqbuf, '\r')) != NULL + + if (((end = strchr(reqbuf, '\r')) != NULL && end[1] == '\n') || (end = strchr(reqbuf, '\n')) != NULL) *end = '\0'; - log_message(prog, LOG_INFO, "Received request, 1st line: %s", reqbuf); + if (verbosity < LOG_TRACE) + trace_log_message(-1, prog, LOG_INFO, + "Received request, 1st line: %s", reqbuf); + log_HTTP(prog, LOG_TRACE, "Received request header:"); + log_HTTP1(prog, LOG_TRACE, "%s", reqbuf); + if (end == NULL) { + log_HTTP(prog, LOG_WARNING, + "Error parsing HTTP header: missing end of line"); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); + goto out; + } url = meth = reqbuf; if ((accept_get && CHECK_AND_SKIP_PREFIX(url, "GET ")) @@ -363,10 +401,10 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, while (*url == ' ') url++; if (*url != '/') { - log_message(prog, LOG_WARNING, - "Invalid %s -- URL does not begin with '/': %s", - meth, url); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP2(prog, LOG_WARNING, + "Invalid %s -- URL does not begin with '/': %s", + meth, url); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } url++; @@ -376,10 +414,10 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, if (*end == ' ') break; if (!HAS_PREFIX(end, HTTP_VERSION_STR)) { - log_message(prog, LOG_WARNING, - "Invalid %s -- bad HTTP/version string: %s", - meth, end + 1); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP2(prog, LOG_WARNING, + "Invalid %s -- bad HTTP/version string: %s", + meth, end + 1); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } *end = '\0'; @@ -393,34 +431,32 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, * the leading slash, so in case 'GET / ' it is now an empty string. */ if (strlen(meth) == 3 && url[0] == '\0') { - (void)http_server_send_status(cbio, 200, "OK"); + (void)http_server_send_status(prog, cbio, 200, "OK"); goto out; } len = urldecode(url); if (len < 0) { - log_message(prog, LOG_WARNING, - "Invalid %s request -- bad URL encoding: %s", - meth, url); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP2(prog, LOG_WARNING, + "Invalid %s request -- bad URL encoding: %s", meth, url); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } if (strlen(meth) == 3) { /* GET */ if ((getbio = BIO_new_mem_buf(url, len)) == NULL || (b64 = BIO_new(BIO_f_base64())) == NULL) { - log_message(prog, LOG_ERR, - "Could not allocate base64 bio with size = %d", - len); + log_HTTP1(prog, LOG_ERR, + "Could not allocate base64 bio with size = %d", len); goto fatal; } BIO_set_flags(b64, BIO_FLAGS_BASE64_NO_NL); getbio = BIO_push(b64, getbio); } } else { - log_message(prog, LOG_WARNING, - "HTTP request does not begin with %sPOST: %s", - accept_get ? "GET or " : "", reqbuf); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP2(prog, LOG_WARNING, + "HTTP request does not begin with %sPOST: %s", + accept_get ? "GET or " : "", reqbuf); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } @@ -433,40 +469,41 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, /* Read and skip past the headers. */ for (;;) { - char *key, *value, *line_end = NULL; + char *key, *value; len = BIO_gets(cbio, inbuf, sizeof(inbuf)); if (len <= 0) { - log_message(prog, LOG_WARNING, "Error reading HTTP header"); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP(prog, LOG_WARNING, "Error reading HTTP header"); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); + goto out; + } + + if (((end = strchr(inbuf, '\r')) != NULL && end[1] == '\n') + || (end = strchr(inbuf, '\n')) != NULL) + *end = '\0'; + log_HTTP1(prog, LOG_TRACE, "%s", *inbuf == '\0' ? + " " /* workaround for "" getting ignored */ : inbuf); + if (end == NULL) { + log_HTTP(prog, LOG_WARNING, + "Error parsing HTTP header: missing end of line"); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } - if (inbuf[0] == '\r' || inbuf[0] == '\n') + if (inbuf[0] == '\0') break; key = inbuf; value = strchr(key, ':'); if (value == NULL) { - log_message(prog, LOG_WARNING, - "Error parsing HTTP header: missing ':'"); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP(prog, LOG_WARNING, + "Error parsing HTTP header: missing ':'"); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); goto out; } *(value++) = '\0'; while (*value == ' ') value++; - line_end = strchr(value, '\r'); - if (line_end == NULL) { - line_end = strchr(value, '\n'); - if (line_end == NULL) { - log_message(prog, LOG_WARNING, - "Error parsing HTTP header: missing end of line"); - (void)http_server_send_status(cbio, 400, "Bad Request"); - goto out; - } - } - *line_end = '\0'; /* https://tools.ietf.org/html/rfc7230#section-6.3 Persistence */ if (found_keep_alive != NULL && OPENSSL_strcasecmp(key, "Connection") == 0) { @@ -486,12 +523,12 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, /* Try to read and parse request */ req = ASN1_item_d2i_bio(it, getbio != NULL ? getbio : cbio, NULL); if (req == NULL) { - log_message(prog, LOG_WARNING, - "Error parsing DER-encoded request content"); - (void)http_server_send_status(cbio, 400, "Bad Request"); + log_HTTP(prog, LOG_WARNING, + "Error parsing DER-encoded request content"); + (void)http_server_send_status(prog, cbio, 400, "Bad Request"); } else if (ppath != NULL && (*ppath = OPENSSL_strdup(url)) == NULL) { - log_message(prog, LOG_ERR, - "Out of memory allocating %zu bytes", strlen(url) + 1); + log_HTTP1(prog, LOG_ERR, + "Out of memory allocating %zu bytes", strlen(url) + 1); ASN1_item_free(req, it); goto fatal; } @@ -508,7 +545,7 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, return ret; fatal: - (void)http_server_send_status(cbio, 500, "Internal Server Error"); + (void)http_server_send_status(prog, cbio, 500, "Internal Server Error"); if (ppath != NULL) { OPENSSL_free(*ppath); *ppath = NULL; @@ -520,28 +557,46 @@ int http_server_get_asn1_req(const ASN1_ITEM *it, ASN1_VALUE **preq, } /* assumes that cbio does not do an encoding that changes the output length */ -int http_server_send_asn1_resp(BIO *cbio, int keep_alive, +int http_server_send_asn1_resp(const char *prog, BIO *cbio, int keep_alive, const char *content_type, const ASN1_ITEM *it, const ASN1_VALUE *resp) { - int ret = BIO_printf(cbio, HTTP_1_0" 200 OK\r\n%s" - "Content-type: %s\r\n" - "Content-Length: %d\r\n\r\n", - keep_alive ? "Connection: keep-alive\r\n" : "", - content_type, - ASN1_item_i2d(resp, NULL, it)) > 0 - && ASN1_item_i2d_bio(it, cbio, resp) > 0; + char buf[200], *p; + int ret = snprintf(buf, sizeof(buf), HTTP_1_0" 200 OK\r\n%s" + "Content-type: %s\r\n" + "Content-Length: %d\r\n", + keep_alive ? "Connection: keep-alive\r\n" : "", + content_type, + ASN1_item_i2d(resp, NULL, it)); + + if (ret < 0 || (size_t)ret >= sizeof(buf)) + return 0; + if (verbosity < LOG_TRACE && (p = strchr(buf, '\r')) != NULL) + trace_log_message(-1, prog, LOG_INFO, + "Sending response, 1st line: %.*s", (int)(p - buf), + buf); + log_HTTP1(prog, LOG_TRACE, "Sending response header:\n%s", buf); + + ret = BIO_printf(cbio, "%s\r\n", buf) > 0 + && ASN1_item_i2d_bio(it, cbio, resp) > 0; (void)BIO_flush(cbio); return ret; } -int http_server_send_status(BIO *cbio, int status, const char *reason) +int http_server_send_status(const char *prog, BIO *cbio, + int status, const char *reason) { - int ret = BIO_printf(cbio, HTTP_1_0" %d %s\r\n\r\n", - /* This implicitly cancels keep-alive */ - status, reason) > 0; + char buf[200]; + int ret = snprintf(buf, sizeof(buf), HTTP_1_0" %d %s\r\n\r\n", + /* This implicitly cancels keep-alive */ + status, reason); + + if (ret < 0 || (size_t)ret >= sizeof(buf)) + return 0; + log_HTTP1(prog, LOG_TRACE, "Sending response header:\n%s", buf); + ret = BIO_printf(cbio, "%s\r\n", buf) > 0; (void)BIO_flush(cbio); return ret; } |