MINOR: ssl: Add traces to ssl init/close functions

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.
This commit is contained in:
Remi Tricot-Le Breton 2025-04-18 17:26:50 +02:00 committed by William Lallemand
parent 08e40f4589
commit 9bb8d6dcd1
4 changed files with 149 additions and 3 deletions

View File

@ -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=),)

View File

@ -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 */

View 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);
}

97
src/ssl_trace.c Normal file
View File

@ -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;
}