diff --git a/docker-compose.yml b/docker-compose.yml index a257afbc..158097c4 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -68,7 +68,22 @@ services: args: IRCD_CONF: tests/docker/ircd-tls-hub.conf TLS_BACKEND: ${TLS_BACKEND:-openssl} + SANITIZE: ${IRCD_SANITIZE:-} container_name: ircu-tls-hub + environment: + IRCD_DEBUG: ${IRCD_DEBUG:-} + ASAN_OPTIONS: ${ASAN_OPTIONS:-abort_on_error=1:halt_on_error=1:detect_leaks=0:log_path=/opt/ircu/debug/asan} + volumes: + - ${IRCD_DEBUG_DIR:-./tests/debug-output}:/opt/ircu/debug + security_opt: + - seccomp:unconfined + ulimits: + core: + soft: -1 + hard: -1 + nofile: + soft: 4096 + hard: 4096 ports: - "16677:6677" - "16697:6697" @@ -88,7 +103,22 @@ services: args: IRCD_CONF: tests/docker/ircd-tls-leaf.conf TLS_BACKEND: ${TLS_BACKEND:-openssl} + SANITIZE: ${IRCD_SANITIZE:-} container_name: ircu-tls-leaf + environment: + IRCD_DEBUG: ${IRCD_DEBUG:-} + ASAN_OPTIONS: ${ASAN_OPTIONS:-abort_on_error=1:halt_on_error=1:detect_leaks=0:log_path=/opt/ircu/debug/asan} + volumes: + - ${IRCD_DEBUG_DIR:-./tests/debug-output}:/opt/ircu/debug + security_opt: + - seccomp:unconfined + ulimits: + core: + soft: -1 + hard: -1 + nofile: + soft: 4096 + hard: 4096 ports: - "16678:6678" - "16680:6680" diff --git a/include/ircd_tls.h b/include/ircd_tls.h index f1c9dd67..bfdc0f79 100644 --- a/include/ircd_tls.h +++ b/include/ircd_tls.h @@ -96,6 +96,9 @@ static inline int ircd_tls_trust_verifies_ca(ircd_tls_trust_policy policy) /** Timeout for TLS handshake in seconds */ #define TLS_HANDSHAKE_TIMEOUT 5 +/** Size of the human-readable reason buffer filled by ircd_tls_negotiate(). */ +#define TLS_REASON_LEN 128 + /* The following variables and functions are provided by ircu2's core * code, not by the TLS interface. */ @@ -227,10 +230,15 @@ void ircd_tls_listen_free(struct Listener *listener); * client's socket and returns 0. * * @param[in] cptr Locally connected client to perform handshake for. + * @param[out] reason If non-NULL, receives a human-readable failure reason + * on a -1 return (empty otherwise). Intended for operator notices and + * the disconnect log, not for the peer (a categorical ERROR line is sent + * to the peer instead). + * @param[in] reasonlen Size of the \a reason buffer (see TLS_REASON_LEN). * \returns 1 on completed handshake, 0 on continuing handshake, -1 on * error. */ -int ircd_tls_negotiate(struct Client *cptr); +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen); /** ircd_tls_recv() performs a non-blocking receive of TLS application * data from \a cptr into \a buf. diff --git a/include/msgq.h b/include/msgq.h index a669165d..b5c5d294 100644 --- a/include/msgq.h +++ b/include/msgq.h @@ -92,7 +92,7 @@ extern void msgq_append(struct Client *dest, struct MsgBuf *mb, const char *format, ...); extern void msgq_clean(struct MsgBuf *mb); extern void msgq_add(struct MsgQ *mq, struct MsgBuf *mb, int prio); -extern void msgq_excise(struct MsgQ *mq, const char *buf, unsigned int len); +extern void msgq_excise(struct MsgQ *mq, const char *buf); extern void msgq_count_memory(struct Client *cptr, size_t *msg_alloc, size_t *msg_used); extern void msgq_histogram(struct Client *cptr, const struct StatDesc *sd, diff --git a/ircd/list.c b/ircd/list.c index a4ae97ad..5430ac37 100644 --- a/ircd/list.c +++ b/ircd/list.c @@ -168,6 +168,9 @@ static void dealloc_connection(struct Connection* con) if (-1 < con_fd(con)) close(con_fd(con)); MsgQClear(&(con_sendQ(con))); + /* MsgQClear frees MsgBufs; drop TLS mid-message rexmit into them. */ + con->con_rexmit = NULL; + con->con_rexmit_len = 0; client_drop_sendq(con); DBufClear(&(con_recvQ(con))); if (con_listener(con)) diff --git a/ircd/listener.c b/ircd/listener.c index 3eca2f9b..e00a88dc 100644 --- a/ircd/listener.c +++ b/ircd/listener.c @@ -156,7 +156,7 @@ void show_ports(struct Client* sptr, const struct StatDesc* sd, char* param) { struct Listener *listener = 0; - char flags[8]; + char flags[16]; /* type + H + E + "4-" + "6-" + F + NUL = 9 bytes max */ int show_hidden = IsOper(sptr); int count = (IsOper(sptr) || MyUser(sptr)) ? 100 : 8; int port = 0; diff --git a/ircd/m_server.c b/ircd/m_server.c index c2c469c3..5c194f11 100644 --- a/ircd/m_server.c +++ b/ircd/m_server.c @@ -612,8 +612,12 @@ int mr_server(struct Client* cptr, struct Client* sptr, int parc, char* parv[]) if (!EmptyString(aconf->tls_fingerprint) && ircd_strcmp(cli_tls_fingerprint(cptr), aconf->tls_fingerprint)) { ++ServerStats->is_wrong_server; - sendto_opmask_butone(0, SNO_OLDSNO, "Access denied (fingerprint mismatch) %s", - cli_name(cptr)); + sendto_opmask_butone(0, SNO_OLDSNO, + "TLS fingerprint mismatch for server %s: presented %s, " + "configured %s", cli_name(cptr), + EmptyString(cli_tls_fingerprint(cptr)) + ? "(none)" : cli_tls_fingerprint(cptr), + aconf->tls_fingerprint); return exit_client_msg(cptr, cptr, &me, "Access denied. Bad TLS fingerprint for server %s", cli_name(cptr)); } diff --git a/ircd/msgq.c b/ircd/msgq.c index 44e911db..ee5e15ec 100644 --- a/ircd/msgq.c +++ b/ircd/msgq.c @@ -608,38 +608,49 @@ msgq_add(struct MsgQ *mq, struct MsgBuf *mb, int prio) mq->count++; /* and the queue count */ } +/** Excise the head message of \a qlist if \a buf points into its buffer. + * @param[in,out] mq Message queue owning \a qlist. + * @param[in] qlist Queue list (normal or priority) to test. + * @param[in] buf Pointer that may fall within the head message's buffer. + * @return Non-zero if the head message was found and removed. + */ static int msgqlist_excise(struct MsgQ *mq, struct MsgQList *qlist, - const char *buf, unsigned int len) + const char *buf) { - struct Msg *msg; + struct Msg *msg = qlist->head; + unsigned int len; - msg = qlist->head; if (!msg) return 0; - if (buf != msg->msg->msg) + /* Does buf point somewhere within this head message's buffer? */ + if (buf < msg->msg->msg || buf >= msg->msg->msg + msg->msg->length) return 0; - assert(len == msg->msg->length); + len = msg->msg->length - msg->sent; /* delete the whole remaining message */ msgq_delmsg(mq, qlist, &len); return 1; } -/** Excise a message from the front of a message queue. +/** Remove, by identity, the queued message that \a buf points into. * - * This is used for TLS, where TLS libraries may return an EAGAIN-like - * condition for a send but also require the application to provide - * exactly the same contents for the next send. + * Used by the TLS send path. A partial-write remainder (con_rexmit) is a raw + * pointer into a queued message, decoupled from the queue's own byte + * accounting. When that message finishes draining it must be removed by + * identity rather than by feeding its byte count to msgq_delete(): the latter + * deletes in (partial-normal, prio, normal) order and would misattribute the + * bytes to a priority message that jumped ahead of it while the socket was + * blocked. \a buf always points into the head message of one of the two + * queues (new priority messages append at the tail, so they never displace an + * in-flight head), which both lists are checked for. * - * @warning \a buf must be at the front of one of \a mq's queues. - * @param[in] mq Message queue to operate on. - * @param[in] buf Buffered message to excise. - * @param[in] len Length of buffered message. + * @param[in,out] mq Message queue to operate on. + * @param[in] buf Pointer anywhere within the head message to remove. */ -void msgq_excise(struct MsgQ *mq, const char *buf, unsigned int len) +void msgq_excise(struct MsgQ *mq, const char *buf) { - if (!msgqlist_excise(mq, &mq->queue, buf, len) - && !msgqlist_excise(mq, &mq->prio, buf, len)) + if (!msgqlist_excise(mq, &mq->queue, buf) + && !msgqlist_excise(mq, &mq->prio, buf)) assert(0 && "msgq_excise() could not find message to excise"); } diff --git a/ircd/s_auth.c b/ircd/s_auth.c index 240e1d0e..ef283543 100644 --- a/ircd/s_auth.c +++ b/ircd/s_auth.c @@ -91,6 +91,7 @@ enum AuthRequestFlag { AR_IAUTH_FUSERNAME, /**< iauth sent a forced username */ AR_IAUTH_SOFT_DONE, /**< iauth has no objection to client */ AR_GLINE_CHECKED, /**< checked for a G-line banning the client */ + AR_FREE_PENDING, /**< destroy during timer MARKED; freelist on ET_DESTROY */ AR_NUM_FLAGS }; @@ -962,10 +963,28 @@ void destroy_auth_request(struct AuthRequest* auth) s_fd(&auth->socket) = -1; } - if (t_active(&auth->timeout)) + /* + * Detach from the client before touching the freelist. If this is + * called from auth_timeout_callback while the timeout timer is + * GEN_MARKED, timer_del() is a no-op and timer_run() still owns the + * Timer. Freelisting now lets start_auth() memset/reuse the same + * AuthRequest, which zeros timeout links still referenced by the + * timer queue and creates a self-loop — timer_enqueue() then spins + * forever (100% CPU). + */ + if (auth->client) + cli_auth(auth->client) = NULL; + auth->client = NULL; + + if (t_onqueue(&auth->timeout) || t_active(&auth->timeout)) timer_del(&auth->timeout); - cli_auth(auth->client) = NULL; + if (auth->timeout.t_header.gh_flags & GEN_MARKED) { + /* timer_run() will ET_DESTROY after the expire callback returns. */ + FlagSet(&auth->flags, AR_FREE_PENDING); + return; + } + auth->next = auth_freelist; auth_freelist = auth; } @@ -1029,9 +1048,23 @@ static void auth_timeout_callback(struct Event* ev) auth = (struct AuthRequest*) t_data(ev_timer(ev)); + if (ev_type(ev) == ET_DESTROY) { + /* Completes destroy_auth_request() deferred while GEN_MARKED. */ + if (FlagHas(&auth->flags, AR_FREE_PENDING)) { + FlagClr(&auth->flags, AR_FREE_PENDING); + auth->next = auth_freelist; + auth_freelist = auth; + } + return; + } + if (ev_type(ev) == ET_EXPIRE) { int flag = 0; + /* Already destroyed while marked (client gone). */ + if (!auth->client) + return; + /* Report the timeout in the log. */ log_write(LS_RESOLVER, L_INFO, 0, "Registration timeout %s", get_client_name(auth->client, HIDE_IP)); @@ -1233,6 +1266,8 @@ static void start_iauth_query(struct AuthRequest *auth) FlagClr(&auth->flags, AR_IAUTH_PENDING); } +static void start_dns_ident_queries(struct Client *client); + /** Starts auth (identd) and dns queries for a client. * @param[in] client The client for which to start queries. */ @@ -1256,9 +1291,19 @@ void start_auth(struct Client* client) /* Allocate the AuthRequest. */ auth = auth_freelist; - if (auth) + if (auth) { auth_freelist = auth->next; - else + /* + * A freelisted AuthRequest must have had its timeout timer fully + * destroyed (off-queue, inactive) before it was freed — destroy_auth_request() + * defers freelisting until the timer's ET_DESTROY via AR_FREE_PENDING for + * exactly this reason. Assert the invariant rather than "repairing" it: + * a timer_del() on a still-GEN_MARKED timer is a no-op, after which the + * memset() below would zero links timer_run() still owns and recreate the + * timer-enqueue self-loop (100% CPU). + */ + assert(!t_onqueue(&auth->timeout) && !t_active(&auth->timeout)); + } else auth = MyMalloc(sizeof(*auth)); assert(0 != auth); memset(auth, 0, sizeof(*auth)); @@ -1297,9 +1342,15 @@ void start_auth(struct Client* client) } } - /* Start DNS and ident queries, except websocket connections not having a handshake. */ + /* + * Start DNS and ident queries, except websocket connections still waiting + * for the HTTP upgrade. Use the query helper — not start_dns_ident() — + * so we do not call check_auth_finished() twice on the same AuthRequest. + * (start_dns_ident() is the deferred resume path from s_bsd after the + * WebSocket handshake and finishes auth itself.) + */ if (!IsWebsocketPort(client) || IsWebsocket(client)) - start_dns_ident(client); + start_dns_ident_queries(client); /* Add client to GlobalClientList. */ add_client_to_list(client); @@ -1308,12 +1359,14 @@ void start_auth(struct Client* client) check_auth_finished(auth, 0); } -/** Start DNS and ident queries for a client, if appropriate. - * @param[in] client The client for which to start queries. +/** Start DNS and ident queries for \a client without finishing auth. + * Used from start_auth(); the caller owns the subsequent + * check_auth_finished(). */ -void start_dns_ident(struct Client *client) +static void start_dns_ident_queries(struct Client *client) { struct AuthRequest *auth; + assert(client != NULL); auth = cli_auth(client); assert(auth != NULL); @@ -1329,8 +1382,20 @@ void start_dns_ident(struct Client *client) if (IsCloudflarePort(client) && !FlagHas(&auth->flags, AR_IAUTH_PENDING)) start_iauth_query(auth); +} - /* Check which auth events remain pending. */ +/** Resume DNS/ident after a deferred setup phase (WebSocket handshake). + * Starts the queries and then checks whether auth can finish. Must not be + * used from start_auth(), which already finishes auth itself. + * @param[in] client The client for which to start queries. + */ +void start_dns_ident(struct Client *client) +{ + struct AuthRequest *auth; + + start_dns_ident_queries(client); + auth = cli_auth(client); + assert(auth != NULL); check_auth_finished(auth, 0); } diff --git a/ircd/s_bsd.c b/ircd/s_bsd.c index 942e782b..02ffb464 100644 --- a/ircd/s_bsd.c +++ b/ircd/s_bsd.c @@ -297,12 +297,23 @@ unsigned int deliver_it(struct Client *cptr, struct MsgQ *buf) cli_sendB(cptr) += bytes_written; cli_sendB(&me) += bytes_written; - /* A partial write implies that future writes will block. */ - if (bytes_written < bytes_count) + /* + * Plain sockets: a short writev means the kernel send buffer is full. + * TLS (SSL_MODE_ENABLE_PARTIAL_WRITE) can return a short success without + * the socket being full — those backends must return IO_BLOCKED only when + * actually blocked (WANT_WRITE/EAGAIN). Treating TLS short writes as + * FLAG_BLOCKED busy-loops on ET_WRITE while POLLOUT stays ready. + */ + if (!IsTLS(cptr) && bytes_written < bytes_count) SetFlag(cptr, FLAG_BLOCKED); break; case IO_BLOCKED: SetFlag(cptr, FLAG_BLOCKED); + /* TLS may have written earlier iovs then hit WANT_WRITE. */ + if (bytes_written) { + cli_sendB(cptr) += bytes_written; + cli_sendB(&me) += bytes_written; + } break; case IO_FAILURE: cli_error(cptr) = errno; @@ -362,11 +373,30 @@ static int completed_connection(struct Client* cptr) SetTLS(cptr); } - /* Are we making progress? */ + /* Are we making progress? Handle the result like tls_negotiate_client(): + * a negative result (timeout, fatal handshake error, missing session) must + * fail the link now rather than wait for the ping timeout or fall through + * to sending PASS/SERVER on a socket without a TLS session. */ if (IsNegotiatingTLS(cptr)) { - ircd_tls_negotiate(cptr); - if (IsNegotiatingTLS(cptr)) - return 1; + char reason[TLS_REASON_LEN]; + int res = ircd_tls_negotiate(cptr, reason, sizeof(reason)); + + if (res < 0) { + sendto_opmask_butone(0, SNO_OLDSNO, "TLS negotiation failed to %s%s%s", + cli_name(cptr), reason[0] ? ": " : "", reason); + /* Mark dead before returning so exit_client() does not flush an + * ERROR line as plaintext into the half-open handshake stream + * (can_send() rejects a dead socket). Mirrors tls_negotiate_client(). */ + SetFlag(cptr, FLAG_DEADSOCKET); + ClearNegotiatingTLS(cptr); + if (s_tls(&cli_socket(cptr))) { + ircd_tls_close(s_tls(&cli_socket(cptr)), NULL); + s_tls(&cli_socket(cptr)) = NULL; + } + return 0; + } + if (res == 0) + return 1; /* still negotiating */ } } @@ -463,6 +493,9 @@ void close_connection(struct Client *cptr) SetFlag(cptr, FLAG_DEADSOCKET); MsgQClear(&(cli_sendQ(cptr))); + /* MsgQClear frees MsgBufs; drop TLS mid-message rexmit into them. */ + cli_connect(cptr)->con_rexmit = NULL; + cli_connect(cptr)->con_rexmit_len = 0; client_drop_sendq(cli_connect(cptr)); DBufClear(&(cli_recvQ(cptr))); memset(cli_passwd(cptr), 0, sizeof(cli_passwd(cptr))); @@ -1067,21 +1100,26 @@ void init_server_identity(void) } /** Notify operators of inbound TLS failures on server ports. */ -static void tls_negotiation_failed(struct Client *cptr) +static void tls_negotiation_failed(struct Client *cptr, const char *reason) { if (IsServerPort(cptr)) sendto_opmask_butone(0, SNO_OLDSNO, - "TLS negotiation failed from unknown server"); + "TLS negotiation failed from unknown server%s%s", + (reason && reason[0]) ? ": " : "", + reason ? reason : ""); } /** Run ircd_tls_negotiate() and handle a fatal result. */ static int tls_negotiate_client(struct Client *cptr, char **fmt, char **fallback) { - int res = ircd_tls_negotiate(cptr); + /* static: *fallback is read by the caller after we return, still within the + * same (synchronous) socket callback, so a stack buffer would dangle. */ + static char reason[TLS_REASON_LEN]; + int res = ircd_tls_negotiate(cptr, reason, sizeof(reason)); if (res < 0) { - tls_negotiation_failed(cptr); + tls_negotiation_failed(cptr, reason); SetFlag(cptr, FLAG_DEADSOCKET); ClrFlag(cptr, FLAG_NEGOTIATING_TLS); if (s_tls(&cli_socket(cptr))) @@ -1089,8 +1127,8 @@ static int tls_negotiate_client(struct Client *cptr, char **fmt, char **fallback ircd_tls_close(s_tls(&cli_socket(cptr)), "TLS negotiation failed"); s_tls(&cli_socket(cptr)) = NULL; } - *fmt = "TLS negotiation failed: %s"; - *fallback = "TLS negotiation failed"; + *fmt = "%s"; + *fallback = reason[0] ? reason : "TLS negotiation failed"; } return res; @@ -1099,8 +1137,14 @@ static int tls_negotiate_client(struct Client *cptr, char **fmt, char **fallback /** Continue client setup after an inbound or outbound TLS handshake completes. */ static void tls_handshake_succeeded(struct Client *cptr) { - if (IsConnecting(cptr)) - completed_connection(cptr); + if (IsConnecting(cptr)) { + /* completed_connection() returns 0 when the link can no longer be set up + * (e.g. the Connect block vanished on a rehash mid-handshake). Exit the + * client instead of leaving it half-initialized until the ping timeout, + * matching the ET_CONNECT path. */ + if (!completed_connection(cptr) && !IsDead(cptr)) + exit_client(cptr, cptr, &me, "Connection setup failed"); + } else if (!cli_auth(cptr)) start_auth(cptr); } @@ -1185,9 +1229,9 @@ static void client_sock_callback(struct Event* ev) /* Still negotiating */ break; } - /* TLS negotiation succeeded */ - tls_handshake_succeeded(cptr); - return; + /* TLS negotiation succeeded */ + tls_handshake_succeeded(cptr); + return; } ClrFlag(cptr, FLAG_BLOCKED); if (cli_listing(cptr) && MsgQLength(&(cli_sendQ(cptr))) < 2048) diff --git a/ircd/send.c b/ircd/send.c index 02950c93..15603714 100644 --- a/ircd/send.c +++ b/ircd/send.c @@ -90,6 +90,9 @@ static void dead_link(struct Client *to, char *notice) */ DBufClear(&(cli_recvQ(to))); MsgQClear(&(cli_sendQ(to))); + /* MsgQClear frees MsgBufs; drop TLS mid-message rexmit into them. */ + cli_connect(to)->con_rexmit = NULL; + cli_connect(to)->con_rexmit_len = 0; client_drop_sendq(cli_connect(to)); /* diff --git a/ircd/test/Makefile.am b/ircd/test/Makefile.am index ee24a8af..0f883961 100644 --- a/ircd/test/Makefile.am +++ b/ircd/test/Makefile.am @@ -1,7 +1,7 @@ AM_CPPFLAGS = -I$(top_srcdir)/include -I../.. AM_CFLAGS = -g -Wall -check_PROGRAMS = cidr_lookups_t ircd_chattr_t ircd_in_addr_t ircd_match_t ircd_string_t +check_PROGRAMS = cidr_lookups_t ircd_chattr_t ircd_in_addr_t ircd_match_t ircd_string_t msgq_excise_t TESTS = $(check_PROGRAMS) @@ -9,6 +9,10 @@ cidr_lookups_t_CPPFLAGS = $(AM_CPPFLAGS) -DIRCU2_BUILD cidr_lookups_t_SOURCES = cidr_lookups_t.c test_stub.c cidr_lookups_t_LDADD = ../cidr_lookups.o ../ircd_alloc.o ../ircd_string.o +msgq_excise_t_CPPFLAGS = $(AM_CPPFLAGS) -DIRCU2_BUILD +msgq_excise_t_SOURCES = msgq_excise_t.c test_stub.c +msgq_excise_t_LDADD = ../msgq.o ../ircd_snprintf.o ../ircd_alloc.o ../ircd_string.o + ircd_chattr_t_SOURCES = ircd_chattr_t.c test_stub.c ircd_chattr_t_LDADD = ../ircd_string.o diff --git a/ircd/test/msgq_excise_t.c b/ircd/test/msgq_excise_t.c new file mode 100644 index 00000000..14fe167d --- /dev/null +++ b/ircd/test/msgq_excise_t.c @@ -0,0 +1,188 @@ +/* msgq_excise_t.c - unit test for identity-based removal of a drained + * TLS partial-write remainder (msgq_excise()). + * + * Regression for the send-path finding where a con_rexmit remainder that + * finished draining was removed from the sendq by byte count (via + * msgq_delete()) instead of by identity. msgq_delete() deletes in + * (partial-normal, prio, normal) order, so a priority message enqueued while + * the socket was blocked would be deleted in place of the drained normal + * message -- re-sending the normal message's tail as duplicate bytes and + * dropping the priority message. msgq_excise() removes the exact message the + * remainder points into, regardless of what jumped ahead of it. + */ + +#include "client.h" +#include "ircd_features.h" +#include "ircd_log.h" +#include "msgq.h" + +#include +#include +#include + +extern struct Client me; + +/* --- stubs for symbols pulled in by msgq.o that these tests never reach --- */ +int feature_bool(enum Feature feat) { (void)feat; return 0; } +/* Large enough for FEAT_BUFFERPOOL so msgq_alloc() actually allocates. */ +int feature_int(enum Feature feat) { (void)feat; return 1 << 20; } +void flush_connections(struct Client *cptr) { (void)cptr; } +void kill_highest_sendq(int servers_too) { (void)servers_too; } +int send_reply(struct Client *to, int reply, ...) { (void)to; (void)reply; return 0; } +void server_panic(const char *message) { (void)message; } +const char *visible_username(const struct Client *cptr) { (void)cptr; return ""; } + +/** Build a queued MsgBuf carrying \a text (msgq_make appends CRLF). */ +static struct MsgBuf *mk(const char *text) +{ + return msgq_make(&me, "%s", text); +} + +/** Map \a mq and return the base pointer of segment \a want, or NULL. */ +static const char *seg_base(struct MsgQ *mq, int want, int *n_out) +{ + struct iovec iov[16]; + unsigned int len = 0; + int n = msgq_mapiov(mq, iov, sizeof(iov) / sizeof(iov[0]), &len); + + if (n_out) + *n_out = n; + return (want >= 0 && want < n) ? (const char *)iov[want].iov_base : 0; +} + +/** True if the first mapped segment of \a mq begins with \a text. */ +static int first_is(struct MsgQ *mq, const char *text) +{ + int n; + const char *base = seg_base(mq, 0, &n); + + return n >= 1 && base && !strncmp(base, text, strlen(text)); +} + +/* A whole normal message is deferred (con_rexmit), a priority message is + * enqueued while the socket is blocked, then the normal message finishes + * draining and is excised. The priority message must survive untouched. */ +static void +test_excise_normal_keeps_prio(void) +{ + struct MsgQ mq; + const char *base; + unsigned int len_norm, len_ping; + int n; + + msgq_init(&mq); + + msgq_add(&mq, mk("NORMALMSG"), 0); /* normal message, sent == 0 */ + len_norm = mq.length; + + /* con_rexmit captures the normal message's pointer via msgq_mapiov, + * exactly as ircd_tls_sendv does, before any priority message exists. */ + base = seg_base(&mq, 0, &n); + assert(n == 1); + + msgq_add(&mq, mk("PING"), 1); /* prio jumps ahead while blocked */ + len_ping = mq.length - len_norm; + assert(mq.count == 2); + + msgq_excise(&mq, base); /* finished draining -> remove it */ + + assert(mq.count == 1); /* only the PING remains */ + assert(mq.length == len_ping); + assert(first_is(&mq, "PING")); /* PING never deleted, still queued */ + + MsgQClear(&mq); + printf("Passed: excise removes drained normal msg, keeps priority msg\n"); +} + +/* con_rexmit points into the MIDDLE of the message (a multi-partial drain + * advanced it); excise must still match by buffer containment. */ +static void +test_excise_matches_mid_message(void) +{ + struct MsgQ mq; + const char *base; + int n; + + msgq_init(&mq); + msgq_add(&mq, mk("A-LONGER-NORMAL-MESSAGE"), 0); + + base = seg_base(&mq, 0, &n); + assert(n == 1 && base); + + msgq_add(&mq, mk("PING"), 1); + + msgq_excise(&mq, base + 7); /* mid-message pointer */ + + assert(mq.count == 1); + assert(first_is(&mq, "PING")); + + MsgQClear(&mq); + printf("Passed: excise matches a mid-message con_rexmit pointer\n"); +} + +/* con_rexmit can also point into a priority message; excise it from the + * priority queue while leaving the normal message queued. */ +static void +test_excise_prio_keeps_normal(void) +{ + struct MsgQ mq; + struct iovec iov[4]; + const char *ping_base; + unsigned int len = 0; + int n; + + msgq_init(&mq); + msgq_add(&mq, mk("NORMALMSG"), 0); + msgq_add(&mq, mk("PINGPRIO"), 1); + + /* mapiov order is (partial-normal, prio, normal); with no partial-normal + * head the priority message is mapped first. */ + n = msgq_mapiov(&mq, iov, 4, &len); + assert(n == 2); + ping_base = iov[0].iov_base; + assert(!strncmp(ping_base, "PINGPRIO", 8)); + + msgq_excise(&mq, ping_base); + + assert(mq.count == 1); + assert(first_is(&mq, "NORMALMSG")); + + MsgQClear(&mq); + printf("Passed: excise removes a priority msg, keeps normal msg\n"); +} + +/* With no priority message present, excise simply removes the head. */ +static void +test_excise_single_normal(void) +{ + struct MsgQ mq; + const char *base; + int n; + + msgq_init(&mq); + msgq_add(&mq, mk("ONLYMSG"), 0); + base = seg_base(&mq, 0, &n); + assert(n == 1 && base); + + msgq_excise(&mq, base); + + assert(mq.count == 0); + assert(mq.length == 0); + + printf("Passed: excise removes a lone normal msg\n"); +} + +int +main(int argc, char *argv[]) +{ + (void)argc; + (void)argv; + + test_excise_normal_keeps_prio(); + test_excise_matches_mid_message(); + test_excise_prio_keeps_normal(); + test_excise_single_normal(); + + printf("All msgq_excise tests passed.\n"); + return 0; +} diff --git a/ircd/tls_gnutls.c b/ircd/tls_gnutls.c index d4103edd..d024ce29 100644 --- a/ircd/tls_gnutls.c +++ b/ircd/tls_gnutls.c @@ -25,6 +25,7 @@ #include "ircd_tls.h" #include "ircd.h" #include "ircd_log.h" +#include "ircd_snprintf.h" #include "ircd_string.h" #include "client.h" #include "s_auth.h" @@ -37,11 +38,24 @@ #include #include #include +#include #include #include #include #include +/** Fill \a reason (if non-NULL) with a formatted TLS failure description. */ +static void tls_reason(char *reason, size_t reasonlen, const char *fmt, ...) +{ + va_list vl; + + if (!reason || reasonlen == 0) + return; + va_start(vl, fmt); + ircd_vsnprintf(0, reason, reasonlen, fmt, vl); + va_end(vl); +} + #if defined(GNUTLS_AUTO_REAUTH) /* 3.6.4 */ # define TLS_SESSION_FLAGS GNUTLS_NONBLOCK | GNUTLS_NO_SIGNAL \ | GNUTLS_POST_HANDSHAKE_AUTH | GNUTLS_AUTH_REAUTH \ @@ -375,7 +389,13 @@ int ircd_tls_check_peer_hostname(struct Client *cptr, const char *name) void ircd_tls_close(void *ctx, const char *message) { - gnutls_bye(ctx, GNUTLS_SHUT_RDWR); + /* Match OpenSSL SSL_is_init_finished() / libtls tls_close(): only send + * close_notify after a completed handshake. ircd_tls_negotiate() marks + * success via the session pointer; gnutls_protocol_get_version() is not + * usable for this (it is already set before any ClientHello arrives), so + * a stalled handshake would otherwise get a TLS alert instead of TCP EOF. */ + if (gnutls_session_get_ptr(ctx)) + gnutls_bye(ctx, GNUTLS_SHUT_WR); gnutls_deinit(ctx); } @@ -417,7 +437,7 @@ void ircd_tls_listen_free(struct Listener *listener) } } -int ircd_tls_negotiate(struct Client *cptr) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) { gnutls_session_t tls; gnutls_x509_crt_t crt; @@ -425,15 +445,26 @@ int ircd_tls_negotiate(struct Client *cptr) size_t len; int res; unsigned char buf[32]; + const char* const err_certreq = "ERROR :TLS certificate required\r\n"; + const char* const err_certrej = "ERROR :TLS certificate rejected\r\n"; + const char* const err_handshake = "ERROR :TLS handshake failed\r\n"; + + if (reason && reasonlen) + reason[0] = '\0'; tls = s_tls(&cli_socket(cptr)); - if (!tls) - return 1; + if (!tls) { + tls_reason(reason, reasonlen, "TLS setup failed (no session)"); + ClearNegotiatingTLS(cptr); + return -1; + } /* Check for handshake timeout - use the constant from header */ if (CurrentTime - cli_firsttime(cptr) > TLS_HANDSHAKE_TIMEOUT) { Debug((DEBUG_DEBUG, "GnuTLS handshake timeout for %s", cli_name(cptr))); + /* No peer write: a stalled handshake must close with a plain EOF. */ + tls_reason(reason, reasonlen, "TLS handshake timed out"); return -1; } @@ -453,6 +484,9 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, "TLS peer certificate required but not presented for %s", cli_name(cptr))); + tls_reason(reason, reasonlen, + "no peer certificate presented (certificate required)"); + write(cli_fd(cptr), err_certreq, strlen(err_certreq)); return -1; } @@ -473,19 +507,36 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, "TLS peer certificate verification failed for %s: %s", cli_name(cptr), gnutls_strerror(res))); + tls_reason(reason, reasonlen, "certificate verification error: %s", + gnutls_strerror(res)); + write(cli_fd(cptr), err_certrej, strlen(err_certrej)); return -1; } if (vstatus != 0) { + gnutls_datum_t out; + Debug((DEBUG_DEBUG, "TLS peer certificate verification failed for %s (0x%x)", cli_name(cptr), vstatus)); + if (gnutls_certificate_verification_status_print(vstatus, GNUTLS_CRT_X509, + &out, 0) >= 0) + { + tls_reason(reason, reasonlen, "certificate verification failed: %s", + out.data); + gnutls_free(out.data); + } + else + tls_reason(reason, reasonlen, + "certificate verification failed (0x%x)", vstatus); + write(cli_fd(cptr), err_certrej, strlen(err_certrej)); return -1; } } if (!datum) { + gnutls_session_set_ptr(tls, (void *)1); /* handshake complete: see ircd_tls_close() */ ClearNegotiatingTLS(cptr); return 1; } @@ -498,26 +549,31 @@ int ircd_tls_negotiate(struct Client *cptr) return -1; } - /* Complete the fingerprint extraction - convert buf to hex */ + /* Extract the SHA-256 fingerprint. If the certificate cannot be + * re-parsed or hashed, treat it like "no fingerprint" (len = 0 takes the + * empty-fingerprint branch below) and still complete the handshake, as the + * OpenSSL and libtls backends do. Returning early here would leave + * FLAG_NEGOTIATING_TLS set and wedge the connection. */ res = gnutls_x509_crt_import(crt, datum, GNUTLS_X509_FMT_DER); if (res) { log_write(LS_SYSTEM, L_ERROR, 0, "gnutls_x509_crt_import failed for %s: %d", cli_name(cptr), res); - gnutls_x509_crt_deinit(crt); - return 1; + len = 0; } - - len = sizeof(buf); - res = gnutls_x509_crt_get_fingerprint(crt, GNUTLS_DIG_SHA256, buf, &len); - gnutls_x509_crt_deinit(crt); - if (res) + else { - log_write(LS_SYSTEM, L_ERROR, 0, "gnutls_x509_crt_get_fingerprint failed for %s: %d", - cli_name(cptr), res); - return 1; + len = sizeof(buf); + res = gnutls_x509_crt_get_fingerprint(crt, GNUTLS_DIG_SHA256, buf, &len); + if (res) + { + log_write(LS_SYSTEM, L_ERROR, 0, "gnutls_x509_crt_get_fingerprint failed for %s: %d", + cli_name(cptr), res); + len = 0; + } } - + gnutls_x509_crt_deinit(crt); + /* Convert buf to hex like OpenSSL version */ if (len == 32 && !IsCloudflarePort(cptr)) { char *p = cli_tls_fingerprint(cptr); @@ -535,6 +591,7 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, "Invalid fingerprint length: %zu", len)); } + gnutls_session_set_ptr(tls, (void *)1); /* handshake complete: see ircd_tls_close() */ ClearNegotiatingTLS(cptr); return 1; @@ -542,9 +599,9 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, " ... gnutls_handshake() failed -> %s (%d)", gnutls_strerror(res), res)); if (gnutls_error_is_fatal(res)) { - const char* const error_tls = "ERROR :TLS connection error\r\n"; Debug((DEBUG_DEBUG, "GnuTLS handshake failed for %s: %s", cli_name(cptr), gnutls_strerror(res))); - write(cli_fd(cptr), error_tls, strlen(error_tls)); + tls_reason(reason, reasonlen, "%s", gnutls_strerror(res)); + write(cli_fd(cptr), err_handshake, strlen(err_handshake)); return -1; } return 0; @@ -568,6 +625,14 @@ IOResult ircd_tls_recv(struct Client *cptr, char *buf, *count_out = res; return IO_SUCCESS; } + /* + * Peer cleanly closed (close_notify) or EOF. gnutls_error_is_fatal(0) is + * false, so treating this as IO_BLOCKED leaves the socket open while the + * client waits for our close_notify (asyncio SSL_SHUTDOWN_TIMEOUT = 30s). + * Match OpenSSL SSL_ERROR_ZERO_RETURN → IO_FAILURE. + */ + if (res == 0) + return IO_FAILURE; if (res == GNUTLS_E_REHANDSHAKE) { res = gnutls_handshake(tls); @@ -585,9 +650,10 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, struct iovec iov[512]; gnutls_session_t tls; struct Connection *con; - IOResult result = IO_BLOCKED; ssize_t res; int ii, count; + int made_progress = 0; + IOResult result; con = cli_connect(cptr); tls = s_tls(&con_socket(con)); @@ -600,28 +666,36 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, * has been accepted or must be provided to a future call to * gnutls_record_send()? */ + *count_in = 0; *count_out = 0; if (con->con_rexmit) { - res = gnutls_record_send(tls, con->con_rexmit, con->con_rexmit_len); - if (res <= 0) { - if (res == GNUTLS_E_INTERRUPTED || res == GNUTLS_E_AGAIN) - return IO_BLOCKED; - return gnutls_error_is_fatal(res) ? IO_FAILURE : IO_BLOCKED; - } + /* Drain the unfinished head message, then remove it by identity with + * msgq_excise(). Its bytes are NOT added to *count_out — see the OpenSSL + * backend for why (msgq_delete() would misattribute them to a priority + * message enqueued while we were blocked). */ + const char *rexmit_base = con->con_rexmit; - // Only excise the message if the full message was sent - if (res == (int)con->con_rexmit_len) { - msgq_excise(buf, con->con_rexmit, con->con_rexmit_len); - con->con_rexmit_len = 0; - con->con_rexmit = NULL; - result = IO_SUCCESS; - } else { - // Partial send, update pointer and length for next retry - con->con_rexmit = (char *)con->con_rexmit + res; - con->con_rexmit_len -= res; - return IO_BLOCKED; + while (con->con_rexmit) + { + res = gnutls_record_send(tls, con->con_rexmit, con->con_rexmit_len); + if (res <= 0) { + if (res == GNUTLS_E_INTERRUPTED || res == GNUTLS_E_AGAIN) + return IO_BLOCKED; + *count_out = 0; + return gnutls_error_is_fatal(res) ? IO_FAILURE : IO_BLOCKED; + } + if (res == (int)con->con_rexmit_len) { + con->con_rexmit_len = 0; + con->con_rexmit = NULL; + } else { + con->con_rexmit = (char *)con->con_rexmit + res; + con->con_rexmit_len -= (size_t)res; + } } + msgq_excise(buf, rexmit_base); + made_progress = 1; + /* fall through to send more from the now-shorter queue */ } // Process remaining messages in the queue @@ -632,12 +706,29 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, if (res > 0) { *count_out += res; - result = IO_SUCCESS; if (res < (int)iov[ii].iov_len) { - // Partial send, store for retransmission - cli_connect(cptr)->con_rexmit = (char *)iov[ii].iov_base + res; - cli_connect(cptr)->con_rexmit_len = iov[ii].iov_len - res; - return IO_BLOCKED; + con->con_rexmit = (char *)iov[ii].iov_base + res; + con->con_rexmit_len = iov[ii].iov_len - (size_t)res; + while (con->con_rexmit) + { + res = gnutls_record_send(tls, con->con_rexmit, con->con_rexmit_len); + if (res <= 0) { + if (res == GNUTLS_E_INTERRUPTED || res == GNUTLS_E_AGAIN) + return IO_BLOCKED; + result = gnutls_error_is_fatal(res) ? IO_FAILURE : IO_BLOCKED; + if (result == IO_FAILURE) + *count_out = 0; + return result; + } + *count_out += (unsigned int)res; + if (res == (int)con->con_rexmit_len) { + con->con_rexmit_len = 0; + con->con_rexmit = NULL; + } else { + con->con_rexmit = (char *)con->con_rexmit + res; + con->con_rexmit_len -= (size_t)res; + } + } } // else, full message sent, continue to next continue; @@ -645,14 +736,17 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, /* We only reach this if the gnutls_record_send failed. */ if (res == GNUTLS_E_INTERRUPTED || res == GNUTLS_E_AGAIN) { - cli_connect(cptr)->con_rexmit = iov[ii].iov_base; - cli_connect(cptr)->con_rexmit_len = iov[ii].iov_len; + con->con_rexmit = iov[ii].iov_base; + con->con_rexmit_len = iov[ii].iov_len; + return IO_BLOCKED; } result = gnutls_error_is_fatal(res) ? IO_FAILURE : IO_BLOCKED; - break; + if (result == IO_FAILURE) + *count_out = 0; + return result; } - return result; + return (*count_out || made_progress) ? IO_SUCCESS : IO_BLOCKED; } int ircd_tls_sha1_base64(const void *data, size_t len, char *out, size_t outlen) diff --git a/ircd/tls_libtls.c b/ircd/tls_libtls.c index f85e5c3f..ee8237df 100644 --- a/ircd/tls_libtls.c +++ b/ircd/tls_libtls.c @@ -25,6 +25,7 @@ #include "ircd_features.h" #include "ircd.h" #include "ircd_log.h" +#include "ircd_snprintf.h" #include "ircd_string.h" #include "ircd_tls.h" #include "listener.h" @@ -34,6 +35,7 @@ #include "s_debug.h" #include "ircd_sha1.h" +#include #include #include #include @@ -41,6 +43,18 @@ #include #include +/** Fill \a reason (if non-NULL) with a formatted TLS failure description. */ +static void tls_reason(char *reason, size_t reasonlen, const char *fmt, ...) +{ + va_list vl; + + if (!reason || reasonlen == 0) + return; + va_start(vl, fmt); + ircd_vsnprintf(0, reason, reasonlen, fmt, vl); + va_end(vl); +} + #define STRINGIFY(x) #x #define TOSTRING(x) STRINGIFY(x) const char *ircd_tls_version = "libtls " TOSTRING(TLS_API); @@ -513,20 +527,30 @@ void ircd_tls_listen_free(struct Listener *listener) } } -int ircd_tls_negotiate(struct Client *cptr) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) { const char *hash; struct tls *tls; int res; - const char* const error_tls = "ERROR :TLS connection error\r\n"; + const char* const err_certreq = "ERROR :TLS certificate required\r\n"; + const char* const err_certrej = "ERROR :TLS certificate rejected\r\n"; + const char* const err_handshake = "ERROR :TLS handshake failed\r\n"; + + if (reason && reasonlen) + reason[0] = '\0'; tls = s_tls(&cli_socket(cptr)); - if (!tls) - return 1; + if (!tls) { + tls_reason(reason, reasonlen, "TLS setup failed (no session)"); + ClearNegotiatingTLS(cptr); + return -1; + } /* Check for handshake timeout */ if (CurrentTime - cli_firsttime(cptr) > TLS_HANDSHAKE_TIMEOUT) { Debug((DEBUG_DEBUG, "libtls handshake timeout for %s", cli_name(cptr))); + /* No peer write: a stalled handshake must close with a plain EOF. */ + tls_reason(reason, reasonlen, "TLS handshake timed out"); return -1; } @@ -541,6 +565,9 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, "TLS peer certificate required but not presented for %s", cli_name(cptr))); + tls_reason(reason, reasonlen, + "no peer certificate presented (certificate required)"); + write(cli_fd(cptr), err_certreq, strlen(err_certreq)); return -1; } @@ -549,6 +576,8 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, "TLS peer certificate verification failed for %s", cli_name(cptr))); + tls_reason(reason, reasonlen, "peer certificate could not be verified"); + write(cli_fd(cptr), err_certrej, strlen(err_certrej)); return -1; } @@ -579,14 +608,23 @@ int ircd_tls_negotiate(struct Client *cptr) return 0; /* Handshake in progress */ } - IOResult tls_result = tls_handle_error(cptr, tls, res); - if (tls_result == IO_FAILURE) { - Debug((DEBUG_DEBUG, "TLS handshake failed for %s", cli_name(cptr))); - write(cli_fd(cptr), error_tls, strlen(error_tls)); - return -1; + { + const char *tls_err = tls_error(tls); /* before tls_handle_error frees it */ + IOResult tls_result; + + if (tls_err) + tls_reason(reason, reasonlen, "%s", tls_err); + tls_result = tls_handle_error(cptr, tls, res); + if (tls_result == IO_FAILURE) { + Debug((DEBUG_DEBUG, "TLS handshake failed for %s", cli_name(cptr))); + if (!tls_err) + tls_reason(reason, reasonlen, "handshake error"); + write(cli_fd(cptr), err_handshake, strlen(err_handshake)); + return -1; + } + /* tls_result == IO_BLOCKED - handshake still in progress */ + return 0; } - /* tls_result == IO_BLOCKED - handshake still in progress */ - return 0; } IOResult ircd_tls_recv(struct Client *cptr, char *buf, @@ -617,6 +655,7 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, struct Connection *con; IOResult result = IO_BLOCKED; int ii, count, res; + int made_progress = 0; con = cli_connect(cptr); tls = s_tls(&con_socket(con)); @@ -624,31 +663,41 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, return IO_FAILURE; /* tls_write() does not document any restriction on retries. */ + *count_in = 0; *count_out = 0; if (con->con_rexmit) { - res = tls_write(tls, con->con_rexmit, con->con_rexmit_len); - if (res <= 0) { - if (res == TLS_WANT_POLLIN || res == TLS_WANT_POLLOUT) - return IO_BLOCKED; - return tls_handle_error(cptr, tls, res); - } + /* Drain the unfinished head message, then remove it by identity with + * msgq_excise(). Its bytes are NOT added to *count_out — see the OpenSSL + * backend for why (msgq_delete() would misattribute them to a priority + * message enqueued while we were blocked). */ + const char *rexmit_base = con->con_rexmit; - // Only excise the message if the full message was sent - if (res == (int)con->con_rexmit_len) { - msgq_excise(buf, con->con_rexmit, con->con_rexmit_len); - con->con_rexmit_len = 0; - con->con_rexmit = NULL; - result = IO_SUCCESS; - } else { - // Partial send, update pointer and length for next retry - con->con_rexmit = (char *)con->con_rexmit + res; - con->con_rexmit_len -= res; - return IO_BLOCKED; + while (con->con_rexmit) + { + res = tls_write(tls, con->con_rexmit, con->con_rexmit_len); + if (res <= 0) { + if (res == TLS_WANT_POLLIN || res == TLS_WANT_POLLOUT) + return IO_BLOCKED; + result = tls_handle_error(cptr, tls, res); + if (result == IO_FAILURE) + *count_out = 0; + return result; + } + if (res == (int)con->con_rexmit_len) { + con->con_rexmit_len = 0; + con->con_rexmit = NULL; + } else { + con->con_rexmit = (char *)con->con_rexmit + res; + con->con_rexmit_len -= (size_t)res; + } } + msgq_excise(buf, rexmit_base); + made_progress = 1; + /* fall through to send more from the now-shorter queue */ } - // Process remaining messages in the queue + /* Process remaining messages in the queue. */ count = msgq_mapiov(buf, iov, sizeof(iov) / sizeof(iov[0]), count_in); for (ii = 0; ii < count; ++ii) { @@ -656,28 +705,46 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, if (res > 0) { *count_out += res; - result = IO_SUCCESS; if (res < (int)iov[ii].iov_len) { - // Partial send, store for retransmission - cli_connect(cptr)->con_rexmit = (char *)iov[ii].iov_base + res; - cli_connect(cptr)->con_rexmit_len = iov[ii].iov_len - res; - return IO_BLOCKED; + con->con_rexmit = (char *)iov[ii].iov_base + res; + con->con_rexmit_len = iov[ii].iov_len - (size_t)res; + while (con->con_rexmit) + { + res = tls_write(tls, con->con_rexmit, con->con_rexmit_len); + if (res <= 0) { + if (res == TLS_WANT_POLLIN || res == TLS_WANT_POLLOUT) + return IO_BLOCKED; + result = tls_handle_error(cptr, tls, res); + if (result == IO_FAILURE) + *count_out = 0; + return result; + } + *count_out += (unsigned int)res; + if (res == (int)con->con_rexmit_len) { + con->con_rexmit_len = 0; + con->con_rexmit = NULL; + } else { + con->con_rexmit = (char *)con->con_rexmit + res; + con->con_rexmit_len -= (size_t)res; + } + } } - // else, full message sent, continue to next continue; } - /* We only reach this if the tls_write failed. */ + /* tls_write failed before any bytes of this iov. */ if (res == TLS_WANT_POLLIN || res == TLS_WANT_POLLOUT) { - cli_connect(cptr)->con_rexmit = iov[ii].iov_base; - cli_connect(cptr)->con_rexmit_len = iov[ii].iov_len; + con->con_rexmit = iov[ii].iov_base; + con->con_rexmit_len = iov[ii].iov_len; return IO_BLOCKED; } result = tls_handle_error(cptr, tls, res); - break; + if (result == IO_FAILURE) + *count_out = 0; + return result; } - return result; + return (*count_out || made_progress) ? IO_SUCCESS : IO_BLOCKED; } int ircd_tls_sha1_base64(const void *data, size_t len, char *out, size_t outlen) diff --git a/ircd/tls_none.c b/ircd/tls_none.c index 7bb55709..8c7a38d6 100644 --- a/ircd/tls_none.c +++ b/ircd/tls_none.c @@ -84,8 +84,10 @@ void ircd_tls_listen_free(struct Listener *listener) (void)listener; } -int ircd_tls_negotiate(struct Client *cptr) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) { + (void)reason; + (void)reasonlen; ClearNegotiatingTLS(cptr); return 1; } diff --git a/ircd/tls_openssl.c b/ircd/tls_openssl.c index 45556252..90955204 100644 --- a/ircd/tls_openssl.c +++ b/ircd/tls_openssl.c @@ -25,6 +25,7 @@ #include "ircd_alloc.h" #include "ircd_features.h" #include "ircd_log.h" +#include "ircd_snprintf.h" #include "ircd_string.h" #include "ircd_tls.h" #include "ircd.h" @@ -42,9 +43,23 @@ #include #include #include +#include +#include /* strerror() */ #include /* IOV_MAX */ #include /* write() on failure of ssl_accept() */ +/** Fill \a reason (if non-NULL) with a formatted TLS failure description. */ +static void tls_reason(char *reason, size_t reasonlen, const char *fmt, ...) +{ + va_list vl; + + if (!reason || reasonlen == 0) + return; + va_start(vl, fmt); + ircd_vsnprintf(0, reason, reasonlen, fmt, vl); + va_end(vl); +} + const char *ircd_tls_version = OPENSSL_VERSION_TEXT; static SSL_CTX *server_ctx; /* For incoming connections */ @@ -672,14 +687,6 @@ void ircd_tls_listen_free(struct Listener *listener) } } -static void clear_tls_rexmit(struct Connection *con) -{ - if (con && con->con_rexmit) { - con->con_rexmit = NULL; - con->con_rexmit_len = 0; - } -} - static IOResult ssl_handle_error(struct Client *cptr, SSL *tls, int res, int orig_errno) { int err = SSL_get_error(tls, res); @@ -726,22 +733,36 @@ static IOResult ssl_handle_error(struct Client *cptr, SSL *tls, int res, int ori return IO_FAILURE; } -int ircd_tls_negotiate(struct Client *cptr) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) { SSL *tls; X509 *cert; unsigned int len; int res; unsigned char buf[EVP_MAX_MD_SIZE]; - const char* const error_ssl = "ERROR :SSL connection error\r\n"; + const char* const err_certreq = "ERROR :TLS certificate required\r\n"; + const char* const err_certrej = "ERROR :TLS certificate rejected\r\n"; + const char* const err_handshake = "ERROR :TLS handshake failed\r\n"; + + if (reason && reasonlen) + reason[0] = '\0'; tls = s_tls(&cli_socket(cptr)); - if (!tls) - return 1; + if (!tls) { + /* No session left to negotiate; do not report success or start_auth + * will be invoked on every subsequent ET_WRITE while FLAG_NEGOTIATING_TLS + * remains set. */ + tls_reason(reason, reasonlen, "TLS setup failed (no session)"); + ClearNegotiatingTLS(cptr); + return -1; + } /* Check for handshake timeout */ if (CurrentTime - cli_firsttime(cptr) > TLS_HANDSHAKE_TIMEOUT) { Debug((DEBUG_DEBUG, "SSL handshake timeout for fd=%d", cli_fd(cptr))); + /* No peer write: a stalled handshake must close with a plain EOF, not a + * plaintext line (which would corrupt a mid-handshake peer's TLS stream). */ + tls_reason(reason, reasonlen, "TLS handshake timed out"); return -1; } @@ -758,7 +779,9 @@ int ircd_tls_negotiate(struct Client *cptr) { Debug((DEBUG_DEBUG, "TLS peer certificate required but not presented for %C", cptr)); - write(cli_fd(cptr), error_ssl, strlen(error_ssl)); + tls_reason(reason, reasonlen, + "no peer certificate presented (certificate required)"); + write(cli_fd(cptr), err_certreq, strlen(err_certreq)); return -1; } @@ -771,9 +794,11 @@ int ircd_tls_negotiate(struct Client *cptr) Debug((DEBUG_DEBUG, "TLS peer certificate verification failed for %C: %ld", cptr, vr)); + tls_reason(reason, reasonlen, "certificate verification failed: %s", + X509_verify_cert_error_string(vr)); if (cert) X509_free(cert); - write(cli_fd(cptr), error_ssl, strlen(error_ssl)); + write(cli_fd(cptr), err_certrej, strlen(err_certrej)); return -1; } } @@ -808,22 +833,38 @@ int ircd_tls_negotiate(struct Client *cptr) } } ClearNegotiatingTLS(cptr); + /* X509_digest may have overwritten res; handshake itself succeeded. */ + return 1; } - else + { int orig_errno = errno; + int sslerr = SSL_get_error(tls, res); + long vr = SSL_get_verify_result(tls); + unsigned long queued = ERR_peek_last_error(); /* before ssl_handle_error drains */ /* Handshake in progress. */ IOResult ssl_result = ssl_handle_error(cptr, tls, res, orig_errno); if (ssl_result == IO_FAILURE) { Debug((DEBUG_DEBUG, "SSL handshake failed for fd=%d", cli_fd(cptr))); - write(cli_fd(cptr), error_ssl, strlen(error_ssl)); + if (vr != X509_V_OK) + /* Handshake aborted on certificate verification: report the exact + * X509 error. SSL_get_verify_result() is set during verification, + * so it is available even though SSL_accept()/SSL_connect() failed. */ + tls_reason(reason, reasonlen, "%s", X509_verify_cert_error_string(vr)); + else if (queued) + tls_reason(reason, reasonlen, "%s", ERR_reason_error_string(queued)); + else if (sslerr == SSL_ERROR_ZERO_RETURN) + tls_reason(reason, reasonlen, "peer closed connection"); + else if (sslerr == SSL_ERROR_SYSCALL && orig_errno) + tls_reason(reason, reasonlen, "%s", strerror(orig_errno)); + else + tls_reason(reason, reasonlen, "handshake error"); + write(cli_fd(cptr), err_handshake, strlen(err_handshake)); return -1; } /* ssl_result == IO_BLOCKED - handshake still in progress */ return 0; } - - return res; } IOResult ircd_tls_recv(struct Client *cptr, char *buf, @@ -856,38 +897,53 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, struct iovec iov[512]; SSL *tls; struct Connection *con; - IOResult result = IO_BLOCKED; int ii, count, res, orig_errno; + int made_progress = 0; + IOResult io; con = cli_connect(cptr); tls = s_tls(&con_socket(con)); if (!tls) return IO_FAILURE; + *count_in = 0; *count_out = 0; if (con->con_rexmit) { - ERR_clear_error(); - res = SSL_write(tls, con->con_rexmit, con->con_rexmit_len); - if (res <= 0) { - orig_errno = errno; - return ssl_handle_error(cptr, tls, res, orig_errno); - } - - // Only excise the message if the full message was sent - if (res == (int)con->con_rexmit_len) { - msgq_excise(buf, con->con_rexmit, con->con_rexmit_len); - con->con_rexmit_len = 0; - con->con_rexmit = NULL; - result = IO_SUCCESS; - } else { - // Partial send, update pointer and length for next retry - con->con_rexmit = (char *)con->con_rexmit + res; - con->con_rexmit_len -= res; - return IO_BLOCKED; + /* con_rexmit is a raw pointer into the head queued message left + * unfinished by a prior partial SSL_write. Drain it to completion (a + * short SSL_write does not mean the socket is full under + * SSL_MODE_ENABLE_PARTIAL_WRITE), then remove that exact message from the + * queue by identity with msgq_excise(). These bytes are deliberately NOT + * added to *count_out: msgq_delete() deletes in (partial-normal, prio, + * normal) order, so crediting a whole normal message here would instead + * delete a priority message that jumped ahead while we were blocked. */ + const char *rexmit_base = con->con_rexmit; + + while (con->con_rexmit) + { + ERR_clear_error(); + res = SSL_write(tls, con->con_rexmit, (int)con->con_rexmit_len); + if (res <= 0) { + orig_errno = errno; + io = ssl_handle_error(cptr, tls, res, orig_errno); + if (io == IO_FAILURE) + *count_out = 0; + return io; + } + if (res == (int)con->con_rexmit_len) { + con->con_rexmit_len = 0; + con->con_rexmit = NULL; + } else { + con->con_rexmit = (char *)con->con_rexmit + res; + con->con_rexmit_len -= (size_t)res; + } } + msgq_excise(buf, rexmit_base); + made_progress = 1; + /* fall through to send more from the now-shorter queue */ } - // Process remaining messages in the queue + /* Process remaining messages in the queue. */ count = msgq_mapiov(buf, iov, sizeof(iov) / sizeof(iov[0]), count_in); for (ii = 0; ii < count; ++ii) { @@ -896,25 +952,46 @@ IOResult ircd_tls_sendv(struct Client *cptr, struct MsgQ *buf, if (res > 0) { *count_out += res; - result = IO_SUCCESS; if (res < (int)iov[ii].iov_len) { - // Partial send, store for retransmission - cli_connect(cptr)->con_rexmit = (char *)iov[ii].iov_base + res; - cli_connect(cptr)->con_rexmit_len = iov[ii].iov_len - res; - return IO_BLOCKED; + con->con_rexmit = (char *)iov[ii].iov_base + res; + con->con_rexmit_len = iov[ii].iov_len - (size_t)res; + /* Finish this message or stop on real TLS block. These bytes are + * in mapiov order, so they are safe to credit to *count_out. */ + while (con->con_rexmit) + { + ERR_clear_error(); + res = SSL_write(tls, con->con_rexmit, (int)con->con_rexmit_len); + if (res <= 0) { + orig_errno = errno; + io = ssl_handle_error(cptr, tls, res, orig_errno); + if (io == IO_FAILURE) + *count_out = 0; + return io; + } + *count_out += (unsigned int)res; + if (res == (int)con->con_rexmit_len) { + con->con_rexmit_len = 0; + con->con_rexmit = NULL; + } else { + con->con_rexmit = (char *)con->con_rexmit + res; + con->con_rexmit_len -= (size_t)res; + } + } } - // else, full message sent, continue to next continue; } - /* We only reach this if the SSL_write failed. */ + /* SSL_write failed before any bytes of this iov were accepted. */ orig_errno = errno; - cli_connect(cptr)->con_rexmit = iov[ii].iov_base; - cli_connect(cptr)->con_rexmit_len = iov[ii].iov_len; - return ssl_handle_error(cptr, tls, res, orig_errno); + con->con_rexmit = iov[ii].iov_base; + con->con_rexmit_len = iov[ii].iov_len; + io = ssl_handle_error(cptr, tls, res, orig_errno); + if (io == IO_FAILURE) + *count_out = 0; + return io; } - return result; + return (*count_out || made_progress) ? IO_SUCCESS : IO_BLOCKED; } int ircd_tls_sha1_base64(const void *data, size_t len, char *out, size_t outlen) diff --git a/tests/conftest.py b/tests/conftest.py index b55bb654..7afdf410 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -407,8 +407,14 @@ def pytest_runtest_makereport(item, call): report = outcome.get_result() if report.when != "call" or not report.failed: return - snapshot = snapshot_failure_artifacts(item.nodeid) - extra = format_failure_report(snapshot) + try: + snapshot = snapshot_failure_artifacts(item.nodeid) + extra = format_failure_report(snapshot) + except (OSError, subprocess.SubprocessError) as exc: + # Never abort the suite over debug capture: a root-owned failures/ dir + # raises OSError, and a hung docker daemon raises TimeoutExpired + # (a SubprocessError, not an OSError) from the inspect/logs calls. + extra = f"\n\n[debug snapshot failed: {exc}]" if extra: report.longrepr = f"{report.longrepr}{extra}" diff --git a/tests/debug_support.py b/tests/debug_support.py index 729ddc1a..7ccd6e29 100644 --- a/tests/debug_support.py +++ b/tests/debug_support.py @@ -147,7 +147,33 @@ def analyze_core_postmortem(core: Path, dest: Path) -> str: return text -def container_state(container: str = HUB_CONTAINER) -> str: +def running_hub_containers() -> list[str]: + """Return hub-like container names that are currently present. + + Prefer tls-hub when both exist; snapshots used to hard-code ircu-hub and + silently missed TLS topology failures. + """ + preferred = ("ircu-tls-hub", "ircu-hub", "ircu-limits") + found: list[str] = [] + for name in preferred: + result = subprocess.run( + ["docker", "inspect", "-f", "{{.State.Status}}", name], + capture_output=True, + text=True, + timeout=15, + ) + if result.returncode == 0 and result.stdout.strip(): + found.append(name) + if found: + return found + # Fall back so callers still attempt the historical default. + return [HUB_CONTAINER] + + +def container_state(container: str | None = None) -> str: + if container is None: + states = [f"{name}: {container_state(name)}" for name in running_hub_containers()] + return "; ".join(states) result = subprocess.run( [ "docker", @@ -165,7 +191,12 @@ def container_state(container: str = HUB_CONTAINER) -> str: return result.stdout.strip() -def docker_logs(container: str = HUB_CONTAINER, tail: int = 500) -> str: +def docker_logs(container: str | None = None, tail: int = 500) -> str: + if container is None: + chunks: list[str] = [] + for name in running_hub_containers(): + chunks.append(f"===== {name} =====\n{docker_logs(name, tail=tail)}") + return "\n".join(chunks) result = subprocess.run( ["docker", "logs", "--tail", str(tail), container], capture_output=True, @@ -207,11 +238,22 @@ def _copy_asan_logs(dest: Path) -> list[str]: def snapshot_failure_artifacts(test_nodeid: str) -> Path | None: - """Save hub logs and debug files for a failed test; return snapshot dir.""" + """Save hub logs and debug files for a failed test; return snapshot dir. + + Raises OSError if the snapshot directory cannot be created (caller should + catch so a permissions problem never aborts the pytest session). + """ stamp = datetime.now().strftime("%Y%m%d-%H%M%S") safe_name = test_nodeid.replace("/", "_").replace("::", "__") dest = FAILURES_DIR / f"{safe_name}__{stamp}" - dest.mkdir(parents=True, exist_ok=True) + try: + FAILURES_DIR.mkdir(parents=True, exist_ok=True) + dest.mkdir(parents=True, exist_ok=True) + except PermissionError: + # Root-owned leftover from a prior docker/sudo run: fall back under /tmp + # so we still capture logs without poisoning the pytest session. + dest = Path("/tmp") / "ircu2-test-failures" / f"{safe_name}__{stamp}" + dest.mkdir(parents=True, exist_ok=True) state = container_state() (dest / "container-state.txt").write_text(state + "\n", encoding="utf-8") diff --git a/tests/docker/ircd-tls-hub.conf b/tests/docker/ircd-tls-hub.conf index 14fc8890..ccd571a1 100644 --- a/tests/docker/ircd-tls-hub.conf +++ b/tests/docker/ircd-tls-hub.conf @@ -205,4 +205,9 @@ Features { "CONFIG_OPERCMDS" = "TRUE"; "TLS_SYSTEMCA" = "FALSE"; "PPATH" = "ircd-tls-hub.pid"; + # The TLS stress tests open many concurrent connections from the single + # docker-network IP; keep IPcheck clone throttling from tripping (matches + # the plaintext hub config). + "IPCHECK_CLONE_LIMIT" = "1000"; + "IPCHECK_CLONE_PERIOD" = "1"; }; diff --git a/tests/pyproject.toml b/tests/pyproject.toml index b7f9b1db..096275b0 100644 --- a/tests/pyproject.toml +++ b/tests/pyproject.toml @@ -22,6 +22,7 @@ markers = [ "tls: tests that need the TLS hub + leaf containers", "dns: tests that need the DNS test server and DNS-enabled ircd containers", "tls_single: tests that need only the TLS hub (no peer servers)", + "tls_stress: concurrent TLS registration / AUTH-drop stress (tls/)", "websocket_stress: aggressive WebSocket load / edge-case tests (pr_websocket/, hub + port 7000)", "limits: tests that need the dedicated limits server", "nf_compat: NETWORK_FEATURES A(prod)-B(NF=FALSE)-C(NF=TRUE) topology", diff --git a/tests/stats_ports/__init__.py b/tests/stats_ports/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/tests/stats_ports/test_stats_p.py b/tests/stats_ports/test_stats_p.py new file mode 100644 index 00000000..03b92550 --- /dev/null +++ b/tests/stats_ports/test_stats_p.py @@ -0,0 +1,101 @@ +"""Regression test for STATS p (listening ports).""" + +import pytest + +from irc_client import IRCClient + + +@pytest.mark.single_server +async def test_stats_p_lists_ports(ircd_hub): + """An oper issuing STATS p must receive RPL_STATSPLINE (217) lines.""" + client = IRCClient() + await client.connect(ircd_hub["host"], ircd_hub["port"]) + await client.register("statsp", "testuser", "Test User") + try: + await client.send("OPER testoper operpass") + await client.wait_for("381") + + await client.send("STATS p") + msgs = await client.collect_until("219", timeout=5.0) + plines = [m for m in msgs if m.command == "217"] + print("STATS p replies:", [(m.command, m.params) for m in msgs]) + assert msgs[-1].command == "219" + assert plines, f"STATS p returned no 217 lines: {[(m.command, m.params) for m in msgs]}" + ports = {int(m.params[2]) for m in plines} + assert {4400, 6667, 7000, 7001, 7002} <= ports, ports + + # Long-form alias and port filter. + await client.send("STATS ports") + msgs = await client.collect_until("219", timeout=5.0) + assert [m for m in msgs if m.command == "217"], msgs + + await client.send("STATS p hub.test.net 6667") + msgs = await client.collect_until("219", timeout=5.0) + plines = [m for m in msgs if m.command == "217"] + assert len(plines) == 1 and plines[0].params[2] == "6667", [(m.command, m.params) for m in msgs] + finally: + try: + await client.send("QUIT :cleanup") + except Exception: + pass + await client.disconnect() + + +async def _oper_client(host, port, nick): + client = IRCClient() + await client.connect(host, port) + await client.register(nick, "testuser", "Test User") + await client.send("OPER testoper operpass") + await client.wait_for("381") + return client + + +async def _stats_p(client, extra=""): + await client.send(f"STATS p{extra}") + msgs = await client.collect_until("219", timeout=5.0) + return [m for m in msgs if m.command == "217"], msgs + + +@pytest.mark.multi_server +async def test_stats_p_remote_and_after_rehash(ircd_network): + """STATS p hunted to a remote server, and STATS p after REHASH.""" + leaf1 = ircd_network["leaf1"] + client = await _oper_client(leaf1["host"], leaf1["port"], "statsp2") + try: + plines, msgs = await _stats_p(client) + print("leaf1 local:", [(m.command, m.params) for m in msgs]) + assert plines, msgs + + plines, msgs = await _stats_p(client, " hub.test.net") + print("remote hub:", [(m.command, m.params) for m in msgs]) + assert plines, msgs + assert any(m.prefix == "hub.test.net" for m in plines), plines + + await client.send("REHASH") + await client.wait_for("382") + plines, msgs = await _stats_p(client) + print("leaf1 after rehash:", [(m.command, m.params) for m in msgs]) + assert plines, msgs + assert all(m.params[-1] == "active" for m in plines), plines + finally: + await client.disconnect() + + +@pytest.mark.single_server +async def test_stats_p_tls_hub(ircd_tls_hub): + """STATS p on a server with TLS/websocket/cloudflare listeners.""" + client = await _oper_client(ircd_tls_hub["host"], ircd_tls_hub["port"], "statsp3") + try: + plines, msgs = await _stats_p(client) + print("tls hub:", [(m.command, m.params) for m in msgs]) + assert plines, msgs + ports = {int(m.params[2]) for m in plines} + assert {6677, 6697, 6698, 6699, 4440, 4441, 6700, 6701} <= ports, ports + await client.send("REHASH") + await client.wait_for("382") + plines, msgs = await _stats_p(client) + print("tls hub after rehash:", [(m.command, m.params) for m in msgs]) + ports2 = {int(m.params[2]) for m in plines} + assert ports2 == ports, (ports, ports2) + finally: + await client.disconnect() diff --git a/tests/tls/helpers.py b/tests/tls/helpers.py index e4e4febd..ac0c4402 100644 --- a/tests/tls/helpers.py +++ b/tests/tls/helpers.py @@ -75,3 +75,95 @@ def is_error(msg: Message | str) -> bool: if isinstance(msg, str): return msg.upper().startswith("ERROR") return msg.command == "ERROR" + + +# --------------------------------------------------------------------------- +# Busy-channel helpers for TLS NAMES / sendq stress +# --------------------------------------------------------------------------- + +NAMES_BURST_CHANNELS = [f"#burst{i}" for i in range(4)] +NAMES_BURST_CROWD = 30 # plaintext fillers; Local class maxlinks=100 + + +async def register_and_join_channels( + host: str, port: int, nick: str, channels: list[str] +) -> IRCClient: + """Plaintext register, JOIN channels, wait for every RPL_ENDOFNAMES.""" + c = IRCClient() + await c.connect(host, port) + msgs = await c.register(nick, "crowd", "TLS burst crowd") + assert any(m.command == "001" for m in msgs), nick + await c.send("JOIN " + ",".join(channels)) + pending = {ch.lower() for ch in channels} + while pending: + msg = await c.recv(timeout=20.0) + if msg.command == "366" and len(msg.params) >= 2: + pending.discard(msg.params[1].lower()) + return c + + +async def populate_channels( + hub: dict, + channels: list[str] | None = None, + crowd: int = NAMES_BURST_CROWD, +) -> list[IRCClient]: + """Fill channels with many nicks so JOIN NAMES replies are large.""" + channels = channels or NAMES_BURST_CHANNELS + clients: list[IRCClient] = [] + batch = 10 + for start in range(0, crowd, batch): + chunk = await asyncio.gather( + *[ + register_and_join_channels( + hub["host"], hub["port"], f"crwd{i:02d}", channels + ) + for i in range(start, min(start + batch, crowd)) + ] + ) + clients.extend(chunk) + return clients + + +async def drain_channel_joins( + victim: IRCClient, channels: list[str], timeout: float +) -> None: + """JOIN all channels and wait for every RPL_ENDOFNAMES (366).""" + pending = {c.lower() for c in channels} + await victim.send("JOIN " + ",".join(channels)) + + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + while pending: + remaining = deadline - loop.time() + if remaining <= 0: + raise TimeoutError( + f"NAMES burst incomplete; still waiting for {sorted(pending)}" + ) + try: + msg = await victim.recv(timeout=remaining) + except ConnectionError as exc: + raise AssertionError( + f"TLS link died mid-NAMES burst (pending={sorted(pending)}): {exc}" + ) from exc + + if msg.command == "PING": + await victim.send(f"PONG :{msg.params[-1]}") + continue + if msg.command == "ERROR": + raise AssertionError(f"ERROR during NAMES burst: {msg.raw}") + if msg.command == "366" and len(msg.params) >= 2: + pending.discard(msg.params[1].lower()) + + +async def assert_client_alive(victim: IRCClient, token: str = "tlsburstalive") -> None: + """Client PING must get a matching PONG.""" + await victim.send(f"PING :{token}") + while True: + msg = await victim.recv(timeout=15.0) + if msg.command == "PING": + await victim.send(f"PONG :{msg.params[-1]}") + continue + if msg.command == "PONG" and token in msg.params[-1]: + return + if msg.command == "ERROR": + raise AssertionError(f"ERROR after ping probe: {msg.raw}") diff --git a/tests/tls/test_tls_auth_drop.py b/tests/tls/test_tls_auth_drop.py new file mode 100644 index 00000000..2741f569 --- /dev/null +++ b/tests/tls/test_tls_auth_drop.py @@ -0,0 +1,208 @@ +"""Stress TLS registration / AUTH notice pipeline (ZNC-like). + +Production symptom under investigation: TLS client sees NOTICE AUTH, then the +link dies with no ERROR and without finishing registration. +""" + +from __future__ import annotations + +import asyncio +import ssl +from dataclasses import dataclass, field + +import pytest + +from irc_client import IRCClient +from tls_certs import client_ssl_context + +pytestmark = [pytest.mark.tls, pytest.mark.tls_stress, pytest.mark.asyncio] + + +@dataclass +class AttemptResult: + nick: str + saw_auth: bool = False + saw_welcome: bool = False + saw_error: bool = False + auth_lines: list[str] = field(default_factory=list) + last_command: str | None = None + outcome: str = "unknown" + detail: str = "" + + +def _is_auth_notice(msg) -> bool: + return ( + msg.command == "NOTICE" + and len(msg.params) >= 1 + and msg.params[0].upper() == "AUTH" + ) + + +async def _pipeline_tls_register( + host: str, + port: int, + nick: str, + *, + ssl_context: ssl.SSLContext | None = None, + timeout: float = 20.0, + delay_before_read: float = 0.0, +) -> AttemptResult: + """TLS connect, immediately send NICK/USER (ZNC-like), watch for silent drop.""" + result = AttemptResult(nick=nick) + client = IRCClient() + try: + await client.connect_tls(host, port, ssl_context=ssl_context) + # Pipeline registration without waiting for AUTH — matches bouncer behaviour. + await client.send(f"NICK {nick}") + await client.send(f"USER {nick} 0 * :TLS AUTH drop probe") + if delay_before_read > 0: + await asyncio.sleep(delay_before_read) + + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + while True: + remaining = deadline - loop.time() + if remaining <= 0: + result.outcome = "timeout" + result.detail = ( + f"timed out after AUTH={result.saw_auth} " + f"welcome={result.saw_welcome} error={result.saw_error} " + f"last={result.last_command}" + ) + return result + try: + msg = await client.recv(timeout=remaining) + except ConnectionError as exc: + result.detail = str(exc) + if result.saw_auth and not result.saw_welcome and not result.saw_error: + result.outcome = "silent_drop" + elif result.saw_welcome: + result.outcome = "ok_closed_after_welcome" + elif result.saw_error: + result.outcome = "error_then_close" + else: + result.outcome = "closed_before_auth" + return result + + result.last_command = msg.command + if _is_auth_notice(msg): + result.saw_auth = True + if len(msg.params) >= 2: + result.auth_lines.append(msg.params[-1]) + elif msg.command == "001": + result.saw_welcome = True + elif msg.command == "ERROR": + result.saw_error = True + result.outcome = "error" + result.detail = " ".join(msg.params) + return result + elif msg.command in ("432", "433", "436", "437", "464", "465"): + result.outcome = "numeric_reject" + result.detail = f"{msg.command} {' '.join(msg.params)}" + return result + elif msg.command in ("376", "422"): + result.outcome = "ok" + return result + finally: + await client.disconnect() + + +async def _run_batch( + host: str, + port: int, + *, + count: int, + nick_prefix: str, + ssl_context: ssl.SSLContext | None = None, + delay_before_read: float = 0.0, +) -> list[AttemptResult]: + tasks = [ + _pipeline_tls_register( + host, + port, + f"{nick_prefix}{i}", + ssl_context=ssl_context, + delay_before_read=delay_before_read, + ) + for i in range(count) + ] + return list(await asyncio.gather(*tasks)) + + +def _assert_no_silent_drops(results: list[AttemptResult]) -> None: + drops = [r for r in results if r.outcome == "silent_drop"] + failures = [r for r in results if r.outcome not in ("ok", "ok_closed_after_welcome")] + if drops: + samples = "; ".join( + f"{r.nick}: auth={r.auth_lines!r} detail={r.detail!r}" for r in drops[:5] + ) + pytest.fail( + f"{len(drops)}/{len(results)} TLS clients saw NOTICE AUTH then " + f"silent close (no ERROR / 001). samples: {samples}" + ) + bad = [r for r in failures if r.outcome not in ("numeric_reject",)] + if bad: + samples = "; ".join(f"{r.nick}:{r.outcome}:{r.detail!r}" for r in bad[:5]) + pytest.fail( + f"{len(bad)}/{len(results)} TLS registrations failed unexpectedly: {samples}" + ) + + +async def test_tls_auth_pipeline_single(ircd_tls_network): + """One pipelined TLS registration must complete or ERROR — never silent drop.""" + hub = ircd_tls_network["hub"] + result = await _pipeline_tls_register(hub["host"], hub["tls_port"], "auths1") + assert result.outcome != "silent_drop", f"silent drop after AUTH: {result}" + assert result.outcome == "ok", f"unexpected outcome: {result}" + assert result.saw_welcome + + +async def test_tls_auth_pipeline_with_client_cert(ircd_tls_network): + """Same with a presented client cert (soft CertificateRequest path).""" + hub = ircd_tls_network["hub"] + ctx = client_ssl_context(cert="selfsigned") + result = await _pipeline_tls_register( + hub["host"], hub["tls_port"], "authcert1", ssl_context=ctx + ) + assert result.outcome != "silent_drop", f"silent drop after AUTH: {result}" + assert result.outcome == "ok", f"unexpected outcome: {result}" + assert result.saw_welcome + + +async def test_tls_auth_pipeline_concurrent(ircd_tls_network): + """Concurrent pipelined TLS connects — stress AUTH flush / sendq.""" + hub = ircd_tls_network["hub"] + results = await _run_batch( + hub["host"], hub["tls_port"], count=24, nick_prefix="authc" + ) + _assert_no_silent_drops(results) + + +async def test_tls_auth_pipeline_concurrent_client_cert(ircd_tls_network): + """Concurrent TLS connects presenting client certificates.""" + hub = ircd_tls_network["hub"] + ctx = client_ssl_context(cert="selfsigned") + results = await _run_batch( + hub["host"], + hub["tls_port"], + count=16, + nick_prefix="authcc", + ssl_context=ctx, + ) + _assert_no_silent_drops(results) + + +async def test_tls_auth_pipeline_burst_rounds(ircd_tls_network): + """Several waves of concurrent connects to amplify timing races.""" + hub = ircd_tls_network["hub"] + all_results: list[AttemptResult] = [] + for wave in range(4): + all_results.extend( + await _run_batch( + hub["host"], + hub["tls_port"], + count=12, + nick_prefix=f"authw{wave}", + ) + ) + _assert_no_silent_drops(all_results) diff --git a/tests/tls/test_tls_names_burst.py b/tests/tls/test_tls_names_burst.py new file mode 100644 index 00000000..758981b4 --- /dev/null +++ b/tests/tls/test_tls_names_burst.py @@ -0,0 +1,45 @@ +"""Regression: large TLS NAMES bursts must not drop the client. + +Production report: after joining several busy channels (large NAMES replies), a +TLS client connection dropped with no ERROR. Root cause was incorrect TLS +sendq accounting on partial SSL_write / con_rexmit (default builds abort at +msgq_excise assert; --disable-asserts silently corrupts the queue). +""" + +from __future__ import annotations + +import pytest + +from irc_client import IRCClient +from tls.helpers import ( + NAMES_BURST_CHANNELS, + assert_client_alive, + drain_channel_joins, + populate_channels, +) + +pytestmark = [pytest.mark.tls, pytest.mark.tls_stress, pytest.mark.asyncio] + + +@pytest.mark.timeout(300) +async def test_tls_names_burst_survives(ircd_tls_network): + """Large NAMES replies over TLS must not drop the victim connection.""" + hub = ircd_tls_network["hub"] + crowd: list[IRCClient] = [] + victim = IRCClient() + try: + crowd = await populate_channels(hub) + + await victim.connect_tls(hub["host"], hub["tls_port"]) + msgs = await victim.register("tlsburst", "victim", "TLS NAMES burst") + assert any(m.command == "001" for m in msgs) + + await drain_channel_joins(victim, NAMES_BURST_CHANNELS, timeout=90.0) + await assert_client_alive(victim) + finally: + await victim.disconnect() + for c in crowd: + try: + await c.disconnect() + except Exception: + pass diff --git a/tests/tls/test_tls_security.py b/tests/tls/test_tls_security.py index 8bbef80e..f06921e5 100644 --- a/tests/tls/test_tls_security.py +++ b/tests/tls/test_tls_security.py @@ -240,14 +240,83 @@ async def test_stalled_handshake_times_out(ircd_tls_network): hub = ircd_tls_network["hub"] reader, writer = await asyncio.open_connection(hub["host"], hub["tls_port"]) try: - # Send nothing (no ClientHello). The server should close on timeout. + # Send nothing (no ClientHello). The server must close on timeout with + # a plain TCP EOF: no close_notify alert may be sent for a session whose + # handshake never completed (all backends: OpenSSL, GnuTLS, libtls). data = await asyncio.wait_for(reader.read(1), timeout=15.0) - assert data == b"", "server should close the stalled handshake" - except (asyncio.TimeoutError, ConnectionResetError): + assert data == b"", f"server should close the stalled handshake with EOF, got {data!r}" + except asyncio.TimeoutError: pytest.fail("server did not close a stalled TLS handshake in time") + except ConnectionResetError: + pass # RST is also a close finally: writer.close() try: await writer.wait_closed() except Exception: pass + + +async def test_stalled_handshake_after_clienthello_times_out(ircd_tls_network): + """L1 (variant): ClientHello sent, client never sends Finished. + + The server must still tear the session down on timeout with a plain TCP + EOF. With TLS 1.3 a close_notify sent at this point is *encrypted*, so a + first-byte check cannot see it; drive the client side of the handshake in + a MemoryBIO so the ssl module decodes whatever the server sends last. + """ + hub = ircd_tls_network["hub"] + ctx = ssl.create_default_context() + ctx.check_hostname = False + ctx.verify_mode = ssl.CERT_NONE + inb, outb = ssl.MemoryBIO(), ssl.MemoryBIO() + obj = ctx.wrap_bio(inb, outb, server_side=False) + try: + obj.do_handshake() + except ssl.SSLWantReadError: + pass + reader, writer = await asyncio.open_connection(hub["host"], hub["tls_port"]) + handshake_done = False + verdict = None + try: + writer.write(outb.read()) # ClientHello only; Finished is never sent + await writer.drain() + loop = asyncio.get_running_loop() + deadline = loop.time() + 15.0 + while verdict is None: + remaining = deadline - loop.time() + assert remaining > 0, "server did not close a stalled TLS handshake in time" + try: + data = await asyncio.wait_for(reader.read(65536), remaining) + except ConnectionResetError: + verdict = "rst" + break + if not data: + inb.write_eof() + else: + inb.write(data) + try: + if not handshake_done: + obj.do_handshake() + handshake_done = True + obj.read(1) + except ssl.SSLWantReadError: + if not data: + verdict = "eof" + continue + except ssl.SSLZeroReturnError: + verdict = "close_notify" + except ssl.SSLEOFError: + verdict = "eof" + except ssl.SSLError as exc: + verdict = f"sslerror:{exc.reason}" + else: + verdict = "eof" if not data else None + finally: + writer.close() + try: + await writer.wait_closed() + except Exception: + pass + assert handshake_done, "server never answered the ClientHello" + assert verdict in ("eof", "rst"), f"expected plain EOF/RST after timeout, got {verdict}"