]> git.ipfire.org Git - thirdparty/haproxy.git/commitdiff
MINOR: ssl: Add traces to ssl init/close functions
authorRemi Tricot-Le Breton <rlebreton@haproxy.com>
Fri, 18 Apr 2025 15:26:50 +0000 (17:26 +0200)
committerWilliam Lallemand <wlallemand@haproxy.com>
Wed, 30 Apr 2025 09:11:26 +0000 (11:11 +0200)
Add a dedicated trace for some unlikely allocation failures and async
errors. Those traces will ostly be used to identify the start and end of
a given SSL connection.

Makefile
include/haproxy/ssl_trace-t.h [new file with mode: 0644]
src/ssl_sock.c
src/ssl_trace.c [new file with mode: 0644]

index 311d010989319bb5c43a45cad972fda9f4e5f379..d1893e54dcce6fa54c5c222939990d7f68a9bd25 100644 (file)
--- a/Makefile
+++ b/Makefile
@@ -630,9 +630,10 @@ ifneq ($(USE_OPENSSL:0=),)
     SSL_LDFLAGS   := $(if $(SSL_LIB),-L$(SSL_LIB)) -lssl -lcrypto
   endif
   USE_SSL         := $(if $(USE_SSL:0=),$(USE_SSL:0=),implicit)
-  OPTIONS_OBJS += src/ssl_sock.o src/ssl_ckch.o src/ssl_ocsp.o src/ssl_crtlist.o     \
-                  src/ssl_sample.o src/cfgparse-ssl.o src/ssl_gencert.o              \
-                  src/ssl_utils.o src/jwt.o src/ssl_clienthello.o src/jws.o src/acme.o
+  OPTIONS_OBJS += src/ssl_sock.o src/ssl_ckch.o src/ssl_ocsp.o src/ssl_crtlist.o       \
+                  src/ssl_sample.o src/cfgparse-ssl.o src/ssl_gencert.o                \
+                  src/ssl_utils.o src/jwt.o src/ssl_clienthello.o src/jws.o src/acme.o \
+                  src/ssl_trace.o
 endif
 
 ifneq ($(USE_ENGINE:0=),)
diff --git a/include/haproxy/ssl_trace-t.h b/include/haproxy/ssl_trace-t.h
new file mode 100644 (file)
index 0000000..513822f
--- /dev/null
@@ -0,0 +1,28 @@
+/*
+ * include/haproxy/ssl_trace-t.h
+ * Definitions for SSL traces internal types, constants and flags.
+ *
+ * Copyright (C) 2025
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License
+ * as published by the Free Software Foundation; either version
+ * 2 of the License, or (at your option) any later version.
+ *
+ */
+
+#ifndef _HAPROXY_SSL_TRACE_T_H
+#define _HAPROXY_SSL_TRACE_T_H
+
+#include <haproxy/trace-t.h>
+
+extern struct trace_source trace_ssl;
+
+#define SSL_EV_CONN_NEW            (1ULL <<  0)
+#define SSL_EV_CONN_CLOSE          (1ULL <<  1)
+#define SSL_EV_CONN_END            (1ULL <<  2)
+#define SSL_EV_CONN_ERR            (1ULL <<  3)
+
+#define TRACE_SOURCE &trace_ssl
+
+#endif /* _HAPROXY_SSL_TRACE_T_H */
index 8d5122c3c4791868b9ec63c53d18a977d69844ad..20ffe26db6d82a500978371c54723a72af859988 100644 (file)
@@ -86,6 +86,8 @@
 #include <haproxy/xxhash.h>
 #include <haproxy/istbuf.h>
 #include <haproxy/ssl_ocsp.h>
+#include <haproxy/trace.h>
+#include <haproxy/ssl_trace-t.h>
 
 
 /* ***** READ THIS before adding code here! *****
@@ -5024,6 +5026,8 @@ static int ssl_sock_init(struct connection *conn, void **xprt_ctx)
        struct ssl_sock_ctx *ctx;
        int next_sslconn = 0;
 
+       TRACE_ENTER(SSL_EV_CONN_NEW, conn);
+
        /* already initialized */
        if (*xprt_ctx)
                return 0;
@@ -5031,12 +5035,14 @@ static int ssl_sock_init(struct connection *conn, void **xprt_ctx)
        ctx = pool_alloc(ssl_sock_ctx_pool);
        if (!ctx) {
                conn->err_code = CO_ER_SSL_NO_MEM;
+               TRACE_ERROR("ssl_sock_ctx allocation failure", SSL_EV_CONN_NEW|SSL_EV_CONN_ERR|SSL_EV_CONN_END, conn);
                return -1;
        }
        ctx->wait_event.tasklet = tasklet_new();
        if (!ctx->wait_event.tasklet) {
                conn->err_code = CO_ER_SSL_NO_MEM;
                pool_free(ssl_sock_ctx_pool, ctx);
+               TRACE_ERROR("tasklet allocation failure", SSL_EV_CONN_NEW|SSL_EV_CONN_ERR|SSL_EV_CONN_END, conn);
                return -1;
        }
        ctx->wait_event.tasklet->process = ssl_sock_io_cb;
@@ -5054,6 +5060,7 @@ static int ssl_sock_init(struct connection *conn, void **xprt_ctx)
        next_sslconn = increment_sslconn();
        if (!next_sslconn) {
                conn->err_code = CO_ER_SSL_TOO_MANY;
+               TRACE_ERROR("Too many SSL connections", SSL_EV_CONN_NEW|SSL_EV_CONN_ERR|SSL_EV_CONN_END, conn);
                goto err;
        }
 
@@ -5143,6 +5150,8 @@ static int ssl_sock_init(struct connection *conn, void **xprt_ctx)
 
                _HA_ATOMIC_INC(&global.totalsslconns);
                *xprt_ctx = ctx;
+
+               TRACE_LEAVE(SSL_EV_CONN_NEW, conn);
                return 0;
        }
        else if (objt_listener(conn->target)) {
@@ -5175,6 +5184,8 @@ static int ssl_sock_init(struct connection *conn, void **xprt_ctx)
 
                _HA_ATOMIC_INC(&global.totalsslconns);
                *xprt_ctx = ctx;
+
+               TRACE_LEAVE(SSL_EV_CONN_NEW, conn);
                return 0;
        }
        /* don't know how to handle such a target */
@@ -5185,6 +5196,7 @@ err:
        if (ctx && ctx->wait_event.tasklet)
                tasklet_free(ctx->wait_event.tasklet);
        pool_free(ssl_sock_ctx_pool, ctx);
+       TRACE_DEVEL("leaving in error", SSL_EV_CONN_NEW|SSL_EV_CONN_ERR|SSL_EV_CONN_END);
        return -1;
 }
 
@@ -6081,6 +6093,7 @@ void ssl_sock_close(struct connection *conn, void *xprt_ctx) {
 
        struct ssl_sock_ctx *ctx = xprt_ctx;
 
+       TRACE_ENTER(SSL_EV_CONN_CLOSE, conn);
 
        if (ctx) {
                if (ctx->wait_event.events != 0)
@@ -6103,6 +6116,7 @@ void ssl_sock_close(struct connection *conn, void *xprt_ctx) {
                        SSL_get_all_async_fds(ctx->ssl, NULL, &num_all_fds);
                        if (num_all_fds > 32) {
                                send_log(NULL, LOG_EMERG, "haproxy: openssl returns too many async fds. It seems a bug. Process may crash\n");
+                               TRACE_ERROR("Too many async fds", SSL_EV_CONN_CLOSE|SSL_EV_CONN_ERR, conn);
                                return;
                        }
 
@@ -6128,6 +6142,7 @@ void ssl_sock_close(struct connection *conn, void *xprt_ctx) {
                                tasklet_free(ctx->wait_event.tasklet);
                                pool_free(ssl_sock_ctx_pool, ctx);
                                _HA_ATOMIC_INC(&jobs);
+                               TRACE_DEVEL("async end", SSL_EV_CONN_CLOSE, conn);
                                return;
                        }
                        /* Else we can remove the fds from the fdtab
@@ -6152,6 +6167,7 @@ void ssl_sock_close(struct connection *conn, void *xprt_ctx) {
                pool_free(ssl_sock_ctx_pool, ctx);
                _HA_ATOMIC_DEC(&global.sslconns);
        }
+       TRACE_LEAVE(SSL_EV_CONN_CLOSE, conn);
 }
 
 /* This function tries to perform a clean shutdown on an SSL connection, and in
@@ -6161,6 +6177,8 @@ static void ssl_sock_shutw(struct connection *conn, void *xprt_ctx, int clean)
 {
        struct ssl_sock_ctx *ctx = xprt_ctx;
 
+       TRACE_ENTER(SSL_EV_CONN_END, conn);
+
        if (conn->flags & (CO_FL_WAIT_XPRT | CO_FL_SSL_WAIT_HS))
                return;
        conn_report_term_evt(conn, tevt_loc_xprt, xprt_tevt_type_shutw);
@@ -6173,6 +6191,8 @@ static void ssl_sock_shutw(struct connection *conn, void *xprt_ctx, int clean)
                ssl_sock_dump_errors(conn, NULL);
                ERR_clear_error();
        }
+
+       TRACE_LEAVE(SSL_EV_CONN_END, conn);
 }
 
 
diff --git a/src/ssl_trace.c b/src/ssl_trace.c
new file mode 100644 (file)
index 0000000..f627351
--- /dev/null
@@ -0,0 +1,97 @@
+/*
+ * SSL traces
+ *
+ * Copyright 2000-2025
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License
+ * as published by the Free Software Foundation; either version
+ * 2 of the License, or (at your option) any later version.
+ *
+ */
+
+#include <inttypes.h>
+
+#include <haproxy/api-t.h>
+#include <haproxy/chunk.h>
+#include <haproxy/trace.h>
+#include <haproxy/ssl_trace-t.h>
+#include <haproxy/connection.h>
+#include <haproxy/openssl-compat.h>
+#include <haproxy/ssl_sock-t.h>
+#include <haproxy/ssl_utils.h>
+
+static void ssl_trace(enum trace_level level, uint64_t mask, const struct trace_source *src,
+                       const struct ist where, const struct ist func,
+                       const void *a1, const void *a2, const void *a3, const void *a4);
+
+static const struct trace_event ssl_trace_events[] = {
+       { .mask = SSL_EV_CONN_NEW,            .name = "sslc_new",            .desc = "new SSL connection" },
+       { .mask = SSL_EV_CONN_CLOSE,          .name = "sslc_close",          .desc = "close SSL connection" },
+       { .mask = SSL_EV_CONN_END,            .name = "sslc_end",            .desc = "SSL connection end" },
+       { .mask = SSL_EV_CONN_ERR,            .name = "sslc_err",            .desc = "SSL error"},
+       { }
+};
+
+
+static const struct name_desc ssl_trace_lockon_args[4] = {
+       /* arg1 */ { /* already used by the connection */ },
+       /* arg2 */ { },
+       /* arg3 */ { },
+       /* arg4 */ { }
+};
+
+static const struct name_desc ssl_trace_decoding[] = {
+#define SSL_VERB_CLEAN    1
+       { .name="clean",    .desc="only user-friendly stuff, generally suitable for level \"user\"" },
+#define SSL_VERB_MINIMAL  2
+       { .name="minimal",  .desc="report only conn, no real decoding" },
+#define SSL_VERB_SIMPLE   3
+       { .name="simple",   .desc="add error messages" },
+#define SSL_VERB_ADVANCED 4
+       { .name="advanced", .desc="add handshake-related details" },
+#define SSL_VERB_COMPLETE 5
+       { .name="complete", .desc="add full data dump when available" },
+       { /* end */ }
+};
+
+
+struct trace_source trace_ssl = {
+       .name = IST("ssl"),
+       .desc = "SSL xprt",
+       .arg_def = TRC_ARG1_CONN,  /* TRACE()'s first argument is always a conn */
+       .default_cb = ssl_trace,
+       .known_events = ssl_trace_events,
+       .lockon_args = ssl_trace_lockon_args,
+       .decoding = ssl_trace_decoding,
+       .report_events = ~0,  /* report everything by default */
+};
+
+INITCALL1(STG_REGISTER, trace_register_source, &trace_ssl);
+
+/* Trace callback for SSL.
+ * These traces always expect that arg1, if non-null, is of type connection.
+ */
+static void ssl_trace(enum trace_level level, uint64_t mask, const struct trace_source *src,
+                      const struct ist where, const struct ist func,
+                      const void *a1, const void *a2, const void *a3, const void *a4)
+{
+       struct connection *conn = (struct connection*)a1;
+
+       if (src->verbosity <= SSL_VERB_CLEAN)
+               return;
+
+       if (conn) {
+               struct proxy *px = conn_get_proxy(conn);
+               chunk_appendf(&trace_buf, " : [%c(%s)] conn=%p(0x%08x)", conn_is_back(conn) ? 'B' : 'F',
+                             px ? px->id : "", conn, conn->flags);
+       }
+
+       if (src->verbosity <= SSL_VERB_MINIMAL)
+               return;
+
+       if (src->verbosity <= SSL_VERB_SIMPLE && !(mask & SSL_EV_CONN_ERR))
+               return;
+
+}
+