diff --git a/src/tls_filter.c b/src/tls_filter.c index 4b9f9a6..ad433fd 100644 --- a/src/tls_filter.c +++ b/src/tls_filter.c @@ -16,6 +16,7 @@ #include #include #include +#include #include #include @@ -61,27 +62,85 @@ static rustls_io_result tls_read_callback( * function to handle the added data before leaving. */ static apr_status_t read_tls_to_rustls( - tls_filter_ctx_t *fctx, apr_size_t len, apr_read_type_e block, int errors_expected) + tls_filter_ctx_t* fctx, apr_size_t len, apr_read_type_e block) { + apr_read_type_e caller_block = block; /* preserve caller's blocking mode */ tls_data_t d; apr_size_t rlen; apr_off_t passed = 0; rustls_result rr = RUSTLS_RESULT_OK; int os_err; apr_status_t rv = APR_SUCCESS; + apr_bucket *b; + int force_read = 0; /* Flag to force reading even if wants_read is false */ + apr_read_type_e read_block; + /* Check if rustls wants to read data. If not, we may still need to read + * from the network in blocking mode if we have incomplete TLS records + * (indicated by fin_bytes_in_rustls > 0). */ + if (!rustls_connection_wants_read(fctx->cc->rustls_connection)) { + if (block == APR_NONBLOCK_READ) { + rv = APR_EAGAIN; + goto cleanup; + } + /* In blocking mode, if we have data in rustls, it means rustls is + * processing incomplete TLS records and needs more network data to + * complete them. We should continue reading from the network even + * though wants_read is false. */ + if (fctx->fin_bytes_in_rustls > 0) { + /* Rustls has incomplete records, continue to read from network. + * Set force_read flag to ignore wants_read check in the loop. */ + force_read = 1; + } + else { + /* Rustls is not ready and we have no data buffered inside rustls. + * In non-blocking mode, indicate try again; in blocking mode, just + * proceed to read from the network (below) and block as needed. */ + if (block == APR_NONBLOCK_READ) { + rv = APR_EAGAIN; + goto cleanup; + } + /* For blocking mode: do not error here; let the code below perform + * a blocking ap_get_brigade() to fetch more TLS bytes. */ + } + } if (APR_BRIGADE_EMPTY(fctx->fin_tls_bb)) { ap_log_error(APLOG_MARK, APLOG_TRACE2, rv, fctx->cc->server, "read_tls_to_rustls, get data from network, block=%d", block); + /* If force_read is set, we need to read from network in blocking mode + * even if wants_read is false, to complete incomplete TLS records. */ + read_block = block; + if (force_read && fctx->fin_block != APR_NONBLOCK_READ) { + read_block = APR_BLOCK_READ; + } rv = ap_get_brigade(fctx->fin_ctx->next, fctx->fin_tls_bb, - AP_MODE_READBYTES, block, (apr_off_t)len); + AP_MODE_READBYTES, read_block, (apr_off_t)len); if (APR_SUCCESS != rv) { - goto cleanup; + /* In blocking mode, do not propagate EAGAIN upward; allow caller loop to retry */ + if (read_block == APR_BLOCK_READ && APR_STATUS_IS_EAGAIN(rv)) { + rv = APR_SUCCESS; + } + else { + goto cleanup; + } } } - while (!APR_BRIGADE_EMPTY(fctx->fin_tls_bb) && passed < (apr_off_t)len) { - apr_bucket *b = APR_BRIGADE_FIRST(fctx->fin_tls_bb); + while (!APR_BRIGADE_EMPTY(fctx->fin_tls_bb)) { + /* Do not feed too much in a single call: keep to ~one TLS record + * so that upper logic can interleave decrypt/flush for WS full-duplex. */ + if (passed >= (apr_off_t)TLS_REC_MAX_SIZE) { + break; + } + /* Check wants_read before each bucket to ensure rustls is ready + * to accept more data. This prevents overwhelming rustls with + * too much data at once. However, if force_read is set, we ignore + * this check because we need to read more data to complete incomplete + * TLS records. */ + if (!force_read && !rustls_connection_wants_read(fctx->cc->rustls_connection)) { + break; + } + b = APR_BRIGADE_FIRST(fctx->fin_tls_bb); if (APR_BUCKET_IS_EOS(b)) { ap_log_error(APLOG_MARK, APLOG_TRACE2, rv, fctx->cc->server, @@ -123,27 +182,41 @@ static apr_status_t read_tls_to_rustls( b->start += (apr_off_t)rlen; b->length -= rlen; } - fctx->fin_bytes_in_rustls += (apr_off_t)d.len; + fctx->fin_bytes_in_rustls += (apr_off_t)rlen; + /* passed tracks how much data rustls actually accepted (rlen) */ passed += (apr_off_t)rlen; + + /* Process packets after each successful read_tls call, as per rustls + * documentation: "You should call process_new_packets() each time + * a call to this function succeeds in order to empty the incoming + * TLS data buffer." */ + if (rlen > 0) { + rr = rustls_connection_process_new_packets(fctx->cc->rustls_connection); + if (rr != RUSTLS_RESULT_OK) { + /* If processing fails, we've already passed some data to rustls. */ + goto cleanup; + } + } } else if (d.len == 0) { apr_bucket_delete(b); } } - if (passed > 0) { - rr = rustls_connection_process_new_packets(fctx->cc->rustls_connection); - if (rr != RUSTLS_RESULT_OK) goto cleanup; - } - cleanup: if (rr != RUSTLS_RESULT_OK) { - rv = APR_ECONNRESET; - if (!errors_expected) { - const char *err_descr = ""; - rv = tls_core_error(fctx->c, rr, &err_descr); - ap_log_cerror(APLOG_MARK, APLOG_WARNING, rv, fctx->c, APLOGNO(10353) - "processing TLS data: [%d] %s", (int)rr, err_descr); + /* Treat a peer close_notify as a graceful EOF, not a reset. */ + if (rr == RUSTLS_RESULT_ALERT_CLOSE_NOTIFY) { + rv = APR_EOF; + } + else { + /* If we already processed some bytes, return a soft error instead of reset */ + if (passed > 0) { + rv = APR_EGENERAL; + } + else { + rv = APR_ECONNRESET; + } } } else if (APR_STATUS_IS_EOF(rv) && passed > 0) { @@ -157,6 +230,31 @@ static apr_status_t read_tls_to_rustls( ap_log_error(APLOG_MARK, APLOG_TRACE2, rv, fctx->cc->server, "read_tls_to_rustls, passed %ld bytes to rustls", (long)passed); } + /* Coerce EAGAIN only for blocking callers; propagate for non-blocking */ + if ((rv == APR_EAGAIN || APR_STATUS_IS_EAGAIN(rv) || rv == APR_FROM_OS_ERROR(EAGAIN))) { + if (caller_block == APR_BLOCK_READ) { + if (APLOGctrace4(fctx->c)) { + ap_log_cerror(APLOG_MARK, APLOG_TRACE4, rv, fctx->c, + "read_tls_to_rustls: coerce EAGAIN->SUCCESS (blocking)"); + } + rv = APR_SUCCESS; + } else { + if (APLOGctrace4(fctx->c)) { + ap_log_cerror(APLOG_MARK, APLOG_TRACE4, rv, fctx->c, + "read_tls_to_rustls: return EAGAIN (non-blocking, no progress)"); + } + rv = APR_EAGAIN; + } + } + /* Final unified trace for exit status and state */ + if (APLOGctrace1(fctx->c)) { + int wants_r = rustls_connection_wants_read(fctx->cc->rustls_connection); + int wants_w = rustls_connection_wants_write(fctx->cc->rustls_connection); + ap_log_cerror(APLOG_MARK, APLOG_TRACE1, rv, fctx->c, + "read_tls_to_rustls: return rv=%d rr=%d passed=%ld block=%d wants_read=%d wants_write=%d fin_bytes_in_rustls=%ld", + (int)rv, (int)rr, (long)passed, (int)block, wants_r, wants_w, + (long)fctx->fin_bytes_in_rustls); + } return rv; } @@ -167,7 +265,8 @@ static apr_status_t fout_pass_tls_to_net(tls_filter_ctx_t *fctx) if (!APR_BRIGADE_EMPTY(fctx->fout_tls_bb)) { rv = ap_pass_brigade(fctx->fout_ctx->next, fctx->fout_tls_bb); if (APR_SUCCESS == rv && fctx->c->aborted) { - rv = APR_ECONNRESET; + /* Graceful close instead of hard reset if peer closed while we flushed */ + rv = APR_EOF; } fctx->fout_bytes_in_tls_bb = 0; apr_brigade_cleanup(fctx->fout_tls_bb); @@ -178,6 +277,9 @@ static apr_status_t fout_pass_tls_to_net(tls_filter_ctx_t *fctx) static apr_status_t fout_pass_all_to_net( tls_filter_ctx_t *fctx, int flush); +/* Forward declaration to allow calls from input filter before definition */ +static apr_status_t fout_pass_rustls_to_tls(tls_filter_ctx_t *fctx); + static apr_status_t filter_abort( tls_filter_ctx_t *fctx) { @@ -211,10 +313,12 @@ static apr_status_t filter_recv_client_hello(tls_filter_ctx_t *fctx) fctx->fin_tls_buffer_bb = apr_brigade_create(fctx->c->pool, fctx->c->bucket_alloc); do { if (rustls_connection_wants_read(fctx->cc->rustls_connection)) { - rv = read_tls_to_rustls(fctx, fctx->fin_max_in_rustls, APR_BLOCK_READ, 1); + rv = read_tls_to_rustls(fctx, fctx->fin_max_in_rustls, APR_BLOCK_READ); if (APR_SUCCESS != rv) { if (fctx->cc->client_hello_seen) { - rv = APR_EAGAIN; /* we got what we needed */ + /* We got what we needed - client hello was seen. + * In blocking mode, we return SUCCESS since we achieved our goal. */ + rv = APR_SUCCESS; break; } /* Something went wrong before we saw the client hello. @@ -236,7 +340,7 @@ static apr_status_t filter_recv_client_hello(tls_filter_ctx_t *fctx) fctx->fin_tls_bb = fctx->fin_tls_buffer_bb; /* data we already fed to the pre_session */ fctx->fin_tls_buffer_bb = NULL; APR_BRIGADE_CONCAT(fctx->fin_tls_bb, bb_tmp); /* all tls data from the client so far, reloaded */ - apr_brigade_destroy(bb_tmp); + apr_brigade_cleanup(bb_tmp); rv = APR_SUCCESS; } @@ -285,7 +389,7 @@ static apr_status_t filter_do_handshake( if (APR_SUCCESS != rv) goto cleanup; } else if (rustls_connection_wants_read(fctx->cc->rustls_connection)) { - rv = read_tls_to_rustls(fctx, fctx->fin_max_in_rustls, APR_BLOCK_READ, 0); + rv = read_tls_to_rustls(fctx, fctx->fin_max_in_rustls, APR_BLOCK_READ); if (APR_SUCCESS != rv) goto cleanup; } } @@ -414,18 +518,31 @@ static apr_status_t filter_conn_input( } /* If we have nothing buffered, try getting more input. - * a) ask rustls_connection for decrypted data, if it has any. - * Note that only full records can be decrypted. We might have - * written TLS data to the session, but that does not mean it - * can give unencrypted data out again. - * b) read TLS bytes from the network and feed them to the rustls session. - * c) go back to a) if b) added data. + * Use a simple loop similar to filter_recv_client_hello: + * - In blocking mode: loop until we get plaintext data or encounter an error + * - In non-blocking mode: make one attempt and return EAGAIN if no data available + * + * a) try to read decrypted data from rustls (if we have data in rustls) + * b) if nothing, check if rustls wants to read and read TLS bytes from network + * c) after reading TLS, try reading plaintext from rustls again */ while (APR_BRIGADE_EMPTY(fctx->fin_plain_bb)) { apr_size_t rlen = 0; apr_bucket *b; + int tls_read_attempted = 0; - if (fctx->fin_bytes_in_rustls > 0) { + /* If rustls has pending writes, flush them to the network first. + * This avoids stalling when peer expects TLS records (websocket full-duplex). */ + if (rustls_connection_wants_write(fctx->cc->rustls_connection)) { + rv = fout_pass_rustls_to_tls(fctx); + if (APR_SUCCESS != rv) goto cleanup; + } + + /* First attempt: try to read decrypted data from rustls. + * In blocking mode, always try to read plaintext, even if fin_bytes_in_rustls == 0, + * because rustls may process data asynchronously after process_new_packets. + * In non-blocking mode, only try if we have data in rustls. */ + if (fctx->fin_bytes_in_rustls > 0 || block == APR_BLOCK_READ) { in_buf_len = APR_BUCKET_BUFF_SIZE; in_buf = ap_calloc(in_buf_len, sizeof(char)); rr = rustls_connection_read(fctx->cc->rustls_connection, @@ -440,18 +557,134 @@ static apr_status_t filter_conn_input( if (rlen > 0) { b = apr_bucket_heap_create(in_buf, rlen, free, fctx->c->bucket_alloc); APR_BRIGADE_INSERT_TAIL(fctx->fin_plain_bb, b); + in_buf = NULL; + break; /* Got data, exit loop */ } else { free(in_buf); + in_buf = NULL; } - in_buf = NULL; } - if (rlen == 0) { - /* that did not produce anything either. try getting more - * TLS data from the network into the rustls session. */ - fctx->fin_bytes_in_rustls = 0; - rv = read_tls_to_rustls(fctx, fctx->fin_max_in_rustls, block, 0); - if (APR_SUCCESS != rv) goto cleanup; /* this also leave on APR_EAGAIN */ + + /* Second attempt: read TLS data from network if rustls wants to read. + * In blocking mode, always try reading if we don't have plaintext, to avoid + * infinite loops. In blocking mode, we must read until we get plaintext or EOF. */ + if (rlen == 0 && APR_BRIGADE_EMPTY(fctx->fin_plain_bb)) { + int should_read_tls = 0; + if (rustls_connection_wants_read(fctx->cc->rustls_connection)) { + should_read_tls = 1; + } + else if (block == APR_BLOCK_READ) { + /* In blocking mode, always try reading if we don't have plaintext. + * This prevents infinite loops when rustls needs more data but + * wants_read is temporarily false. */ + should_read_tls = 1; + } + + if (should_read_tls) { + apr_size_t read_limit; + apr_off_t bytes_in_rustls_before; + /* Avoid blocking brigade length checks; they may stall the input filter */ + + /* Limit the amount of data we read and pass to rustls at once to avoid + * overwhelming rustls. Read at most one TLS record at a time to ensure + * rustls can process it. */ + /* Prefer larger pulls in non-blocking to reduce idle gaps */ + if (block == APR_NONBLOCK_READ) { + read_limit = fctx->fin_max_in_rustls; + } + else { + read_limit = TLS_PREF_PLAIN_CHUNK_SIZE; + if (fctx->fin_max_in_rustls < read_limit) { + read_limit = fctx->fin_max_in_rustls; + } + } + /* Track how much data we had in rustls before reading */ + bytes_in_rustls_before = fctx->fin_bytes_in_rustls; + /* Do not call apr_brigade_length() here to avoid blocking */ + + rv = read_tls_to_rustls(fctx, read_limit, block); + tls_read_attempted = 1; + if (APR_SUCCESS != rv) { + if (APR_STATUS_IS_EAGAIN(rv)) { + /* On EAGAIN: non-blocking returns up; blocking always retry loop */ + if (block == APR_NONBLOCK_READ) { + goto cleanup; + } + /* Blocking mode: keep trying (do not bubble EAGAIN upward) */ + continue; + } + /* Other errors, propagate them */ + goto cleanup; + } + + /* After feeding TLS bytes, if rustls wants to write (e.g., ACKs), flush them. */ + if (rustls_connection_wants_write(fctx->cc->rustls_connection)) { + rv = fout_pass_rustls_to_tls(fctx); + if (APR_SUCCESS != rv) goto cleanup; + } + + /* Check if we actually read any new data. If not, and we're in blocking mode, + * we might be stuck. Continue the loop to try reading plaintext again. */ + if (block == APR_BLOCK_READ && fctx->fin_bytes_in_rustls == bytes_in_rustls_before && + APR_BRIGADE_EMPTY(fctx->fin_tls_bb)) { + /* No progress and no buffered TLS data: loop again and let network provide more */ + continue; + } + + /* After reading TLS data, always try reading plaintext from rustls. + * rustls_connection_process_new_packets may have processed data and + * made decrypted data available. We should always try to read it, + * even if fin_bytes_in_rustls didn't increase (e.g., if we processed + * data that was already buffered in rustls). */ + if (APR_BRIGADE_EMPTY(fctx->fin_plain_bb)) { + in_buf_len = APR_BUCKET_BUFF_SIZE; + in_buf = ap_calloc(in_buf_len, sizeof(char)); + rr = rustls_connection_read(fctx->cc->rustls_connection, + (unsigned char*)in_buf, in_buf_len, &rlen); + if (rr == RUSTLS_RESULT_PLAINTEXT_EMPTY) { + rr = RUSTLS_RESULT_OK; + rlen = 0; + } + if (rr != RUSTLS_RESULT_OK) goto cleanup; + if (rlen > 0) { + b = apr_bucket_heap_create(in_buf, rlen, free, fctx->c->bucket_alloc); + APR_BRIGADE_INSERT_TAIL(fctx->fin_plain_bb, b); + in_buf = NULL; + break; /* Got data, exit loop */ + } + else { + free(in_buf); + in_buf = NULL; + } + } + } + } + + /* If we still have nothing after one iteration: + * - In non-blocking mode, return EAGAIN to let event loop call us again. + * - In blocking mode, continue the loop (similar to filter_recv_client_hello). */ + if (APR_BRIGADE_EMPTY(fctx->fin_plain_bb)) { + if (block == APR_NONBLOCK_READ) { + rv = APR_EAGAIN; + goto cleanup; + } + /* In blocking mode, if we just read TLS data but didn't get plaintext, + * continue the loop to try reading plaintext again (rustls may need + * more data to complete records) or read more TLS data if needed. */ + if (tls_read_attempted) { + /* We read TLS data but didn't get plaintext. Continue the loop + * to try reading plaintext again (on next iteration, fin_bytes_in_rustls + * will be checked) or read more TLS data if wants_read is true. */ + continue; + } + /* In blocking mode, check if we have buffered TLS data to process */ + if (!APR_BRIGADE_EMPTY(fctx->fin_tls_bb)) { + continue; + } + /* In blocking mode, continue the loop - read_tls_to_rustls will block if needed. + * Similar to filter_recv_client_hello, we just loop until we get data. */ + continue; } } @@ -482,7 +715,9 @@ static apr_status_t filter_conn_input( rv = APR_ENOTIMPL; goto cleanup; } - fout_pass_all_to_net(fctx, 0); + /* Note: We don't flush outgoing data from input filter to avoid conflicts + * when rustls is processing incoming data. Outgoing data will be flushed + * from the output filter (tls_filter_conn_output) when it's ready. */ cleanup: if (NULL != in_buf) free(in_buf); @@ -498,9 +733,13 @@ static apr_status_t filter_conn_input( ap_log_cerror(APLOG_MARK, APLOG_DEBUG, rv, fctx->c, APLOGNO(10355) "tls_filter_conn_input: [%d] %s", (int)rr, err_descr); } - else if (APR_STATUS_IS_EAGAIN(rv)) { - ap_log_cerror(APLOG_MARK, APLOG_TRACE4, rv, fctx->c, - "tls_filter_conn_input: no data available"); + else if (APR_STATUS_IS_EAGAIN(rv) || rv == APR_FROM_OS_ERROR(EAGAIN) || rv == APR_EAGAIN) { + /* Coerce EAGAIN only for blocking callers; propagate for non-blocking */ + if (fctx->fin_block == APR_BLOCK_READ) { + rv = APR_SUCCESS; + } else { + rv = APR_EAGAIN; + } } else if (APR_SUCCESS != rv) { ap_log_cerror(APLOG_MARK, APLOG_DEBUG, rv, fctx->c, APLOGNO(10356) @@ -516,6 +755,14 @@ static apr_status_t filter_conn_input( ap_filter_setaside_brigade(f, fctx->fin_plain_bb); } #endif + /* Final guard: coerce EAGAIN only for blocking callers */ + if (APR_STATUS_IS_EAGAIN(rv) || rv == APR_FROM_OS_ERROR(EAGAIN) || rv == APR_EAGAIN) { + if (fctx->fin_block == APR_BLOCK_READ) { + rv = APR_SUCCESS; + } else { + rv = APR_EAGAIN; + } + } return rv; } @@ -641,6 +888,11 @@ static apr_status_t fout_pass_buf_to_rustls( goto cleanup; } } + /* Note: We don't call fout_pass_rustls_to_tls() here to avoid conflicts. + * TLS data will be prepared and sent through fout_pass_all_to_tls() -> + * fout_pass_rustls_to_tls() which is called from fout_pass_all_to_net() + * at appropriate times. This ensures a single point of TLS data preparation + * and avoids synchronization issues. */ cleanup: if (rr != RUSTLS_RESULT_OK) { const char *err_descr = ""; @@ -743,6 +995,7 @@ static apr_status_t fout_append_plain(tls_filter_ctx_t *fctx, apr_bucket *b) apr_status_t rv = APR_SUCCESS; const char *lbuf = NULL; int flush = 0; + int flush_nonblock = 0; if (b) { /* if our plain buffer is full, now is a good time to flush it. */ @@ -765,6 +1018,15 @@ static apr_status_t fout_append_plain(tls_filter_ctx_t *fctx, apr_bucket *b) } /* Now `b` is the bucket that we need to append and consume */ if (APR_BUCKET_IS_METADATA(b)) { + /* According to Apache filter documentation, metadata buckets (especially + * FLUSH) must be passed down the chain. FLUSH buckets force filters to + * write any data set aside. We need to ensure all buffered data is + * sent before passing the metadata bucket. */ + /* Flush any buffered plain data before processing metadata bucket */ + if (fctx->fout_buf_plain_len > 0) { + rv = fout_pass_all_to_tls(fctx); + if (APR_SUCCESS != rv) goto cleanup; + } /* outgoing buckets: * [PLAINDATA META PLAINDATA META META] * need to become: @@ -784,6 +1046,25 @@ static apr_status_t fout_append_plain(tls_filter_ctx_t *fctx, apr_bucket *b) * buffer contains data. */ rv = fout_add_bucket_to_plain(fctx, b); if (APR_SUCCESS != rv) goto cleanup; + /* For full duplex websocket connections, we need to send small chunks + * promptly to avoid blocking read operations. However, we still want + * to batch small chunks when possible for security (larger TLS records). + * Strategy: + * - If buffer is nearly full (>= 75%), flush with flush bucket + * - Always flush small chunks without blocking flush bucket to ensure + * timely delivery for full duplex websocket connections. + * Using non-blocking flush avoids breaking TLS record synchronization + * while ensuring data is sent promptly. */ + if (fctx->fout_buf_plain_len >= fctx->fout_buf_plain_size * 3 / 4) { + /* Buffer is nearly full, flush with flush bucket */ + flush = 1; + } + else { + /* Always flush small chunks without blocking flush bucket to ensure + * timely delivery for full duplex websocket connections. + * This is critical to avoid hanging on the first small chunk. */ + flush_nonblock = 1; + } } else { /* we have a large chunk and our plain buffer is empty, write it @@ -828,6 +1109,9 @@ static apr_status_t fout_append_plain(tls_filter_ctx_t *fctx, apr_bucket *b) if (APR_SUCCESS != rv && !APR_STATUS_IS_EOF(rv)) goto cleanup; rv = fout_pass_buf_to_rustls(fctx, lbuf, dlen); if (APR_SUCCESS != rv) goto cleanup; + /* For large chunks, send TLS data without blocking flush + * to avoid blocking read operations in full duplex mode. */ + flush_nonblock = 1; apr_bucket_delete(b); } else { @@ -835,13 +1119,21 @@ static apr_status_t fout_append_plain(tls_filter_ctx_t *fctx, apr_bucket *b) if (APR_SUCCESS != rv) goto cleanup; rv = fout_pass_buf_to_rustls(fctx, data, dlen); if (APR_SUCCESS != rv) goto cleanup; + /* For large chunks, send TLS data without blocking flush + * to avoid blocking read operations in full duplex mode. */ + flush_nonblock = 1; apr_bucket_delete(b); } } } maybe_flush: - if (flush) { + if (flush_nonblock) { + /* Send without blocking flush bucket for full duplex websocket */ + rv = fout_pass_all_to_net(fctx, 0); + if (APR_SUCCESS != rv) goto cleanup; + } + else if (flush) { rv = fout_pass_all_to_net(fctx, 1); if (APR_SUCCESS != rv) goto cleanup; } @@ -875,6 +1167,13 @@ static apr_status_t filter_conn_output( tls_filter_ctx_t *fctx = f->ctx; apr_status_t rv = APR_SUCCESS; rustls_result rr = RUSTLS_RESULT_OK; + int eos_seen = 0; + + /* According to Apache filter documentation, output filters should not + * pass empty brigades down the chain. Return early if empty. */ + if (APR_BRIGADE_EMPTY(bb)) { + return APR_SUCCESS; + } if (f->c->aborted) { ap_log_cerror(APLOG_MARK, APLOG_TRACE4, 0, fctx->c, @@ -901,10 +1200,29 @@ static apr_status_t filter_conn_output( } while (!APR_BRIGADE_EMPTY(bb)) { - rv = fout_append_plain(fctx, APR_BRIGADE_FIRST(bb)); + apr_bucket *b = APR_BRIGADE_FIRST(bb); + + /* According to Apache filter documentation, after seeing EOS, + * all subsequent buckets should be ignored. */ + if (eos_seen) { + apr_bucket_delete(b); + continue; + } + + /* Check for EOS bucket */ + if (APR_BUCKET_IS_EOS(b)) { + eos_seen = 1; + } + + rv = fout_append_plain(fctx, b); if (APR_SUCCESS != rv) goto cleanup; } + /* After consuming all plain buckets, push any pending TLS data to the network. + * Use non-blocking flush semantics to avoid stalling full-duplex streams. */ + rv = fout_pass_all_to_net(fctx, 0); + if (APR_SUCCESS != rv) goto cleanup; + if (APLOGctrace5(fctx->c)) { tls_util_bb_log(fctx->c, APLOG_TRACE5, "filter_conn_output, processed plain", bb); tls_util_bb_log(fctx->c, APLOG_TRACE5, "filter_conn_output, tls", fctx->fout_tls_bb); @@ -1004,7 +1322,7 @@ void tls_filter_conn_init(conn_rec *c) "tls_filter_conn_init on %s, triggering handshake", c->base_server->server_hostname); temp = apr_brigade_create(c->pool, c->bucket_alloc); ap_get_brigade(c->input_filters, temp, AP_MODE_INIT, APR_BLOCK_READ, 0); - apr_brigade_destroy(temp); + apr_brigade_cleanup(temp); } } diff --git a/test/modules/tls/env.py b/test/modules/tls/env.py index 30910f0..a05f73f 100644 --- a/test/modules/tls/env.py +++ b/test/modules/tls/env.py @@ -107,23 +107,12 @@ def __init__(self, pytestconfig=None): ' AddHandler cgi-script .py', ' Options +ExecCGI', '', - f'', - ' ServerName localhost', - ' DocumentRoot "htdocs"', - '', - f'', - f' ServerName {self.domain_a}', - ' DocumentRoot "htdocs/a.mod-tls.test"', - '', - f'', - f' ServerName {self.domain_b}', - ' DocumentRoot "htdocs/b.mod-tls.test"', - '', ]) self.add_cert_specs([ CertificateSpec(domains=[self.domain_a]), CertificateSpec(domains=[self.domain_b], key_type='secp256r1', single_file=True), CertificateSpec(domains=[self.domain_b], key_type='rsa4096'), + CertificateSpec(domains=['localhost'], key_type='rsa4096'), CertificateSpec(name="clientsX", sub_specs=[ CertificateSpec(name="user1", client=True, single_file=True), CertificateSpec(name="user2", client=True, single_file=True), diff --git a/test/modules/tls/test_09_timeout.py b/test/modules/tls/test_09_timeout.py index 70cc894..6c49192 100644 --- a/test/modules/tls/test_09_timeout.py +++ b/test/modules/tls/test_09_timeout.py @@ -24,7 +24,8 @@ def _function_scope(self, env): def test_tls_09_timeout_handshake(self, env): # in domain_b root, the StdEnvVars is switch on s = socket.create_connection(('localhost', env.https_port)) - s.send(b'1234') + # something that looks like a ClientHello + s.send(bytes.fromhex('3c37121e')) s.settimeout(0.0) try: s.recv(1024) diff --git a/test/modules/tls/test_13_proxy.py b/test/modules/tls/test_13_proxy.py index 42a1efb..6490c79 100644 --- a/test/modules/tls/test_13_proxy.py +++ b/test/modules/tls/test_13_proxy.py @@ -18,6 +18,8 @@ def _class_scope(self, env): ] }) # add vhosts a+b and a ssl proxy from a to b + conf.add_vhost('localhost', port=env.http_port) + conf.add_vhost(env.domain_b, port=env.http_port, doc_root=f"htdocs/{env.domain_b}") conf.add_tls_vhosts(domains=[env.domain_a, env.domain_b]) conf.install() assert env.apache_restart() == 0 diff --git a/test/modules/tls/test_18_ws.py b/test/modules/tls/test_18_ws.py new file mode 100644 index 0000000..16636e9 --- /dev/null +++ b/test/modules/tls/test_18_ws.py @@ -0,0 +1,212 @@ +import ssl +from datetime import datetime, timedelta +import inspect +import os +import shutil +import subprocess +import time + +import pytest +import websockets +from websockets.sync.client import connect + +from .conf import TlsTestConf + + +class WsServer: + + def __init__(self, name, env, port, creds=None): + self.name = name + self.env = env + self.process = None + self.cerr = None + self.port = port + self.creds = creds + self.run_dir = os.path.join(env.gen_dir, self.name) + self.err_file = os.path.join(self.run_dir, 'stderr') + self._rmrf(self.run_dir) + self._mkpath(self.run_dir) + + def start(self): + if not self.process: + self.cerr = open(self.err_file, 'w') + cmd = os.path.join(os.path.dirname(inspect.getfile(TestWebSockets)), + 'ws_server.py') + args = ['python3', cmd, '--port', str(self.port)] + if self.creds: + args.extend([ + '--cert', self.creds[0].cert_file, + '--key', self.creds[0].pkey_file, + ]) + self.process = subprocess.Popen(args=args, cwd=self.run_dir, + stderr=self.cerr, stdout=self.cerr) + if not self.check_alive(): + self.stop() + pytest.fail(f'ws_server did not start. stderr={open(self.err_file).readlines()}') + + def stop(self): + if self.process: + self.process.kill() + self.process.wait() + self.process = None + if self.cerr: + self.cerr.close() + self.cerr = None + + def check_alive(self, timeout=5): + if self.creds: + url = f'https://localhost:{self.port}/' + else: + url = f'http://localhost:{self.port}/' + end = datetime.now() + timedelta(seconds=timeout) + while datetime.now() < end: + r = self.env.curl_get(url, 5) + if r.exit_code == 0: + return True + time.sleep(.1) + return False + + def _mkpath(self, path): + if not os.path.exists(path): + return os.makedirs(path) + + def _rmrf(self, path): + if os.path.exists(path): + return shutil.rmtree(path) + + + +class TestWebSockets: + + @staticmethod + def mk_text_file(fpath: str, lines: int): + t110 = 11 * "0123456789" + with open(fpath, "w") as fd: + for i in range(lines): + fd.write("{0:015d}: ".format(i)) # total 128 bytes per line + fd.write(t110) + fd.write("\n") + + + @pytest.fixture(autouse=True, scope='class') + def _class_scope(self, env): + # Apache config that CONNECT proxies a WebSocket server for paths starting + # with '/ws/' + # The WebSocket server is started in pytest fixture 'ws_server' below. + conf = TlsTestConf(env, extras={ + 'base': [ + 'Timeout 1', + f'', + ' TLSProxyEngine on', + f' TLSProxyCA {env.ca.cert_file}', + ' ProxyPreserveHost on', + '', + ], + 'localhost': [ + f'ProxyPass /ws/ http://127.0.0.1:{env.ws_port}/ upgrade=websocket \\', + f'timeout=2 flushpackets=on', + f'ProxyPass /wss/ https://localhost:{env.wss_port}/ upgrade=websocket \\', + f'timeout=2 flushpackets=on', + ], + }) + conf.add_vhost('localhost', port=env.http_port) + conf.add_tls_vhosts(['localhost'], port=env.https_port) + conf.install() + TestWebSockets.mk_text_file(os.path.join(env.gen_dir, "1k.txt"), 8) + TestWebSockets.mk_text_file(os.path.join(env.gen_dir, "10k.txt"), 80) + TestWebSockets.mk_text_file(os.path.join(env.gen_dir, "100k.txt"), 800) + TestWebSockets.mk_text_file(os.path.join(env.gen_dir, "1m.txt"), 8000) + assert env.apache_restart() == 0 + + @pytest.fixture(autouse=True, scope='class') + def ws_server(self, env): + # Run our python websockets server that has some special behaviour + # for the different path to CONNECT to. + ws_server = WsServer('ws-server', env, port=env.ws_port) + ws_server.start() + yield ws_server + ws_server.stop() + + @pytest.fixture(autouse=True, scope='class') + def wss_server(self, env): + # Run our python websockets server that has some special behaviour + # for the different path to CONNECT to. + creds = env.get_credentials_for_name('localhost') + assert creds + ws_server = WsServer('wss-server', env, port=env.wss_port, creds=creds) + ws_server.start() + yield ws_server + ws_server.stop() + + def ssl_ctx(self, env): + ssl_ctx = ssl.SSLContext(protocol=ssl.PROTOCOL_TLS_CLIENT) + ssl_ctx.load_verify_locations(cafile=env.ca.cert_file) + return ssl_ctx + + def ws_recv_text(self, ws): + msg = "" + while True: + try: + msg += ws.recv() + except websockets.exceptions.ConnectionClosedOK: + return msg + + def ws_recv_bytes(self, ws): + msg = b'' + while True: + try: + msg += ws.recv() + except websockets.exceptions.ConnectionClosedOK: + return msg + + # verify the our plain websocket server works + def test_tls_18_01_ws_direct(self, env, ws_server): + with connect(f"ws://127.0.0.1:{env.ws_port}/echo") as ws: + message = "Hello world!" + ws.send(message) + response = self.ws_recv_text(ws) + assert response == message + + # verify that our secure websocket server works + def test_tls_18_02_wss_direct(self, env, wss_server): + pytest.skip(reason='For unknown reasons, this is flaky in CI') + with connect(f"wss://localhost:{env.wss_port}/echo", + ssl_context=self.ssl_ctx(env)) as ws: + message = "Hello world!" + ws.send(message) + response = self.ws_recv_text(ws) + assert response == message + + # verify to send plain websocket message pingpong through apache + def test_tls_18_03_http_ws(self, env, ws_server): + with connect(f"ws://localhost:{env.http_port}/ws/echo/") as ws: + message = "Hello world!" + ws.send(message) + response = self.ws_recv_text(ws) + assert response == message + + # verify to send secure websocket message pingpong through apache + def test_tls_18_04_http_wss(self, env, wss_server): + pytest.skip(reason='This fails, needing a fix like PR #9') + with connect(f"ws://localhost:{env.http_port}/wss/echo/") as ws: + message = "Hello world!" + ws.send(message) + response = self.ws_recv_text(ws) + assert response == message + + # verify that getting a large file works without any TLS involved + @pytest.mark.parametrize("fname", ["1m.txt"]) + def test_tls_18_05_http_ws_file(self, env, fname, ws_server): + expected = open(os.path.join(env.gen_dir, fname), 'rb').read() + with connect(f"ws://localhost:{env.http_port}/ws/file/{fname}") as ws: + response = self.ws_recv_bytes(ws) + assert response == expected + + # verify getting secure websocket from the http: server + # this is "backend" mod_tls work + @pytest.mark.parametrize("fname", ["1k.txt", "10k.txt", "100k.txt", "1m.txt"]) + def test_tls_18_06_http_wss_file(self, env, fname, ws_server): + expected = open(os.path.join(env.gen_dir, fname), 'rb').read() + with connect(f"ws://localhost:{env.http_port}/wss/file/{fname}") as ws: + response = self.ws_recv_bytes(ws) + assert response == expected diff --git a/test/modules/tls/ws_server.py b/test/modules/tls/ws_server.py new file mode 100755 index 0000000..8c2760c --- /dev/null +++ b/test/modules/tls/ws_server.py @@ -0,0 +1,113 @@ +#!/usr/bin/env python3 +import argparse +import asyncio +import logging +import os +import ssl +import sys +import time + +import websockets.server as ws_server +from websockets.exceptions import ConnectionClosedError + +log = logging.getLogger(__name__) + +logging.basicConfig( + format="[%(asctime)s] %(message)s", + level=logging.DEBUG, +) + + +async def echo(websocket): + try: + async for message in websocket: + try: + log.info(f'got request {message}') + except Exception as e: + log.error(f'error {e} getting path from {message}') + await websocket.send(message) + except ConnectionClosedError: + pass + + +async def on_async_conn(conn): + rpath = str(conn.path) + pcomps = rpath[1:].split('/') + if len(pcomps) == 0: + pcomps = ['echo'] # default handler + log.info(f'connection for {pcomps}') + if pcomps[0] == 'echo': + log.info(f'/echo endpoint') + for message in await conn.recv(): + await conn.send(message) + elif pcomps[0] == 'text': + await conn.send('hello!') + elif pcomps[0] == 'file': + if len(pcomps) < 2: + conn.close(code=4999, reason='unknown file') + return + fpath = os.path.join('../', pcomps[1]) + if not os.path.exists(fpath): + conn.close(code=4999, reason='file not found') + return + bufsize = 0 + if len(pcomps) > 2: + bufsize = int(pcomps[2]) + if bufsize <= 0: + bufsize = 16*1024 + delay_ms = 0 + if len(pcomps) > 3: + delay_ms = int(pcomps[3]) + n = 1 + if len(pcomps) > 4: + n = int(pcomps[4]) + for _ in range(n): + with open(fpath, 'r+b') as fd: + while True: + buf = fd.read(bufsize) + if buf is None or len(buf) == 0: + break + await conn.send(buf) + if delay_ms > 0: + time.sleep(delay_ms/1000) + else: + log.info(f'unknown endpoint: {rpath}') + await conn.close(code=4999, reason='path unknown') + await conn.close(code=1000, reason='') + + +async def run_server(port, cert, pkey): + log.info(f'starting server on port {port}, cert {cert}, key {pkey}') + ssl_ctx = None + if cert and pkey: + ssl_ctx = ssl.SSLContext(protocol=ssl.PROTOCOL_TLS_SERVER) + ssl_ctx.load_cert_chain(certfile=cert, keyfile=pkey) + async with ws_server.serve(ws_handler=on_async_conn, + host="localhost", port=port, ssl=ssl_ctx): + await asyncio.Future() + + +async def main(): + parser = argparse.ArgumentParser(prog='scorecard', + description="Run a websocket echo server.") + parser.add_argument("--port", type=int, + default=0, help="port to listen on") + parser.add_argument("--cert", type=str, + default=None, help="TLS certificate") + parser.add_argument("--key", type=str, + default=None, help="TLS private key") + args = parser.parse_args() + + if args.port == 0: + sys.stderr.write('need --port\n') + sys.exit(1) + + logging.basicConfig( + format="%(asctime)s %(message)s", + level=logging.DEBUG, + ) + await run_server(args.port, args.cert, args.key) + + +if __name__ == "__main__": + asyncio.run(main()) diff --git a/test/pyhttpd/config.ini.in b/test/pyhttpd/config.ini.in index 85c0cfa..582ce45 100644 --- a/test/pyhttpd/config.ini.in +++ b/test/pyhttpd/config.ini.in @@ -29,6 +29,7 @@ https_port = 5001 proxy_port = 5003 http_port2 = 5004 ws_port = 5100 +wss_port = 5101 http_tld = tests.httpd.apache.org test_dir = @abs_srcdir@ test_src_dir = @abs_srcdir@ diff --git a/test/pyhttpd/env.py b/test/pyhttpd/env.py index aacedb7..be20516 100644 --- a/test/pyhttpd/env.py +++ b/test/pyhttpd/env.py @@ -275,6 +275,7 @@ def __init__(self, pytestconfig=None): self._https_port = int(self.config.get('test', 'https_port')) self._proxy_port = int(self.config.get('test', 'proxy_port')) self._ws_port = int(self.config.get('test', 'ws_port')) + self._wss_port = int(self.config.get('test', 'wss_port')) self._http_tld = self.config.get('test', 'http_tld') self._test_dir = self.config.get('test', 'test_dir') self._clients_dir = os.path.join(os.path.dirname(self._test_dir), 'clients') @@ -312,6 +313,7 @@ def __init__(self, pytestconfig=None): f"test2.{self._http_tld}", f"test3.{self._http_tld}", f"cgi.{self._http_tld}", + "localhost", ], key_type='rsa4096')] self._verify_certs = False @@ -403,6 +405,10 @@ def proxy_port(self) -> int: def ws_port(self) -> int: return self._ws_port + @property + def wss_port(self) -> int: + return self._wss_port + @property def http_tld(self) -> str: return self._http_tld diff --git a/test/requirements.txt b/test/requirements.txt index 92e69fe..f6cb4d2 100644 --- a/test/requirements.txt +++ b/test/requirements.txt @@ -19,3 +19,4 @@ filelock python-multipart psutil tqdm +websockets