diff --git a/include/ircd_tls.h b/include/ircd_tls.h index bfdc0f79..7d495e9c 100644 --- a/include/ircd_tls.h +++ b/include/ircd_tls.h @@ -93,7 +93,8 @@ static inline int ircd_tls_trust_verifies_ca(ircd_tls_trust_policy policy) return policy == TLS_TRUST_REQUIRE_CA; } -/** Timeout for TLS handshake in seconds */ +/** Timeout for a TLS handshake in seconds, measured from when the handshake + * starts (enforced by the connection timer in s_bsd.c, not by the backends). */ #define TLS_HANDSHAKE_TIMEOUT 5 /** Size of the human-readable reason buffer filled by ircd_tls_negotiate(). */ @@ -226,8 +227,10 @@ void ircd_tls_listen_free(struct Listener *listener); /** ircd_tls_negotiate() attempts to continue an initial TLS handshake * for \a cptr. If the handshake completes, this function calls * \a ClearNegotiatingTLS(cptr) and returns 1. If the handshake failed, - * this function returns -1. Otherwise it updates event flags for the - * client's socket and returns 0. + * this function returns -1. Otherwise it returns 0 and reports through + * \a wants_write which socket direction the handshake is blocked on, so the + * caller can adjust the socket's event interest (the backend itself never + * touches socket events). * * @param[in] cptr Locally connected client to perform handshake for. * @param[out] reason If non-NULL, receives a human-readable failure reason @@ -235,10 +238,15 @@ void ircd_tls_listen_free(struct Listener *listener); * 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). + * @param[out] wants_write If non-NULL, set to 1 when a 0 return means the + * handshake is waiting to write (SSL_ERROR_WANT_WRITE and equivalents, + * or a backend asking to be called again immediately), 0 when it is + * waiting for peer data. Always 0 on a non-zero return. * \returns 1 on completed handshake, 0 on continuing handshake, -1 on * error. */ -int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen); +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen, + int *wants_write); /** ircd_tls_recv() performs a non-blocking receive of TLS application * data from \a cptr into \a buf. diff --git a/ircd/engine_kqueue.c b/ircd/engine_kqueue.c index 92641e98..e16077c2 100644 --- a/ircd/engine_kqueue.c +++ b/ircd/engine_kqueue.c @@ -410,7 +410,15 @@ engine_loop(struct Generators* gen) case SS_CONNECTED: if (evt->filter == EVFILT_READ) { /* data on socket */ Debug((DEBUG_ENGINE, "kqueue: EOF or data to be read")); - event_generate(evt->flags & EV_EOF ? ET_EOF : ET_READ, sock, 0); + /* EV_EOF is set as soon as the peer's FIN arrives, even while + * evt->data bytes are still unread (typically the peer's final + * ERROR/SQUIT line). Deliver those as ET_READ first; the filter is + * level-triggered, so once the buffer is drained the next kevent() + * returns EV_EOF with data == 0 and becomes the real ET_EOF. */ + if ((evt->flags & EV_EOF) && evt->data <= 0) + event_generate(ET_EOF, sock, 0); + else + event_generate(ET_READ, sock, 0); } if (evt->filter == EVFILT_WRITE) { /* socket writable */ Debug((DEBUG_ENGINE, "kqueue: Data can be written")); diff --git a/ircd/s_bsd.c b/ircd/s_bsd.c index 02ffb464..653dcc58 100644 --- a/ircd/s_bsd.c +++ b/ircd/s_bsd.c @@ -107,6 +107,9 @@ const char* const TOS_ERROR_MSG = "error setting TOS for %s: %s"; static void client_sock_callback(struct Event* ev); static void client_timer_callback(struct Event* ev); +static void tls_negotiation_events(struct Client *cptr, int wants_write); +static void tls_handshake_timer_arm(struct Client *cptr); +static int tls_negotiate_client(struct Client *cptr, char **fmt, char **fallback); /* @@ -371,30 +374,21 @@ static int completed_connection(struct Client* cptr) s_tls(&cli_socket(cptr)) = tls; SetNegotiatingTLS(cptr); SetTLS(cptr); + tls_handshake_timer_arm(cptr); } - /* 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. */ + /* Are we making progress? A failure (fatal handshake error, missing + * session) must fail the link now rather than fall through to sending + * PASS/SERVER on a socket without a TLS session; tls_negotiate_client() + * has notified opers, marked the socket dead and dropped the session, so + * the caller's exit cannot leak plaintext into the handshake stream. */ if (IsNegotiatingTLS(cptr)) { - 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; - } + char *fmt = "%s"; + char *fallback = 0; + int res = tls_negotiate_client(cptr, &fmt, &fallback); + + if (res < 0) return 0; - } if (res == 0) return 1; /* still negotiating */ } @@ -550,6 +544,7 @@ void add_connection(struct Listener* listener, int fd) { struct Client *new_client; time_t next_target = 0; void *tls; + int ipchecked; const char* const throttle_message = "ERROR :Your host is trying to (re)connect too fast -- throttled\r\n"; @@ -595,33 +590,37 @@ void add_connection(struct Listener* listener, int fd) { } } - if (listener_server(listener)) + /* + * Throttle check before allocating the Client, so a rejected connection + * has nothing to leak but the TLS session freed here. Cloudflare + * websocket ports defer IPcheck until CF-Connecting-IP is known at + * handshake; the socket peer is a Cloudflare edge node. + */ + ipchecked = 0; + if (!listener_server(listener) && !listener_webirc(listener) + && !(listener_websocket(listener) && listener_cloudflare(listener))) { - new_client = make_client(0, STAT_UNKNOWN_SERVER); + if (!IPcheck_local_connect(&addr.addr, &next_target)) + { + ++ServerStats->is_throttled; + write(fd, throttle_message, strlen(throttle_message)); + close(fd); + if (tls) + ircd_tls_close(tls, NULL); + return; + } + ipchecked = 1; } + + if (listener_server(listener)) + new_client = make_client(0, STAT_UNKNOWN_SERVER); else if (listener_webirc(listener)) - { - new_client = make_client(0, STAT_WEBIRC); - } + new_client = make_client(0, STAT_WEBIRC); else - { new_client = make_client(0, listener_websocket(listener) ? STAT_WEBSOCKET : STAT_UNKNOWN_USER); - /* - * Cloudflare websocket ports: defer IPcheck until CF-Connecting-IP is - * known at handshake; the socket peer is a Cloudflare edge node. - */ - if (!(listener_websocket(listener) && listener_cloudflare(listener))) { - if (!IPcheck_local_connect(&addr.addr, &next_target)) - { - ++ServerStats->is_throttled; - write(fd, throttle_message, strlen(throttle_message)); - close(fd); - return; - } - SetIPChecked(new_client); - } - } + if (ipchecked) + SetIPChecked(new_client); /* * Copy ascii address to 'sockhost' just in case. Then we have something @@ -641,6 +640,11 @@ void add_connection(struct Listener* listener, int fd) { write(fd, register_message, strlen(register_message)); close(fd); cli_fd(new_client) = -1; + if (tls) + ircd_tls_close(tls, NULL); + if (IsIPChecked(new_client)) + IPcheck_disconnect(new_client); + free_client(new_client); return; } cli_freeflag(new_client) |= FREEFLAG_SOCKET; @@ -652,7 +656,16 @@ void add_connection(struct Listener* listener, int fd) { { SetTLS(new_client); SetNegotiatingTLS(new_client); - socket_events(&cli_socket(new_client), SOCK_EVENT_WRITABLE); + /* Wait for the ClientHello. The handshake is driven by ET_READ / + * ET_WRITE in client_sock_callback(); tls_negotiation_events() adds + * WRITABLE only while the backend is blocked on a write. Registering + * WRITABLE here would busy-loop on a level-triggered writable socket + * until the peer's first flight arrived. */ + socket_events(&cli_socket(new_client), SOCK_EVENT_READABLE); + /* Until start_auth() runs after the handshake this client is not in + * LocalClientArray, so check_pings(), /CLOSE and kill_highest_sendq() + * cannot see it; the handshake timer is the only thing that reaps it. */ + tls_handshake_timer_arm(new_client); } Count_newunknown(UserStats); @@ -1099,34 +1112,103 @@ void init_server_identity(void) SetYXXServerName(&me, conf->numeric); } -/** Notify operators of inbound TLS failures on server ports. */ +/** Notify operators of a failed TLS handshake on a server link: an + * outbound link we initiated, or an inbound connection on a server port. + * This is the only place that reports it, so a failure detected on a + * later socket event (ET_READ after the connect step) is reported exactly + * like one detected during the connect step itself. */ static void tls_negotiation_failed(struct Client *cptr, const char *reason) { - if (IsServerPort(cptr)) + if (IsConnecting(cptr)) + sendto_opmask_butone(0, SNO_OLDSNO, "TLS negotiation failed to %s%s%s", + cli_name(cptr), + (reason && reason[0]) ? ": " : "", + reason ? reason : ""); + else if (IsServerPort(cptr)) sendto_opmask_butone(0, SNO_OLDSNO, "TLS negotiation failed from unknown server%s%s", (reason && reason[0]) ? ": " : "", reason ? reason : ""); } +/** Adjust socket event interest for a handshake still in progress. + * Wait on exactly the direction the backend is blocked on. A writable + * socket is level-triggered and almost always ready, so holding WRITABLE + * while waiting for the peer spins; holding READABLE while blocked on a + * write lets a peer that leaves bytes unread re-run the handshake every + * loop pass. Errors (RST) are reported regardless of interest, and a + * silent peer is bounded by the handshake timer either way. + * @param[in] cptr Client whose TLS handshake returned "in progress". + * @param[in] wants_write Non-zero if the backend is waiting to write. + */ +static void tls_negotiation_events(struct Client *cptr, int wants_write) +{ + socket_events(&cli_socket(cptr), SOCK_ACTION_SET + | (wants_write ? SOCK_EVENT_WRITABLE : SOCK_EVENT_READABLE)); +} + +/** Arm the TLS handshake deadline for \a cptr. + * The handshake is driven purely by socket events, so a peer that never + * speaks (or stops mid-handshake) would otherwise sit forever. Measured + * from here, i.e. from when the handshake actually starts, not from + * make_client(): for outbound links that would include the TCP connect + * and SYN retransmits. con_proc is unused until read_packet() runs, + * which cannot precede the handshake; tls_handshake_succeeded() cancels + * the timer and free_client() deletes it on any other exit. + * @param[in] cptr Client whose handshake is starting. + */ +static void tls_handshake_timer_arm(struct Client *cptr) +{ + cli_freeflag(cptr) |= FREEFLAG_TIMER; + timer_add(&cli_proc(cptr), client_timer_callback, cli_connect(cptr), + TT_RELATIVE, TLS_HANDSHAKE_TIMEOUT); +} + +/** Drop the TLS session of a failed handshake. + * Marks the socket dead first so exit_client() cannot flush an ERROR line + * as plaintext into the peer's half-open TLS stream (can_send() rejects a + * dead socket). + * @param[in] cptr Client whose handshake failed. + */ +static void tls_handshake_drop(struct Client *cptr) +{ + SetFlag(cptr, FLAG_DEADSOCKET); + ClrFlag(cptr, FLAG_NEGOTIATING_TLS); + if (s_tls(&cli_socket(cptr))) + { + ircd_tls_close(s_tls(&cli_socket(cptr)), NULL); + s_tls(&cli_socket(cptr)) = NULL; + } +} + +/** Abort a handshake with \a reason: notify opers, drop the session and + * exit the client. Used where no backend call is needed (the deadline). + * @param[in] cptr Client whose handshake is aborted. + * @param[in] reason Human-readable reason for notices and the exit. + */ +static void tls_handshake_abort(struct Client *cptr, const char *reason) +{ + tls_negotiation_failed(cptr, reason); + tls_handshake_drop(cptr); + exit_client_msg(cptr, cptr, &me, "%s", reason); +} + /** Run ircd_tls_negotiate() and handle a fatal result. */ static int tls_negotiate_client(struct Client *cptr, char **fmt, char **fallback) { /* 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)); + int wants_write = 0; + int res = ircd_tls_negotiate(cptr, reason, sizeof(reason), &wants_write); + + if (res == 0) + tls_negotiation_events(cptr, wants_write); if (res < 0) { tls_negotiation_failed(cptr, reason); - SetFlag(cptr, FLAG_DEADSOCKET); - ClrFlag(cptr, FLAG_NEGOTIATING_TLS); - if (s_tls(&cli_socket(cptr))) - { - ircd_tls_close(s_tls(&cli_socket(cptr)), "TLS negotiation failed"); - s_tls(&cli_socket(cptr)) = NULL; - } + tls_handshake_drop(cptr); *fmt = "%s"; *fallback = reason[0] ? reason : "TLS negotiation failed"; } @@ -1137,6 +1219,10 @@ 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) { + /* Drop the handshake deadline armed by tls_handshake_timer_arm(). */ + if (t_onqueue(&cli_proc(cptr))) + timer_del(&cli_proc(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 @@ -1241,7 +1327,14 @@ static void client_sock_callback(struct Event* ev) break; case ET_READ: /* socket is readable */ - if (!IsDead(cptr)) { + if (IsDead(cptr)) { + /* dead_link() deferred the exit to check_pings(); the readable + * event is level-triggered and would re-fire every loop pass until + * then, so exit now (same context as the ET_EOF case). */ + exit_client(cptr, cptr, &me, cli_info(cptr)); + return; + } + { Debug((DEBUG_DEBUG, "Reading data from %C", cptr)); if (IsNegotiatingTLS(cptr)) { int res = tls_negotiate_client(cptr, &fmt, &fallback); @@ -1251,8 +1344,12 @@ static void client_sock_callback(struct Event* ev) /* Still negotiating */ break; } - /* TLS negotiation succeeded */ + /* TLS negotiation succeeded. start_auth() / completed_connection() + * may have exited (and freed) cptr, so do not touch it again; any + * application data already queued re-fires the level-triggered + * readable event. */ tls_handshake_succeeded(cptr); + return; } if (read_packet(cptr, 1) == 0) /* error while reading packet */ fallback = "EOF from client"; @@ -1306,6 +1403,13 @@ static void client_timer_callback(struct Event* ev) if (!con_freeflag(con) && !cptr) free_connection(con); /* client is being destroyed */ + } else if (IsNegotiatingTLS(cptr)) { + /* Handshake deadline from tls_handshake_timer_arm(). No peer write: a + * stalled handshake must close with a plain EOF, not a plaintext line + * that would corrupt a mid-handshake peer's TLS stream. Exiting from + * inside the timer's own callback is fine: timer_del() is a no-op while + * it is GEN_MARKED and timer_run() destroys the one-shot afterwards. */ + tls_handshake_abort(cptr, "TLS handshake timed out"); } else { Debug((DEBUG_LIST, "Client process timer for %C expired; processing", cptr)); diff --git a/ircd/s_misc.c b/ircd/s_misc.c index d71fb5d7..7f74035c 100644 --- a/ircd/s_misc.c +++ b/ircd/s_misc.c @@ -419,8 +419,12 @@ int exit_client(struct Client *cptr, NumNick(victim), /* two %s's */ cli_name(victim), cli_info(victim)); + /* IsClient() does not cover STAT_CONNECTING, but the "Link with %s + * canceled" notices below are meant for connecting links too: without + * this, an outbound link that dies between connect() and registration + * (e.g. reset during the TLS handshake) is invisible to opers. */ if (victim != cli_from(killer) /* The source knows already */ - && IsClient(victim)) /* Not a Ping struct or Log file */ + && (IsClient(victim) || IsConnecting(victim))) /* Not a Ping struct or Log file */ { if (IsServer(victim) || IsHandshake(victim)) sendcmdto_one(killer, CMD_SQUIT, victim, "%s 0 :%s", cli_name(&me), comment); diff --git a/ircd/tls_gnutls.c b/ircd/tls_gnutls.c index d024ce29..bf978eb2 100644 --- a/ircd/tls_gnutls.c +++ b/ircd/tls_gnutls.c @@ -437,13 +437,14 @@ void ircd_tls_listen_free(struct Listener *listener) } } -int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen, + int *wants_write) { gnutls_session_t tls; gnutls_x509_crt_t crt; const gnutls_datum_t *datum; size_t len; - int res; + int res, i; 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"; @@ -451,6 +452,8 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) if (reason && reasonlen) reason[0] = '\0'; + if (wants_write) + *wants_write = 0; tls = s_tls(&cli_socket(cptr)); @@ -460,21 +463,23 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) 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; + /* Non-fatal results other than E_AGAIN/E_INTERRUPTED (e.g. a warning + * alert) mean "call gnutls_handshake() again now"; no socket event will + * follow, so retry here. Each pass consumes at least one record, and the + * bound only guards against a misbehaving peer. */ + for (i = 0; i < 16; ++i) + { + res = gnutls_handshake(tls); + if (res >= 0 || res == GNUTLS_E_AGAIN || res == GNUTLS_E_INTERRUPTED + || gnutls_error_is_fatal(res)) + break; } - - res = gnutls_handshake(tls); switch (res) { case GNUTLS_E_INTERRUPTED: case GNUTLS_E_AGAIN: - case GNUTLS_E_WARNING_ALERT_RECEIVED: - case GNUTLS_E_GOT_APPLICATION_DATA: + if (wants_write) + *wants_write = (gnutls_record_get_direction(tls) == 1); return 0; case GNUTLS_E_SUCCESS: @@ -604,6 +609,10 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) write(cli_fd(cptr), err_handshake, strlen(err_handshake)); return -1; } + /* Still non-fatal after the retry bound above: come back on the next + * loop pass via the always-ready writable event. */ + if (wants_write) + *wants_write = 1; return 0; } } diff --git a/ircd/tls_libtls.c b/ircd/tls_libtls.c index ee8237df..3248e922 100644 --- a/ircd/tls_libtls.c +++ b/ircd/tls_libtls.c @@ -527,7 +527,8 @@ void ircd_tls_listen_free(struct Listener *listener) } } -int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen, + int *wants_write) { const char *hash; struct tls *tls; @@ -538,6 +539,8 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) if (reason && reasonlen) reason[0] = '\0'; + if (wants_write) + *wants_write = 0; tls = s_tls(&cli_socket(cptr)); if (!tls) { @@ -546,14 +549,6 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) 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; - } - Debug((DEBUG_DEBUG, "libtls handshake for %s", cli_name(cptr))); res = tls_handshake(tls); @@ -605,6 +600,8 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) } if (res == TLS_WANT_POLLIN || res == TLS_WANT_POLLOUT) { + if (wants_write) + *wants_write = (res == TLS_WANT_POLLOUT); return 0; /* Handshake in progress */ } diff --git a/ircd/tls_none.c b/ircd/tls_none.c index 8c7a38d6..fb7a8f1c 100644 --- a/ircd/tls_none.c +++ b/ircd/tls_none.c @@ -84,10 +84,13 @@ void ircd_tls_listen_free(struct Listener *listener) (void)listener; } -int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen, + int *wants_write) { (void)reason; (void)reasonlen; + if (wants_write) + *wants_write = 0; ClearNegotiatingTLS(cptr); return 1; } diff --git a/ircd/tls_openssl.c b/ircd/tls_openssl.c index 90955204..aa3425b1 100644 --- a/ircd/tls_openssl.c +++ b/ircd/tls_openssl.c @@ -733,7 +733,8 @@ static IOResult ssl_handle_error(struct Client *cptr, SSL *tls, int res, int ori return IO_FAILURE; } -int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) +int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen, + int *wants_write) { SSL *tls; X509 *cert; @@ -746,6 +747,8 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) if (reason && reasonlen) reason[0] = '\0'; + if (wants_write) + *wants_write = 0; tls = s_tls(&cli_socket(cptr)); if (!tls) { @@ -757,15 +760,6 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) 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; - } - /* For client connections, use SSL_connect; for server, SSL_accept. */ if (SSL_is_server(tls)) res = SSL_accept(tls); @@ -862,7 +856,12 @@ int ircd_tls_negotiate(struct Client *cptr, char *reason, size_t reasonlen) write(cli_fd(cptr), err_handshake, strlen(err_handshake)); return -1; } - /* ssl_result == IO_BLOCKED - handshake still in progress */ + /* ssl_result == IO_BLOCKED - handshake still in progress. Tell the + * caller which direction to wait for. Anything other than WANT_READ + * is reported as a write: a wrong "write" costs one loop pass on the + * always-ready writable event, a wrong "read" costs the deadline. */ + if (wants_write) + *wants_write = (sslerr != SSL_ERROR_WANT_READ); return 0; } } diff --git a/tests/docker/ircd-tls-hub.conf b/tests/docker/ircd-tls-hub.conf index ccd571a1..92ff9a6d 100644 --- a/tests/docker/ircd-tls-hub.conf +++ b/tests/docker/ircd-tls-hub.conf @@ -81,6 +81,19 @@ Connect { tls fingerprint = "0f0a727085a80a3f772e1994dfb332be3838f06015a6fc657c84d0e19117f61d"; }; +# Misbehaving TLS peer (tests/tls/test_tls_bogus_peer.py): a sidecar +# container on the test network the hub is told to CONNECT to. +Connect { + name = "bogus.test.net"; + host = "10.55.0.40"; + password = "testpass"; + class = "Server"; + hub; + autoconnect = no; + tls = yes; + tls fingerprint = "0f0a727085a80a3f772e1994dfb332be3838f06015a6fc657c84d0e19117f61d"; +}; + Connect { name = "tlspeer-ca.test.net"; host = "10.55.0.1"; diff --git a/tests/tls/bogus_peer.py b/tests/tls/bogus_peer.py new file mode 100644 index 00000000..d71f66ff --- /dev/null +++ b/tests/tls/bogus_peer.py @@ -0,0 +1,486 @@ +"""Misbehaving TLS peers for edge-case testing of ircd's TLS handshake. + +Both halves drive OpenSSL through ``ssl.MemoryBIO`` instead of a socket, so +the test -- not the TLS library -- decides which bytes reach the wire and +when. That is what makes it possible to leave the server parked in exactly +one handshake state (waiting to read, waiting to write, mid-record, ...) and +observe what it does there. + +``BogusTLSClient`` connects *to* ircd (client or server TLS port). +``BogusTLSServer`` is the server half; ``SidecarBogusServer`` runs it in a +container on the docker test network (the host firewall may not let +containers reach the host) so ircd can be made to connect *out* to it with +``CONNECT bogus.test.net `` -- see the Connect block in +tests/docker/ircd-tls-hub.conf. +""" + +from __future__ import annotations + +import asyncio +import json +import os +import socket +import ssl +import struct +import subprocess +import time +from dataclasses import dataclass, field + +from tls_certs import cert_path, key_path + + +# --------------------------------------------------------------------------- +# Wire helpers +# --------------------------------------------------------------------------- + + +async def _open_socket(host: str, port: int, *, rcvbuf: int | None = None): + """asyncio streams over a socket we configured before connecting.""" + sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) + if rcvbuf is not None: + # Must be set before connect() so the advertised window is small too. + sock.setsockopt(socket.SOL_SOCKET, socket.SO_RCVBUF, rcvbuf) + sock.setblocking(False) + loop = asyncio.get_running_loop() + await loop.sock_connect(sock, (host, port)) + reader, writer = await asyncio.open_connection(sock=sock) + return reader, writer + + +async def wait_for_eof(reader: asyncio.StreamReader, timeout: float) -> tuple[bytes, float]: + """Read until EOF (or timeout). Returns (bytes received, seconds waited).""" + start = time.monotonic() + chunks = [] + try: + while True: + remaining = timeout - (time.monotonic() - start) + if remaining <= 0: + raise asyncio.TimeoutError + data = await asyncio.wait_for(reader.read(65536), remaining) + if not data: + break + chunks.append(data) + except asyncio.TimeoutError: + return b"".join(chunks), -1.0 + except (ConnectionResetError, BrokenPipeError): + pass + return b"".join(chunks), time.monotonic() - start + + +# --------------------------------------------------------------------------- +# Bogus client +# --------------------------------------------------------------------------- + + +@dataclass +class BogusTLSClient: + host: str + port: int + rcvbuf: int | None = None + cert: str | None = None # client certificate name from tests/docker/certs + reader: asyncio.StreamReader = field(init=False, default=None) + writer: asyncio.StreamWriter = field(init=False, default=None) + incoming: ssl.MemoryBIO = field(init=False, default=None) + outgoing: ssl.MemoryBIO = field(init=False, default=None) + tls: ssl.SSLObject = field(init=False, default=None) + + async def connect(self) -> None: + self.reader, self.writer = await _open_socket( + self.host, self.port, rcvbuf=self.rcvbuf + ) + + def start_tls(self) -> bytes: + """Create the client-side TLS state and return the ClientHello bytes + (not yet sent).""" + ctx = ssl.SSLContext(ssl.PROTOCOL_TLS_CLIENT) + ctx.check_hostname = False + ctx.verify_mode = ssl.CERT_NONE + if self.cert: + ctx.load_cert_chain(cert_path(self.cert), key_path(self.cert)) + self.incoming = ssl.MemoryBIO() + self.outgoing = ssl.MemoryBIO() + self.tls = ctx.wrap_bio(self.incoming, self.outgoing, server_side=False) + return self.handshake_step() + + def handshake_step(self) -> bytes: + """Advance the handshake as far as possible; return bytes to send.""" + try: + self.tls.do_handshake() + except ssl.SSLWantReadError: + pass + return self.outgoing.read() + + def _pending(self) -> bool: + try: + self.tls.do_handshake() + return False + except ssl.SSLWantReadError: + return True + + async def send_raw(self, data: bytes) -> None: + self.writer.write(data) + await self.writer.drain() + + async def send_slowly(self, data: bytes, chunk: int, delay: float) -> None: + for i in range(0, len(data), chunk): + self.writer.write(data[i:i + chunk]) + await self.writer.drain() + await asyncio.sleep(delay) + + async def feed(self, timeout: float = 5.0) -> bytes: + """Read one chunk from the wire into the TLS engine; returns it.""" + data = await asyncio.wait_for(self.reader.read(65536), timeout) + if data: + self.incoming.write(data) + return data + + async def complete_handshake(self, timeout: float = 10.0, *, flush: bool = True) -> bytes: + """Run the handshake to completion. + + With flush=False the client's final flight (Finished) is left in + the outgoing BIO and returned instead of sent, so a test can + coalesce it with application data in a single segment. + """ + deadline = time.monotonic() + timeout + out = self.start_tls() if self.tls is None else self.handshake_step() + if out: + await self.send_raw(out) + while self._pending(): + if time.monotonic() > deadline: + raise asyncio.TimeoutError("TLS handshake did not complete") + data = await self.feed(timeout=max(0.1, deadline - time.monotonic())) + if not data: + raise ConnectionError("EOF during TLS handshake") + if self._pending(): + out = self.handshake_step() + if out: + await self.send_raw(out) + final = self.outgoing.read() # client Finished (TLS 1.3) + if flush and final: + await self.send_raw(final) + return b"" + return final + + def app_bytes(self, text: str) -> bytes: + """Encrypt `text` and return the record bytes without sending.""" + self.tls.write(text.encode()) + return self.outgoing.read() + + async def send_app(self, text: str) -> None: + await self.send_raw(self.app_bytes(text)) + + async def recv_app(self, timeout: float = 5.0) -> str: + while True: + try: + return self.tls.read(65536).decode(errors="replace") + except ssl.SSLWantReadError: + data = await self.feed(timeout) + if not data: + raise ConnectionError("EOF") + + async def close_rst(self) -> None: + """Abort with RST instead of FIN.""" + sock = self.writer.get_extra_info("socket") + sock.setsockopt(socket.SOL_SOCKET, socket.SO_LINGER, struct.pack("ii", 1, 0)) + self.writer.close() + + async def close_fin(self) -> None: + """Half-close: FIN to the server, keep reading.""" + self.writer.write_eof() + + async def close(self) -> None: + if self.writer is not None: + self.writer.close() + try: + await self.writer.wait_closed() + except Exception: + pass + + +# --------------------------------------------------------------------------- +# Bogus server (ircd connects out to it) +# --------------------------------------------------------------------------- + + +class BogusTLSServer: + """A TLS 'server' with selectable misbehaviour. + + modes: + silent accept, read everything, never send a byte + close accept, close immediately + garbage accept, send random bytes, keep reading + truncated_flight reply to ClientHello with the first `truncate` bytes + of the server flight, then go silent + complete full handshake with the given cert, then record the + decrypted application data ircd sends (PASS/SERVER) + """ + + def __init__(self, mode: str, *, cert: str = "tlspeer", truncate: int = 200, + delay: float = 0.0): + self.mode = mode + self.cert = cert + self.truncate = truncate + # Seconds to wait after accept before misbehaving. 0 hits the peer + # while ircd is still inside its connect-completion step; ~1 s makes + # sure ircd has parked in "waiting for the server flight" first. + self.delay = delay + self.server: asyncio.AbstractServer | None = None + self.port: int = 0 + self.accepted = asyncio.Event() + self.received_raw = bytearray() + self.app_lines: list[str] = [] + self.done = asyncio.Event() + self._closed = False + + async def start(self, host: str = "0.0.0.0") -> int: + self.server = await asyncio.start_server(self._handle, host, 0) + self.port = self.server.sockets[0].getsockname()[1] + return self.port + + async def stop(self) -> None: + if self.server is not None: + self.server.close() + try: + await self.server.wait_closed() + except Exception: + pass + self.server = None + + async def _handle(self, reader: asyncio.StreamReader, writer: asyncio.StreamWriter) -> None: + self.accepted.set() + try: + if self.delay: + await asyncio.sleep(self.delay) + if self.mode == "close": + writer.close() + return + if self.mode == "garbage": + writer.write(os.urandom(512)) + await writer.drain() + await self._drain_until_eof(reader) + return + if self.mode == "silent": + await self._drain_until_eof(reader) + return + + ctx = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER) + ctx.load_cert_chain(cert_path(self.cert), key_path(self.cert)) + incoming, outgoing = ssl.MemoryBIO(), ssl.MemoryBIO() + tls = ctx.wrap_bio(incoming, outgoing, server_side=True) + + if self.mode == "truncated_flight": + # Feed the ClientHello, take the server flight, send a prefix. + while True: + data = await reader.read(65536) + if not data: + return + self.received_raw += data + incoming.write(data) + try: + tls.do_handshake() + except ssl.SSLWantReadError: + pass + flight = outgoing.read() + if flight: + writer.write(flight[: self.truncate]) + await writer.drain() + break + await self._drain_until_eof(reader) + return + + if self.mode == "complete": + # Full handshake, then decrypt whatever ircd sends. + while True: + try: + tls.do_handshake() + break + except ssl.SSLWantReadError: + out = outgoing.read() + if out: + writer.write(out) + await writer.drain() + data = await reader.read(65536) + if not data: + return + self.received_raw += data + incoming.write(data) + out = outgoing.read() + if out: + writer.write(out) + await writer.drain() + buf = "" + while True: + try: + chunk = tls.read(65536) + if not chunk: + return + buf += chunk.decode(errors="replace") + while "\n" in buf: + line, buf = buf.split("\n", 1) + self.app_lines.append(line.rstrip("\r")) + self.done.set() + except ssl.SSLWantReadError: + data = await reader.read(65536) + if not data: + return + incoming.write(data) + except ssl.SSLZeroReturnError: + return + except (ConnectionResetError, BrokenPipeError, asyncio.IncompleteReadError): + pass + finally: + self.done.set() + writer.close() + + async def _drain_until_eof(self, reader: asyncio.StreamReader) -> None: + while True: + data = await reader.read(65536) + if not data: + return + self.received_raw += data + + +# --------------------------------------------------------------------------- +# Sidecar: the bogus server inside the docker test network +# --------------------------------------------------------------------------- + +SIDECAR_IMAGE = "python:3-alpine" +SIDECAR_NAME = "ircu-bogus-tls" +SIDECAR_IP = "10.55.0.40" # Connect { name = "bogus.test.net" } in ircd-tls-hub.conf +SIDECAR_PORT = 4500 +TESTS_DIR = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) + + +def _test_network() -> str: + out = subprocess.run( + ["docker", "network", "ls", "--filter", "name=ircu-test-net", "--format", "{{.Name}}"], + capture_output=True, text=True, timeout=30, + ) + names = [n for n in out.stdout.split() if n] + if not names: + raise RuntimeError("ircu-test-net docker network not found (is the TLS topology up?)") + return names[0] + + +class SidecarBogusServer: + """BogusTLSServer running in a container on the test network. + + The host firewall may drop container->host traffic, so the server runs + where the hub can reach it. Events are read back from the container's + stdout as JSON lines (see bogus_server_main.py). + """ + + def __init__(self, mode: str, *, truncate: int = 200, cert: str = "tlspeer", + delay: float = 0.0): + self.mode = mode + self.truncate = truncate + self.cert = cert + self.delay = delay + self.port = SIDECAR_PORT + self.ip = SIDECAR_IP + self.events: list[dict] = [] + self._started = False + + async def start(self) -> int: + loop = asyncio.get_running_loop() + await loop.run_in_executor(None, self._start_blocking) + self._started = True + await self.wait_event("listening", 20.0) + return self.port + + def _start_blocking(self) -> None: + subprocess.run(["docker", "rm", "-f", SIDECAR_NAME], capture_output=True, timeout=30) + net = _test_network() + cmd = [ + "docker", "run", "-d", "--name", SIDECAR_NAME, + "--network", net, "--ip", self.ip, + "-v", f"{TESTS_DIR}:/tests:ro", "-e", "PYTHONPATH=/tests", "-w", "/tests", + SIDECAR_IMAGE, "python", "-u", "tls/bogus_server_main.py", + "--mode", self.mode, "--port", str(self.port), + "--truncate", str(self.truncate), "--cert", self.cert, + "--delay", str(self.delay), + ] + r = subprocess.run(cmd, capture_output=True, text=True, timeout=180) + if r.returncode != 0: + raise RuntimeError(f"sidecar start failed: {r.stderr.strip()}") + + def _poll_events(self) -> list[dict]: + r = subprocess.run(["docker", "logs", SIDECAR_NAME], capture_output=True, text=True, timeout=30) + events = [] + for line in r.stdout.splitlines(): + line = line.strip() + if line.startswith("{"): + try: + events.append(json.loads(line)) + except ValueError: + pass + return events + + async def wait_event(self, name: str, timeout: float) -> dict: + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + while True: + self.events = await loop.run_in_executor(None, self._poll_events) + for ev in self.events: + if ev.get("event") == name: + return ev + if loop.time() > deadline: + raise asyncio.TimeoutError(f"sidecar: no {name!r} event; got {self.events[-5:]}") + await asyncio.sleep(0.3) + + @property + def received_raw(self) -> bytes: + data = b"" + for ev in self.events: + if ev.get("event") == "raw": + data += bytes.fromhex(ev["hex"]) + return data + + @property + def app_lines(self) -> list[str]: + return [ev["text"] for ev in self.events if ev.get("event") == "line"] + + async def stop(self) -> None: + if not self._started: + return + loop = asyncio.get_running_loop() + await loop.run_in_executor( + None, + lambda: subprocess.run(["docker", "rm", "-f", SIDECAR_NAME], capture_output=True, timeout=30), + ) + self._started = False + + +# --------------------------------------------------------------------------- +# Observers +# --------------------------------------------------------------------------- + + +def container_cpu_percent(container: str) -> float | None: + """One `docker stats` sample of the container's CPU usage, or None.""" + try: + out = subprocess.run( + ["docker", "stats", "--no-stream", "--format", "{{.CPUPerc}}", container], + capture_output=True, text=True, timeout=15, + ) + except (OSError, subprocess.SubprocessError): + return None + if out.returncode != 0: + return None + value = out.stdout.strip().rstrip("%") + try: + return float(value) + except ValueError: + return None + + +async def sample_cpu(container: str, seconds: float) -> list[float]: + """Sample CPU% repeatedly for `seconds` (each sample takes ~1-2 s).""" + loop = asyncio.get_running_loop() + deadline = loop.time() + seconds + samples: list[float] = [] + while loop.time() < deadline: + value = await loop.run_in_executor(None, container_cpu_percent, container) + if value is not None: + samples.append(value) + return samples diff --git a/tests/tls/bogus_server_main.py b/tests/tls/bogus_server_main.py new file mode 100644 index 00000000..fa73badd --- /dev/null +++ b/tests/tls/bogus_server_main.py @@ -0,0 +1,78 @@ +"""Entry point for running BogusTLSServer inside a container. + +Prints one JSON object per line on stdout so the test on the host can +follow what happened through `docker logs`: + + {"event": "listening", "port": N} + {"event": "accepted"} + {"event": "raw", "hex": "..."} bytes received on the wire (silent / + garbage / truncated modes) + {"event": "line", "text": "..."} decrypted application-data line + (complete mode) + {"event": "done"} +""" + +from __future__ import annotations + +import argparse +import asyncio +import json +import subprocess +import sys + +from tls.bogus_peer import BogusTLSServer + + +def emit(**kw) -> None: + sys.stdout.write(json.dumps(kw) + "\n") + sys.stdout.flush() + + +async def main() -> None: + ap = argparse.ArgumentParser() + ap.add_argument("--mode", required=True) + ap.add_argument("--port", type=int, default=4500) + ap.add_argument("--truncate", type=int, default=200) + ap.add_argument("--cert", default="tlspeer") + ap.add_argument("--delay", type=float, default=0.0) + args = ap.parse_args() + + # Each scenario replaces the container at the same address; announce the + # new MAC so the hub's neighbour cache does not point at the old one. + try: + ip = subprocess.run(["hostname", "-i"], capture_output=True, text=True, timeout=5).stdout.split()[0] + subprocess.run(["arping", "-c", "2", "-U", "-I", "eth0", ip], capture_output=True, timeout=10) + except Exception: + pass + + srv = BogusTLSServer(args.mode, cert=args.cert, truncate=args.truncate, delay=args.delay) + srv.server = await asyncio.start_server(srv._handle, "0.0.0.0", args.port) + srv.port = args.port + emit(event="listening", port=args.port) + + async def report() -> None: + raw_sent = 0 + lines_sent = 0 + accepted_sent = False + while True: + await asyncio.sleep(0.2) + if srv.accepted.is_set() and not accepted_sent: + accepted_sent = True + emit(event="accepted") + if len(srv.received_raw) > raw_sent: + emit(event="raw", hex=bytes(srv.received_raw[raw_sent:]).hex()) + raw_sent = len(srv.received_raw) + while lines_sent < len(srv.app_lines): + emit(event="line", text=srv.app_lines[lines_sent]) + lines_sent += 1 + if srv.done.is_set(): + emit(event="done") + return + + await report() + # Keep serving (ircd may reconnect) until the container is removed. + await asyncio.Event().wait() + + +if __name__ == "__main__": + asyncio.run(main()) diff --git a/tests/tls/test_tls_bogus_peer.py b/tests/tls/test_tls_bogus_peer.py new file mode 100644 index 00000000..a728c667 --- /dev/null +++ b/tests/tls/test_tls_bogus_peer.py @@ -0,0 +1,531 @@ +"""Misbehaving TLS peers against ircd's inbound and outbound handshake paths. + +Each scenario parks ircd in one handshake state (waiting for the peer, +blocked on a write, mid-record, garbage on the wire, RST/FIN mid-handshake, +peer that never reads) and checks three things: + + * the deadline: the connection is torn down at TLS_HANDSHAKE_TIMEOUT (5 s) + or promptly on a hard failure, with nothing written before the close; + * no CPU spin: `docker stats` on the hub stays far below 100% while peers + are stalled (the original inbound bug spun on a level-triggered writable + event for the whole handshake); + * liveness: a healthy client keeps getting PONGs while peers are stalled. + +Outbound scenarios use the hub's `Connect { name = "bogus.test.net"; +host = "10.55.0.40"; }` block: a BogusTLSServer runs in a sidecar container +on the test network and an oper issues `CONNECT bogus.test.net `, so +the hub runs its own client-side handshake against a server we control +byte by byte. + +Set BOGUS_TLS_HOST / BOGUS_TLS_PORT / BOGUS_TLS_SERVER_PORT to run the +inbound scenarios against a real ircd instead of the docker hub (CPU and +notice checks are skipped there). +""" + +from __future__ import annotations + +import asyncio +import os +import re +import time + +import pytest +import pytest_asyncio + +from irc_client import IRCClient +from tls.bogus_peer import BogusTLSClient, SidecarBogusServer, sample_cpu, wait_for_eof +from tls.helpers import oper_up + +pytestmark = [pytest.mark.tls, pytest.mark.asyncio] + +HUB_CONTAINER = "ircu-tls-hub" +HANDSHAKE_TIMEOUT = 5.0 +# Deadline window: timer fires at 5 s, plus docker/scheduling slack. +CLOSE_MIN, CLOSE_MAX = 3.5, 10.0 +CPU_SPIN_THRESHOLD = 50.0 # a single-threaded spin shows as ~100% + +EXTERNAL = os.environ.get("BOGUS_TLS_HOST") + + +def _target(hub: dict) -> dict: + if EXTERNAL: + return { + "host": EXTERNAL, + "tls_port": int(os.environ["BOGUS_TLS_PORT"]), + "server_port": int(os.environ["BOGUS_TLS_SERVER_PORT"]), + "external": True, + } + return {"host": hub["host"], "tls_port": hub["tls_port"], + "server_port": hub["server_port"], "external": False} + + +# --------------------------------------------------------------------------- +# helpers +# --------------------------------------------------------------------------- + + +async def _oper(hub: dict, nick: str) -> IRCClient: + c = IRCClient() + await c.connect(hub["host"], hub["port"]) + await c.register(nick, "oper", "Bogus peer oper") + msg = await oper_up(c) + assert msg.command == "381", msg + await c.send(f"MODE {nick} +s +65535") + await asyncio.sleep(0.2) + return c + + +async def _notices(oper: IRCClient, pattern: str, seconds: float) -> list[str]: + """Collect server notices matching `pattern` for `seconds`.""" + rx = re.compile(pattern) + found = [] + loop = asyncio.get_running_loop() + deadline = loop.time() + seconds + while True: + remaining = deadline - loop.time() + if remaining <= 0: + return found + try: + msg = await oper.recv(timeout=remaining) + except asyncio.TimeoutError: + return found + if msg.command == "NOTICE" and rx.search(msg.params[-1]): + found.append(msg.params[-1]) + + +async def _wait_notice(oper: IRCClient, pattern: str, timeout: float) -> str: + rx = re.compile(pattern) + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + seen = [] + while True: + remaining = deadline - loop.time() + if remaining <= 0: + raise AssertionError(f"no notice matching {pattern!r} within {timeout}s; saw {seen[-5:]}") + msg = await oper.recv(timeout=remaining) + if msg.command == "NOTICE": + seen.append(msg.params[-1]) + if rx.search(msg.params[-1]): + return msg.params[-1] + + +async def _ping_rtt(client: IRCClient, token: str, timeout: float = 2.0) -> float: + start = time.monotonic() + await client.send(f"PING :{token}") + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + while True: + remaining = deadline - loop.time() + if remaining <= 0: + raise AssertionError("healthy client got no PONG while peers stalled") + msg = await client.recv(timeout=remaining) + if msg.command == "PONG" and msg.params[-1] == token: + return time.monotonic() - start + + +async def _recv_until(peer: BogusTLSClient, needle: str, timeout: float) -> str: + """Read decrypted data until `needle` appears or `timeout` elapses.""" + got = "" + answered = 0 + deadline = time.monotonic() + timeout + while needle not in got: + remaining = deadline - time.monotonic() + if remaining <= 0: + break + try: + got += await peer.recv_app(timeout=min(remaining, 5.0)) + except asyncio.TimeoutError: + continue + except ConnectionError: + break + # Registration requires answering the nospoof PING. + for m in re.finditer(r"^PING :(\S+)\r?$", got, re.M): + if m.end() > answered: + await peer.send_app(f"PONG :{m.group(1)}\r\n") + answered = m.end() + return got + + +async def _cpu_or_none(target: dict, seconds: float) -> list[float]: + if target["external"]: + await asyncio.sleep(seconds) + return [] + return await sample_cpu(HUB_CONTAINER, seconds) + + +def _assert_no_spin(samples: list[float], what: str) -> None: + if not samples: + return + assert max(samples) < CPU_SPIN_THRESHOLD, ( + f"hub CPU spun while {what}: samples={samples}" + ) + + +def _assert_closed_on_deadline(elapsed: float, what: str) -> None: + assert elapsed >= 0, f"{what}: still open after {CLOSE_MAX}s" + assert CLOSE_MIN <= elapsed <= CLOSE_MAX, ( + f"{what}: closed after {elapsed:.1f}s, expected ~{HANDSHAKE_TIMEOUT}s" + ) + + +@pytest_asyncio.fixture +async def healthy(ircd_tls_network): + """A registered plaintext client on the hub used as a liveness probe.""" + hub = ircd_tls_network["hub"] + if EXTERNAL: + yield None + return + c = IRCClient() + await c.connect(hub["host"], hub["port"]) + await c.register("bogushealthy", "probe", "liveness probe") + yield c + try: + await c.disconnect() + except Exception: + pass + + +# --------------------------------------------------------------------------- +# inbound: bogus clients +# --------------------------------------------------------------------------- + + +async def test_silent_peers_time_out_without_spin(ircd_tls_network, healthy): + """Several peers that connect and send nothing: each is closed at the + deadline with no bytes written, the hub does not spin, and a healthy + client stays responsive meanwhile.""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + oper = None if tgt["external"] else await _oper(hub, "bogusop1") + peers = [BogusTLSClient(tgt["host"], tgt["tls_port"]) for _ in range(4)] + peers += [BogusTLSClient(tgt["host"], tgt["server_port"]) for _ in range(2)] + start = time.monotonic() + try: + for p in peers: + await p.connect() + samples = await _cpu_or_none(tgt, 3.0) + if healthy: + rtt = await _ping_rtt(healthy, "silent") + assert rtt < 1.0, f"PONG took {rtt:.2f}s during stall" + results = await asyncio.gather(*(wait_for_eof(p.reader, CLOSE_MAX) for p in peers)) + for (data, waited), p in zip(results, peers): + assert data == b"", f"server wrote {data[:40]!r} to a silent peer" + _assert_closed_on_deadline( + (time.monotonic() - start) if waited >= 0 else -1, f"silent peer on :{p.port}" + ) + _assert_no_spin(samples, "6 peers sat silent in the handshake") + if oper: + notes = await _notices(oper, r"TLS negotiation failed from unknown server.*timed out", 2.0) + assert len(notes) >= 2, notes # the two server-port peers + finally: + for p in peers: + await p.close() + if oper: + await oper.disconnect() + + +async def test_stall_after_clienthello_times_out_without_spin(ircd_tls_network, healthy): + """ClientHello sent, server flight received, peer never continues.""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"]) + try: + await peer.connect() + hello = peer.start_tls() + start = time.monotonic() + await peer.send_raw(hello) + flight = await peer.feed(timeout=5.0) + assert flight[:1] == b"\x16", f"expected a TLS handshake record, got {flight[:8]!r}" + samples = await _cpu_or_none(tgt, 3.0) + if healthy: + assert await _ping_rtt(healthy, "stall") < 1.0 + data, waited = await wait_for_eof(peer.reader, CLOSE_MAX) + _assert_closed_on_deadline((time.monotonic() - start) if waited >= 0 else -1, "stalled after ClientHello") + # Nothing but TLS records: no plaintext ERROR into the handshake stream. + assert not data or data[:1] in (b"\x15", b"\x16", b"\x17"), data[:40] + _assert_no_spin(samples, "peer stalled after ClientHello") + finally: + await peer.close() + + +async def test_slowloris_clienthello_is_cut_at_deadline(ircd_tls_network, healthy): + """A ClientHello dribbled one byte at a time keeps generating read + events but must not extend the deadline (and must not spin).""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"]) + try: + await peer.connect() + hello = peer.start_tls() + start = time.monotonic() + dribble = asyncio.create_task(peer.send_slowly(hello, 1, 0.15)) + samples = await _cpu_or_none(tgt, 3.0) + data, waited = await wait_for_eof(peer.reader, CLOSE_MAX) + dribble.cancel() + _assert_closed_on_deadline((time.monotonic() - start) if waited >= 0 else -1, "slowloris ClientHello") + assert data == b"" + _assert_no_spin(samples, "ClientHello dribbled 1 byte at a time") + finally: + await peer.close() + + +async def test_slow_but_complete_handshake_registers(ircd_tls_network): + """Control: a slow peer that does finish inside the deadline registers.""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"]) + try: + await peer.connect() + hello = peer.start_tls() + await peer.send_slowly(hello, 48, 0.1) # ~0.5-1 s + await peer.complete_handshake(timeout=8.0) + await peer.send_app("NICK bogusslow\r\nUSER slow 0 * :slow\r\n") + got = await _recv_until(peer, " 001 ", 15.0) + assert " 001 " in got, got[-300:] + finally: + await peer.close() + + +async def test_finished_coalesced_with_data_registers(ircd_tls_network): + """The client's Finished and its first application record arrive in + one segment. After the handshake completes the server must still pick + up the application data that is already queued (whether it sits in the + kernel or was pulled into the TLS library's buffer).""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"]) + try: + await peer.connect() + finished = await peer.complete_handshake(timeout=8.0, flush=False) + assert finished, "expected an unsent client Finished flight" + await peer.send_raw(finished + peer.app_bytes("NICK boguscoal\r\nUSER coal 0 * :coalesced\r\n")) + got = await _recv_until(peer, " 001 ", 15.0) + assert " 001 " in got, got[-300:] + finally: + await peer.close() + + +async def test_garbage_after_clienthello_closes_promptly(ircd_tls_network, healthy): + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"]) + try: + await peer.connect() + hello = peer.start_tls() + await peer.send_raw(hello) + await peer.feed(timeout=5.0) # server flight + start = time.monotonic() + await peer.send_raw(os.urandom(2048)) + data, waited = await wait_for_eof(peer.reader, CLOSE_MAX) + assert waited >= 0, "server kept a garbage-fed handshake open" + assert time.monotonic() - start < 3.0, "garbage should fail the handshake immediately" + assert not data or data[:1] in (b"\x15", b"\x16", b"\x17"), data[:40] + if healthy: + assert await _ping_rtt(healthy, "garbage") < 1.0 + finally: + await peer.close() + + +@pytest.mark.parametrize("how", ["rst", "fin"]) +async def test_abort_mid_handshake_then_normal_client_works(ircd_tls_network, how): + """RST or FIN right after ClientHello must be handled cleanly; a normal + TLS registration afterwards proves nothing was left wedged.""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"]) + await peer.connect() + hello = peer.start_tls() + await peer.send_raw(hello) + await peer.feed(timeout=5.0) + if how == "rst": + await peer.close_rst() + else: + await peer.close_fin() + data, waited = await wait_for_eof(peer.reader, 6.0) + assert waited >= 0, "server did not close after peer FIN mid-handshake" + assert waited < 3.0, f"FIN mid-handshake took {waited:.1f}s to close" + await peer.close() + await asyncio.sleep(0.3) + + ok = IRCClient() + await ok.connect_tls(tgt["host"], tgt["tls_port"]) + try: + msgs = await ok.register(f"bogusok{how}", "ok", "after abort") + assert any(m.command == "001" for m in msgs) + finally: + await ok.disconnect() + + +async def test_peer_that_never_reads_is_cut_at_deadline(ircd_tls_network, healthy): + """Tiny receive window, ClientHello sent, then the peer never reads: the + server's flight may block on write (WANT_WRITE); it must wait on the + write side without spinning and still abort at the deadline.""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"], rcvbuf=1024) + try: + await peer.connect() + hello = peer.start_tls() + start = time.monotonic() + await peer.send_raw(hello) + samples = await _cpu_or_none(tgt, 3.5) + if healthy: + assert await _ping_rtt(healthy, "noread") < 1.0 + await asyncio.sleep(max(0.0, HANDSHAKE_TIMEOUT + 1.5 - (time.monotonic() - start))) + # Only now start reading: whatever was queued, then EOF. + data, waited = await wait_for_eof(peer.reader, 4.0) + assert waited >= 0, "server kept a never-reading peer open past the deadline" + assert data[:1] == b"\x16", f"expected the server flight, got {data[:8]!r}" + _assert_no_spin(samples, "peer never read the server flight") + finally: + await peer.close() + + +async def test_flood_without_reading_after_handshake(ircd_tls_network, healthy): + """Completed handshake, then the peer floods commands and never reads + the replies: the data-path write side must back off, kill the client + (sendq or flood limit) and never spin.""" + hub = ircd_tls_network["hub"] + tgt = _target(hub) + peer = BogusTLSClient(tgt["host"], tgt["tls_port"], rcvbuf=2048) + try: + await peer.connect() + await peer.complete_handshake() + await peer.send_app("NICK bogusflood\r\nUSER flood 0 * :flood\r\n") + start = time.monotonic() + # Ask for lots of output without ever reading it. + try: + for _ in range(400): + await peer.send_app("MOTD\r\nLUSERS\r\nVERSION\r\nADMIN\r\n") + except (ConnectionResetError, BrokenPipeError, OSError): + pass + samples = await _cpu_or_none(tgt, 3.0) + if healthy: + assert await _ping_rtt(healthy, "flood") < 1.0 + data, waited = await wait_for_eof(peer.reader, 60.0) + assert waited >= 0, "flooding peer was never disconnected" + _assert_no_spin(samples, "peer flooded without reading") + finally: + await peer.close() + + +# --------------------------------------------------------------------------- +# outbound: bogus servers the hub connects to +# --------------------------------------------------------------------------- + +PEER_NAME = "bogus.test.net" + + +@pytest_asyncio.fixture +async def link_oper(ircd_tls_network): + if EXTERNAL: + pytest.skip("outbound scenarios need the docker hub") + hub = ircd_tls_network["hub"] + oper = await _oper(hub, "boguslink") + yield oper + try: + await oper.disconnect() + except Exception: + pass + + +async def _connect_out(oper: IRCClient, port: int) -> None: + await oper.send(f"CONNECT {PEER_NAME} {port}") + + +async def test_outbound_silent_server_times_out(ircd_tls_network, link_oper): + srv = SidecarBogusServer("silent") + port = await srv.start() + try: + await _connect_out(link_oper, port) + await srv.wait_event("accepted", 10.0) + start = time.monotonic() + samples = await sample_cpu(HUB_CONTAINER, 3.0) + note = await _wait_notice(link_oper, rf"TLS negotiation failed to {PEER_NAME}.*timed out", CLOSE_MAX) + elapsed = time.monotonic() - start + assert elapsed <= CLOSE_MAX, f"outbound timeout took {elapsed:.1f}s" + # The hub did start the handshake: a TLS handshake record arrived. + await srv.wait_event("raw", 3.0) + assert srv.received_raw[:1] == b"\x16", srv.received_raw[:8] + _assert_no_spin(samples, "outbound peer stayed silent") + assert "timed out" in note + finally: + await srv.stop() + + +async def test_outbound_truncated_server_flight_times_out(ircd_tls_network, link_oper): + srv = SidecarBogusServer("truncated_flight", truncate=200) + port = await srv.start() + try: + await _connect_out(link_oper, port) + await srv.wait_event("accepted", 10.0) + start = time.monotonic() + samples = await sample_cpu(HUB_CONTAINER, 3.0) + note = await _wait_notice(link_oper, rf"TLS negotiation failed to {PEER_NAME}", CLOSE_MAX) + assert "timed out" in note, note + assert time.monotonic() - start <= CLOSE_MAX + _assert_no_spin(samples, "outbound server sent a truncated flight") + finally: + await srv.stop() + + +# delay=0: the failure is already on the wire when the hub's connect step +# runs its first negotiate (detected in completed_connection()). +# delay=1: the hub has parked waiting for the server flight and the +# failure arrives as a later read event (detected in the ET_READ arm). +# Both must be reported to opers immediately, never via the 5 s deadline. +@pytest.mark.parametrize("delay", [0.0, 1.0], ids=["during-connect", "after-connect"]) +async def test_outbound_garbage_server_fails_fast(ircd_tls_network, link_oper, delay): + srv = SidecarBogusServer("garbage", delay=delay) + port = await srv.start() + try: + await _connect_out(link_oper, port) + await srv.wait_event("accepted", 10.0) + start = time.monotonic() + note = await _wait_notice(link_oper, rf"TLS negotiation failed to {PEER_NAME}", 6.0) + assert "timed out" not in note, note + assert time.monotonic() - start < delay + 3.0, note + finally: + await srv.stop() + + +@pytest.mark.parametrize("delay", [0.0, 1.0], ids=["during-connect", "after-connect"]) +async def test_outbound_server_closes(ircd_tls_network, link_oper, delay): + srv = SidecarBogusServer("close", delay=delay) + port = await srv.start() + try: + await _connect_out(link_oper, port) + await srv.wait_event("accepted", 10.0) + start = time.monotonic() + # Depending on timing the EOF is seen by the TLS layer (unexpected + # eof), by the connect step, or as a socket reset on a later event; + # every variant must reach the oper who issued the CONNECT. + note = await _wait_notice( + link_oper, + rf"(TLS negotiation failed to {PEER_NAME}|Connection failed to {PEER_NAME}" + rf"|Link with {PEER_NAME} canceled)", + 6.0, + ) + assert "timed out" not in note, note + assert time.monotonic() - start < delay + 3.0, note + finally: + await srv.stop() + + +async def test_outbound_full_handshake_delivers_pass_and_server(ircd_tls_network, link_oper): + """Control: against a well-behaved foreign TLS stack the hub completes + the handshake and sends PASS + SERVER over the encrypted link.""" + srv = SidecarBogusServer("complete", cert="tlspeer") + port = await srv.start() + try: + await _connect_out(link_oper, port) + await srv.wait_event("line", 10.0) + await asyncio.sleep(0.5) + await srv.wait_event("line", 1.0) + lines = srv.app_lines + assert any(l.startswith("PASS ") for l in lines), lines + assert any(l.startswith("SERVER tls-hub.test.net ") for l in lines), lines + finally: + await srv.stop() + # The hub drops the link once our server goes away. + await _notices(link_oper, r".", 1.0) diff --git a/tests/tls/test_tls_s2s_burst.py b/tests/tls/test_tls_s2s_burst.py new file mode 100644 index 00000000..d75c75bb --- /dev/null +++ b/tests/tls/test_tls_s2s_burst.py @@ -0,0 +1,142 @@ +"""S2S TLS link carrying a populated burst, initiated from each side. + +Links tls-hub and tls-leaf over TLS with the hub in both TLS roles (client +when it initiates, server when the leaf does) and a non-trivial user burst, +and requires the link to stay up and the burst to have arrived on the far +side. Regression coverage for the TLS handshake / send-path code on server +links, which the other S2S tests exercise only with an empty network. +""" + +from __future__ import annotations + +import asyncio +import logging + +import pytest + +from irc_client import IRCClient +from tls.helpers import ( + links_contains, + oper_up, + populate_channels, +) + +log = logging.getLogger(__name__) + +pytestmark = [pytest.mark.tls, pytest.mark.tls_stress, pytest.mark.asyncio] + +HUB_NAME = "tls-hub.test.net" +LEAF_NAME = "tls-leaf.test.net" + + +async def _oper(host: str, port: int, nick: str) -> IRCClient: + c = IRCClient() + await c.connect(host, port) + await c.register(nick, "oper", "Oper") + msg = await oper_up(c) + assert msg.command == "381", msg + # See server notices (net breaks, TLS failures) for diagnosis. + await c.send(f"MODE {nick} +s +65535") + return c + + +async def _drain(c: IRCClient, seconds: float, tag: str) -> list: + """Read everything for `seconds`, logging each line.""" + out = [] + loop = asyncio.get_running_loop() + deadline = loop.time() + seconds + while True: + remaining = deadline - loop.time() + if remaining <= 0: + return out + try: + msg = await c.recv(timeout=remaining) + except asyncio.TimeoutError: + return out + out.append(msg) + log.info("%s <- %s", tag, msg.raw) + + +async def _wait_linked(c: IRCClient, peer: str, tag: str, timeout: float = 45.0) -> None: + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + while loop.time() < deadline: + await _drain(c, 1.0, tag) + if await links_contains(c, peer, timeout=5.0): + return + raise TimeoutError(f"{tag}: {peer} never appeared in LINKS") + + +async def _wait_unlinked(c: IRCClient, peer: str, tag: str, timeout: float = 30.0) -> None: + loop = asyncio.get_running_loop() + deadline = loop.time() + timeout + while loop.time() < deadline: + await _drain(c, 1.0, tag) + if not await links_contains(c, peer, timeout=5.0): + return + raise TimeoutError(f"{tag}: {peer} still in LINKS") + + +async def _whois_ok(c: IRCClient, nick: str) -> bool: + await c.send(f"WHOIS {nick}") + while True: + msg = await c.recv(timeout=10.0) + if msg.command == "311": + return True + if msg.command in ("401", "318"): + return False + + +async def _link_and_check( + initiator: IRCClient, other: IRCClient, peer: str, port: int, + other_peer: str, probe_nick: str, tag: str, +) -> None: + await initiator.send(f"CONNECT {peer} {port}") + await _wait_linked(initiator, peer, f"{tag}/init") + await _wait_linked(other, other_peer, f"{tag}/other") + # Let the burst finish and any delayed failure show up. + await _drain(initiator, 8.0, f"{tag}/init") + await _drain(other, 3.0, f"{tag}/other") + assert await links_contains(initiator, peer), f"{tag}: link dropped (initiator side)" + assert await links_contains(other, other_peer), f"{tag}: link dropped (other side)" + assert await _whois_ok(other, probe_nick), f"{tag}: burst did not arrive on other side" + + +@pytest.mark.timeout(400) +async def test_s2s_tls_burst_both_directions(ircd_tls_network): + hub = ircd_tls_network["hub"] + leaf = ircd_tls_network["leaf"] + crowd: list[IRCClient] = [] + hub_op = leaf_op = None + try: + hub_op = await _oper(hub["host"], hub["port"], "s2sophub") + leaf_op = await _oper(leaf["host"], leaf["port"], "s2sopleaf") + + # Start from an unlinked state. + if await links_contains(hub_op, LEAF_NAME): + await hub_op.send(f"SQUIT {LEAF_NAME} :reset") + await _wait_unlinked(hub_op, LEAF_NAME, "reset/hub") + await _wait_unlinked(leaf_op, HUB_NAME, "reset/leaf") + + crowd = await populate_channels(hub) + log.info("crowd of %d populated on hub", len(crowd)) + + # Direction 1: hub initiates (hub is TLS client, sends the big burst). + await _link_and_check(hub_op, leaf_op, LEAF_NAME, 4401, HUB_NAME, + "crwd00", "hub->leaf") + + await hub_op.send(f"SQUIT {LEAF_NAME} :direction swap") + await _wait_unlinked(hub_op, LEAF_NAME, "swap/hub") + await _wait_unlinked(leaf_op, HUB_NAME, "swap/leaf") + + # Direction 2: leaf initiates (hub is TLS server). + await _link_and_check(leaf_op, hub_op, HUB_NAME, 4441, LEAF_NAME, + "crwd00", "leaf->hub") + finally: + for c in [hub_op, leaf_op, *crowd]: + if c is None: + continue + try: + await c.disconnect() + except Exception: + pass