diff --git a/changes-entries/apxs-i-wo-n.txt b/changes-entries/apxs-i-wo-n.txt new file mode 100644 index 00000000000..8adcfa1afb1 --- /dev/null +++ b/changes-entries/apxs-i-wo-n.txt @@ -0,0 +1,2 @@ + *) apxs: Fix -i in some cases where -n is not used. + [Jan Pazdziora ] diff --git a/docs/conf/mime.types b/docs/conf/mime.types index 870176f77de..2957b67d25e 100644 --- a/docs/conf/mime.types +++ b/docs/conf/mime.types @@ -585,6 +585,7 @@ application/vnd.genomatix.tuxedo txd # application/vnd.geo+json # application/vnd.geocube+xml application/vnd.geogebra.file ggb +application/vnd.geogebra.slides ggs application/vnd.geogebra.tool ggt application/vnd.geometry-explorer gex gre application/vnd.geonext gxt @@ -1212,6 +1213,7 @@ application/vnd.zul zir zirz application/vnd.zzazz.deck+xml zaz application/voicexml+xml vxml # application/vq-rtcpxr +application/wasm wasm # application/watcherinfo+xml # application/whoispp-query # application/whoispp-response diff --git a/modules/mappers/mod_rewrite.c b/modules/mappers/mod_rewrite.c index 1e97d8b75d4..0676804695c 100644 --- a/modules/mappers/mod_rewrite.c +++ b/modules/mappers/mod_rewrite.c @@ -4831,8 +4831,8 @@ static int hook_uri2file(request_rec *r) } if (rulestatus) { - unsigned skip_absolute = is_absolute_uri(r->filename, NULL); apr_size_t flen = r->filename ? strlen(r->filename) : 0; + unsigned skip_absolute = flen ? is_absolute_uri(r->filename, NULL) : 0; int to_proxyreq = (flen > 6 && strncmp(r->filename, "proxy:", 6) == 0); int will_escape = skip_absolute && (rulestatus != ACTION_NOESCAPE); diff --git a/server/util_filter.c b/server/util_filter.c index 8c278293cf1..3b1e96fb447 100644 --- a/server/util_filter.c +++ b/server/util_filter.c @@ -949,12 +949,14 @@ AP_DECLARE(apr_status_t) ap_filter_setaside_brigade(ap_filter_t *f, apr_status_t rv = APR_SUCCESS; struct ap_filter_private *fp = f->priv; - ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, - "setaside %s brigade to %s brigade in '%s' %sput filter", - APR_BRIGADE_EMPTY(bb) ? "empty" : "full", - (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : "full", - f->frec->name, - f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); + if (!APR_BRIGADE_EMPTY(bb) || (fp->bb && !APR_BRIGADE_EMPTY(fp->bb))) { + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, + "setaside %s brigade to %s brigade in '%s' %sput filter", + APR_BRIGADE_EMPTY(bb) ? "empty" : "full", + (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : "full", + f->frec->name, + f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); + } /* This API is not suitable for request filters */ if (f->frec->ftype < AP_FTYPE_CONNECTION) { @@ -1049,12 +1051,14 @@ AP_DECLARE(void) ap_filter_adopt_brigade(ap_filter_t *f, { struct ap_filter_private *fp = f->priv; - ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, - "adopt %s brigade to %s brigade in '%s' %sput filter", - APR_BRIGADE_EMPTY(bb) ? "empty" : "full", - (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : "full", - f->frec->name, - f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); + if (!APR_BRIGADE_EMPTY(bb) || (fp->bb && !APR_BRIGADE_EMPTY(fp->bb))) { + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, + "adopt %s brigade to %s brigade in '%s' %sput filter", + APR_BRIGADE_EMPTY(bb) ? "empty" : "full", + (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : "full", + f->frec->name, + f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); + } if (!APR_BRIGADE_EMPTY(bb)) { ap_filter_prepare_brigade(f); @@ -1067,18 +1071,26 @@ AP_DECLARE(apr_status_t) ap_filter_reinstate_brigade(ap_filter_t *f, apr_bucket **flush_upto) { apr_bucket *bucket, *next; + apr_size_t flush_max_threshold; + apr_int32_t flush_max_pipelined; apr_size_t bytes_in_brigade, memory_bytes_in_brigade; int eor_buckets_in_brigade, opaque_buckets_in_brigade; struct ap_filter_private *fp = f->priv; core_server_config *conf; int is_flush; - ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, - "reinstate %s brigade to %s brigade in '%s' %sput filter", - (!fp->bb || APR_BRIGADE_EMPTY(fp->bb) ? "empty" : "full"), - (APR_BRIGADE_EMPTY(bb) ? "empty" : "full"), - f->frec->name, - f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); + if (flush_upto) { + *flush_upto = NULL; + } + + if (!APR_BRIGADE_EMPTY(bb) || (fp->bb && !APR_BRIGADE_EMPTY(fp->bb))) { + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, + "reinstate %s brigade to %s brigade in '%s' %sput filter", + (!fp->bb || APR_BRIGADE_EMPTY(fp->bb) ? "empty" : "full"), + (APR_BRIGADE_EMPTY(bb) ? "empty" : "full"), + f->frec->name, + f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); + } /* This API is not suitable for request filters */ if (f->frec->ftype < AP_FTYPE_CONNECTION) { @@ -1086,17 +1098,15 @@ AP_DECLARE(apr_status_t) ap_filter_reinstate_brigade(ap_filter_t *f, } /* Buckets in fp->bb are leftover from previous call to setaside, so - * they happen before anything added here in bb. + * they happen before anything in bb already. */ if (fp->bb) { APR_BRIGADE_PREPEND(bb, fp->bb); } - if (!flush_upto) { - /* Just prepend all. */ + if (!flush_upto || APR_BRIGADE_EMPTY(bb)) { + /* Just prepend all, or nothing to do. */ return APR_SUCCESS; } - - *flush_upto = NULL; /* * Determine if and up to which bucket the caller needs to do a blocking @@ -1124,13 +1134,15 @@ AP_DECLARE(apr_status_t) ap_filter_reinstate_brigade(ap_filter_t *f, * reinstated by moving them from/to fp->bb to/from user bb. */ + conf = ap_get_core_module_config(f->c->base_server->module_config); + flush_max_threshold = conf->flush_max_threshold; + flush_max_pipelined = conf->flush_max_pipelined; + bytes_in_brigade = 0; memory_bytes_in_brigade = 0; eor_buckets_in_brigade = 0; opaque_buckets_in_brigade = 0; - conf = ap_get_core_module_config(f->c->base_server->module_config); - for (bucket = APR_BRIGADE_FIRST(bb); bucket != APR_BRIGADE_SENTINEL(bb); bucket = next) { next = APR_BUCKET_NEXT(bucket); @@ -1157,9 +1169,9 @@ AP_DECLARE(apr_status_t) ap_filter_reinstate_brigade(ap_filter_t *f, } if (is_flush - || (memory_bytes_in_brigade > conf->flush_max_threshold) - || (conf->flush_max_pipelined >= 0 - && eor_buckets_in_brigade > conf->flush_max_pipelined)) { + || (memory_bytes_in_brigade > flush_max_threshold) + || (flush_max_pipelined >= 0 + && eor_buckets_in_brigade > flush_max_pipelined)) { /* this segment of the brigade MUST be sent before returning. */ if (APLOGctrace6(f->c)) { @@ -1170,11 +1182,9 @@ AP_DECLARE(apr_status_t) ap_filter_reinstate_brigade(ap_filter_t *f, ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, "will flush because of %s", reason); ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, f->c, - "seen in brigade%s: bytes: %" APR_SIZE_T_FMT + "seen in brigade so far: bytes: %" APR_SIZE_T_FMT ", memory bytes: %" APR_SIZE_T_FMT ", eor " "buckets: %d, opaque buckets: %d", - *flush_upto == NULL ? " so far" - : " since last flush point", bytes_in_brigade, memory_bytes_in_brigade, eor_buckets_in_brigade, @@ -1183,16 +1193,18 @@ AP_DECLARE(apr_status_t) ap_filter_reinstate_brigade(ap_filter_t *f, /* * Defer the actual blocking write to avoid doing many writes. */ + if (memory_bytes_in_brigade > flush_max_threshold) { + flush_max_threshold = APR_SIZE_MAX; + } + if (flush_max_pipelined >= 0 + && eor_buckets_in_brigade > flush_max_pipelined) { + flush_max_pipelined = APR_INT32_MAX; + } *flush_upto = next; - - bytes_in_brigade = 0; - memory_bytes_in_brigade = 0; - eor_buckets_in_brigade = 0; - opaque_buckets_in_brigade = 0; } } - ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, f->c, + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, "brigade contains%s: bytes: %" APR_SIZE_T_FMT ", non-file bytes: %" APR_SIZE_T_FMT ", eor buckets: %d, opaque buckets: %d", diff --git a/support/ab.c b/support/ab.c index 01aee882539..318eea6d21e 100644 --- a/support/ab.c +++ b/support/ab.c @@ -176,6 +176,7 @@ #if APR_HAVE_LIMITS_H #include #endif +#include #if defined(HAVE_OPENSSL) @@ -248,10 +249,12 @@ typedef STACK_OF(X509) X509_STACK_TYPE; /* ------------------- DEFINITIONS -------------------------- */ -#ifndef LLONG_MAX -#define AB_MAX APR_INT64_C(0x7fffffffffffffff) +#if defined(APR_INT64_MAX) +#define AB_TIME_MAX APR_INT64_MAX +#elif defined(LLONG_MAX) +#define AB_TIME_MAX LLONG_MAX #else -#define AB_MAX LLONG_MAX +#define AB_TIME_MAX APR_INT64_C(0x7fffffffffffffff) #endif /* default number of requests on a time limited test */ @@ -357,6 +360,8 @@ struct worker { int slot; int requests; int concurrency; + int polled; + int bind_rr; /* next address to bind (round robin) */ int succeeded_once; /* response header received once */ apr_int64_t started; /* number of requests started, so no excess */ @@ -412,7 +417,9 @@ apr_port_t port; /* port number */ char *proxyhost = NULL; /* proxy host name */ int proxyport = 0; /* proxy port */ const char *connecthost; -const char *myhost; +int bind_count = 0; +const char **bind_hosts; +apr_sockaddr_t **bind_addrs; apr_port_t connectport; const char *gnuplot; /* GNUplot file */ const char *csvperc; /* CSV Percentile file */ @@ -465,7 +472,6 @@ struct connection *conns; /* connection array */ struct data *stats; /* data for each request */ apr_pool_t *cntxt; -apr_sockaddr_t *mysa; apr_sockaddr_t *destsa; #ifdef NOT_ASCII @@ -477,14 +483,14 @@ static apr_thread_mutex_t *workers_mutex; static apr_thread_cond_t *workers_can_start; #endif -static APR_INLINE int worker_should_stop(struct worker *worker) +static APR_INLINE int worker_can_stop(struct worker *worker) { - return (lasttime >= stoptime + return (stoptime <= lasttime || (rlimited && worker->metrics.done >= worker->requests)); } -static APR_INLINE int worker_can_start_connection(struct worker *worker) +static APR_INLINE int worker_can_connect(struct worker *worker) { - return !(worker_should_stop(worker) + return !(stoptime <= lasttime || (rlimited && worker->started >= worker->requests)); } @@ -617,7 +623,9 @@ static int set_polled_events(struct connection *c, apr_int16_t new_reqevents) graceful_strerror("apr_pollset_remove()", rv); return 0; } - } + assert(c->worker->polled > 0); + c->worker->polled--; + } c->pollfd.reqevents = new_reqevents; if (new_reqevents != 0) { @@ -626,6 +634,7 @@ static int set_polled_events(struct connection *c, apr_int16_t new_reqevents) graceful_strerror("apr_pollset_add()", rv); return 0; } + c->worker->polled++; } } return 1; @@ -809,7 +818,7 @@ static void ssl_print_info(struct connection *c) for (i=1; issl); if (cert == NULL) { @@ -858,6 +867,7 @@ static void ssl_proceed_handshake(struct connection *c) SSL_get_version(c->ssl), SSL_CIPHER_get_name(ci), pk_bits, sk_bits); + if (cert) X509_free(cert); } #if OPENSSL_VERSION_NUMBER >= 0x10002000L if (!worker->metrics.ssl_tmp_key[0] && !worker->metrics.ssl_tmp_key[1]) { @@ -1223,8 +1233,8 @@ static void output_results(void) apr_int64_t i, count = ap_min(metrics.done, requests); apr_time_t totalcon = 0, total = 0, totald = 0, totalwait = 0; apr_time_t meancon, meantot, meand, meanwait; - apr_interval_time_t mincon = AB_MAX, mintot = AB_MAX, mind = AB_MAX, - minwait = AB_MAX; + apr_interval_time_t mincon = AB_TIME_MAX, mintot = AB_TIME_MAX, + mind = AB_TIME_MAX, minwait = AB_TIME_MAX; apr_interval_time_t maxcon = 0, maxtot = 0, maxd = 0, maxwait = 0; apr_interval_time_t mediancon = 0, mediantot = 0, mediand = 0, medianwait = 0; double sdtot = 0, sdcon = 0, sdd = 0, sdwait = 0; @@ -1522,7 +1532,7 @@ static void output_html_results(void) /* work out connection times */ apr_int64_t i, count = ap_min(metrics.done, requests); apr_interval_time_t totalcon = 0, total = 0; - apr_interval_time_t mincon = AB_MAX, mintot = AB_MAX; + apr_interval_time_t mincon = AB_TIME_MAX, mintot = AB_TIME_MAX; apr_interval_time_t maxcon = 0, maxtot = 0; for (i = 0; i < count; i++) { @@ -1580,7 +1590,7 @@ static void start_connection(struct connection * c) struct worker *worker = c->worker; apr_status_t rv; - if (!worker_can_start_connection(worker)) { + if (!worker_can_connect(worker)) { return; } @@ -1602,8 +1612,11 @@ static void start_connection(struct connection * c) c->pollfd.reqevents = c->pollfd.rtnevents = 0; c->pollfd.client_data = c; - if (myhost) { - if ((rv = apr_socket_bind(c->aprsock, mysa)) != APR_SUCCESS) { + if (bind_count) { + if (worker->bind_rr >= bind_count) { + worker->bind_rr = 0; + } + if ((rv = apr_socket_bind(c->aprsock, bind_addrs[worker->bind_rr++]))) { graceful_strerror("bind", rv); close_connection(c); return; @@ -1757,6 +1770,7 @@ static void finalize_connection(struct connection *c, int reuse) { struct worker *worker = c->worker; int good = (c->gotheader && c->bread >= c->length); + int final_state = c->state; /* close before measuring, to account for shutdown time */ if (!reuse || !good) { @@ -1771,12 +1785,15 @@ static void finalize_connection(struct connection *c, int reuse) */ worker->metrics.doneka--; worker->metrics.aborted_ka++; + if (final_state > STATE_WRITE) { + worker->started--; + } } else { /* save out time */ if (tlimit || worker->metrics.done < worker->requests) { apr_time_t tnow = lasttime = c->end = apr_time_now(); - struct data *s = &worker->stats[worker->metrics.done++ % worker->requests]; + struct data *s = &worker->stats[worker->metrics.done % worker->requests]; /* Cumulative for when worker->metrics.done > worker->requests (tlimit), * consolidate_metrics() will do the mean. @@ -1838,6 +1855,7 @@ static void finalize_connection(struct connection *c, int reuse) } } } + worker->metrics.done++; /* update worker's metrics */ if (good) { @@ -1857,9 +1875,9 @@ static void finalize_connection(struct connection *c, int reuse) } if (!reuse) { - start_connection(c); /* nop if !worker_can_start_connection() */ + start_connection(c); /* nop if !worker_can_connect() */ } - else if (worker_can_start_connection(worker)) { + else if (worker_can_connect(worker)) { c->keptalive++; worker->metrics.doneka++; @@ -2301,19 +2319,23 @@ static int test(void) } #endif /* NOT_ASCII */ - if (myhost) { + if (bind_count) { /* This only needs to be done once */ - if ((rv = apr_sockaddr_info_get(&mysa, myhost, APR_UNSPEC, 0, 0, cntxt))) { - char buf[120]; - apr_snprintf(buf, sizeof(buf), - "apr_sockaddr_info_get() for %s", myhost); - fatal_strerror(buf, rv); + bind_addrs = apr_pcalloc(cntxt, bind_count * sizeof(apr_sockaddr_t*)); + for (i = 0; i < bind_count; ++i) { + if ((rv = apr_sockaddr_info_get(&bind_addrs[i], bind_hosts[i], + APR_UNSPEC, 0, 0, cntxt))) { + char buf[120]; + apr_snprintf(buf, sizeof(buf), + "apr_sockaddr_info_get() for %s", bind_hosts[i]); + fatal_strerror(buf, rv); + } } } /* This too */ if ((rv = apr_sockaddr_info_get(&destsa, connecthost, - myhost ? mysa->family : APR_UNSPEC, + bind_count ? bind_addrs[0]->family : APR_UNSPEC, connectport, 0, cntxt))) { char buf[120]; apr_snprintf(buf, sizeof(buf), @@ -2378,7 +2400,7 @@ static int test(void) /* ok - lets start */ start = lasttime = apr_time_now(); - stoptime = tlimit ? (start + apr_time_from_sec(tlimit)) : AB_MAX; + stoptime = tlimit ? start + apr_time_from_sec(tlimit) : AB_TIME_MAX; #if APR_HAS_THREADS if (num_workers > 1) { @@ -2434,20 +2456,24 @@ static void worker_test(struct worker *worker) apr_int32_t n; const apr_pollfd_t *pollresults, *pollfd; apr_interval_time_t t = aprtimeout; - apr_time_t now = apr_time_now(); - - while (!APR_RING_EMPTY(&worker->delayed_ring, connection, delay_list)) { - c = APR_RING_FIRST(&worker->delayed_ring); - if (c->delay <= now) { - APR_RING_REMOVE(c, delay_list); - APR_RING_ELEM_INIT(c, delay_list); - c->delay = 0; - start_connection(c); - } - else { - t = c->delay - now; - break; - } + + if (!APR_RING_EMPTY(&worker->delayed_ring, connection, delay_list)) { + apr_time_t now = apr_time_now(); + do { + c = APR_RING_FIRST(&worker->delayed_ring); + if (c->delay <= now) { + APR_RING_REMOVE(c, delay_list); + APR_RING_ELEM_INIT(c, delay_list); + c->delay = 0; + start_connection(c); + } + else { + if (t > c->delay - now) { + t = c->delay - now; + } + break; + } + } while (!APR_RING_EMPTY(&worker->delayed_ring, connection, delay_list)); } n = worker->metrics.concurrent; @@ -2560,7 +2586,9 @@ static void worker_test(struct worker *worker) continue; } } - } while (!worker_should_stop(worker)); + } while (worker->polled > 0 && stoptime > lasttime); + + assert(worker_can_stop(worker)); } #if APR_HAS_THREADS @@ -2628,9 +2656,9 @@ static void workers_may_exit(int unused) { (void)unused; - test_aborted = -1; - lasttime = apr_time_now(); /* record final time if interrupted */ stoptime = 0; /* everyone stop now! */ + lasttime = apr_time_now(); /* record final time if interrupted */ + test_aborted = -1; #ifdef APR_POLLSET_WAKEABLE /* wake up poll()ing workers */ @@ -2686,7 +2714,7 @@ static void usage(const char *progname) fprintf(stderr, " -R rampdelay Milliseconds in between each new connection when starting up\n"); fprintf(stderr, " Default is no delay\n"); fprintf(stderr, " -b windowsize Size of TCP send/receive buffer, in bytes\n"); - fprintf(stderr, " -B address Address to bind to when making outgoing connections\n"); + fprintf(stderr, " -B addr[,addr]* Address[es] to bind to when making outgoing connections\n"); fprintf(stderr, " -p postfile File containing data to POST. Remember also to set -T\n"); fprintf(stderr, " -u putfile File containing data to PUT. Remember also to set -T\n"); fprintf(stderr, " -T content-type Content-type header to use for POST/PUT data, eg.\n"); @@ -2944,8 +2972,6 @@ int main(int argc, const char * const argv[]) } #endif - myhost = NULL; /* 0.0.0.0 or :: */ - apr_getopt_init(&opt, cntxt, argc, argv); while ((status = apr_getopt(opt, "n:c:t:s:b:T:p:u:v:lrkVhwiIx:y:z:C:H:P:A:g:X:de:SqQB:m:R:" #if APR_HAS_THREADS @@ -3141,7 +3167,30 @@ int main(int argc, const char * const argv[]) copyright(); return 0; case 'B': - myhost = apr_pstrdup(cntxt, opt_arg); + { + const char *ptr, *end; + + bind_count = 1; + for (ptr = opt_arg; (end = strchr(ptr, ',')); ptr = end + 1) { + bind_count++; + } + bind_hosts = apr_palloc(cntxt, bind_count * sizeof(char*)); + + bind_count = 0; + for (ptr = opt_arg; (end = strchr(ptr, ',')); ptr = end + 1) { + if (end > ptr) { + bind_hosts[bind_count++] = apr_pstrmemdup(cntxt, ptr, end - ptr); + } + } + if (*ptr) { + bind_hosts[bind_count++] = apr_pstrdup(cntxt, ptr); + } + + if (!bind_count) { + fprintf(stderr, "%s: Invalid bind address[es]\n", argv[0]); + usage(argv[0]); + } + } break; case 'm': method = CUSTOM_METHOD; @@ -3311,7 +3360,7 @@ int main(int argc, const char * const argv[]) exit(1); } #endif - + if (!(ssl_ctx = SSL_CTX_new(meth))) { BIO_printf(bio_err, "Could not initialize SSL Context.\n"); ERR_print_errors(bio_err); diff --git a/support/apxs.in b/support/apxs.in index 65e1288527d..4a990625779 100644 --- a/support/apxs.in +++ b/support/apxs.in @@ -538,7 +538,7 @@ if ($opt_i or $opt_e) { } } if ($name eq '') { - if ($base =~ m|.*mod_([a-zA-Z0-9_]+)\..+|) { + if ($base =~ m/.*mod_([a-zA-Z0-9_]+)(\..+|$)/) { $name = "$1"; $filename = $base; $filename =~ s|^[^/]+/||; diff --git a/test/conftest.py b/test/conftest.py index 2ae35f34ed9..ac0a7c553d8 100644 --- a/test/conftest.py +++ b/test/conftest.py @@ -23,9 +23,25 @@ def pytest_generate_tests(metafunc): metafunc.fixturenames.append('tmp_ct') metafunc.parametrize('repeat', range(count)) + @pytest.fixture(autouse=True, scope="function") def _function_scope(env, request): env.set_current_test_name(request.node.name) yield + env.check_error_log() env.set_current_test_name(None) + +@pytest.fixture(autouse=True, scope="module") +def _module_scope(env): + yield + env.check_error_log() + + +@pytest.fixture(autouse=True, scope="package") +def _package_scope(env): + env.httpd_error_log.clear_ignored_matches() + env.httpd_error_log.clear_ignored_lognos() + yield + assert env.apache_stop() == 0 + env.check_error_log() diff --git a/test/modules/core/conftest.py b/test/modules/core/conftest.py index cf670bbea18..22906efbb04 100644 --- a/test/modules/core/conftest.py +++ b/test/modules/core/conftest.py @@ -28,18 +28,3 @@ def env(pytestconfig) -> CoreTestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - env.httpd_error_log.set_ignored_lognos([ - 'AH10244', # core: invalid URI path - 'AH01264', # mod_cgid script not found - ]) - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - diff --git a/test/modules/core/test_001_encoding.py b/test/modules/core/test_001_encoding.py index b7ffbaa8429..a3b24d04710 100644 --- a/test/modules/core/test_001_encoding.py +++ b/test/modules/core/test_001_encoding.py @@ -1,12 +1,11 @@ import pytest +from typing import List, Optional from pyhttpd.conf import HttpdConf class TestEncoding: - EXP_AH10244_ERRS = 0 - @pytest.fixture(autouse=True, scope='class') def _class_scope(self, env): conf = HttpdConf(env, extras={ @@ -57,29 +56,29 @@ def test_core_001_03(self, env, path): assert r.response["status"] == 200 # check path traversals - @pytest.mark.parametrize(["path", "status"], [ - ["/../echo.py", 400], - ["/nothing/../../echo.py", 400], - ["/cgi-bin/../../echo.py", 400], - ["/nothing/%2e%2e/%2e%2e/echo.py", 400], - ["/cgi-bin/%2e%2e/%2e%2e/echo.py", 400], - ["/nothing/%%32%65%%32%65/echo.py", 400], - ["/cgi-bin/%%32%65%%32%65/echo.py", 400], - ["/nothing/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400], - ["/cgi-bin/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400], - ["/nothing/%25%32%65%25%32%65/echo.py", 404], - ["/cgi-bin/%25%32%65%25%32%65/echo.py", 404], - ["/nothing/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404], - ["/cgi-bin/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404], + @pytest.mark.parametrize(["path", "status", "lognos"], [ + ["/../echo.py", 400, ["AH10244"]], + ["/nothing/../../echo.py", 400, ["AH10244"]], + ["/cgi-bin/../../echo.py", 400, ["AH10244"]], + ["/nothing/%2e%2e/%2e%2e/echo.py", 400, ["AH10244"]], + ["/cgi-bin/%2e%2e/%2e%2e/echo.py", 400, ["AH10244"]], + ["/nothing/%%32%65%%32%65/echo.py", 400, ["AH10244"]], + ["/cgi-bin/%%32%65%%32%65/echo.py", 400, ["AH10244"]], + ["/nothing/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400, ["AH10244"]], + ["/cgi-bin/%%32%65%%32%65/%%32%65%%32%65/h2_env.py", 400, ["AH10244"]], + ["/nothing/%25%32%65%25%32%65/echo.py", 404, ["AH01264"]], + ["/cgi-bin/%25%32%65%25%32%65/echo.py", 404, ["AH01264"]], + ["/nothing/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404, ["AH01264"]], + ["/cgi-bin/%25%32%65%25%32%65/%25%32%65%25%32%65/h2_env.py", 404, ["AH01264"]], ]) - def test_core_001_04(self, env, path, status): + def test_core_001_04(self, env, path, status, lognos: Optional[List[str]]): url = env.mkurl("https", "test1", path) r = env.curl_get(url) assert r.response["status"] == status - if status == 400: - TestEncoding.EXP_AH10244_ERRS += 1 - # the log will have a core:err about invalid URI path - + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) + # check handling of %2f url encodings that are not decoded by default @pytest.mark.parametrize(["host", "path", "status"], [ ["test1", "/006%2f006.css", 404], diff --git a/test/modules/http1/conftest.py b/test/modules/http1/conftest.py index 0ebb4391298..33a16a11704 100644 --- a/test/modules/http1/conftest.py +++ b/test/modules/http1/conftest.py @@ -34,14 +34,3 @@ def env(pytestconfig) -> H1TestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - diff --git a/test/modules/http1/env.py b/test/modules/http1/env.py index 5e395f31a8d..e2df1a561f2 100644 --- a/test/modules/http1/env.py +++ b/test/modules/http1/env.py @@ -1,7 +1,6 @@ import inspect import logging import os -import re import subprocess from typing import Dict, Any @@ -61,13 +60,6 @@ def __init__(self, pytestconfig=None): super().__init__(pytestconfig=pytestconfig) self.add_httpd_log_modules(["http", "core"]) - self.httpd_error_log.set_ignored_lognos([ - 'AH00135', # unsafe/strict tests send invalid methods - 'AH02430', # test of invalid chars in response headers - ]) - self.httpd_error_log.add_ignored_patterns([ - ]) - def setup_httpd(self, setup: HttpdTestSetup = None): super().setup_httpd(setup=H1TestSetup(env=self)) diff --git a/test/modules/http1/test_003_get.py b/test/modules/http1/test_003_get.py index 21fd4ef5bf6..1cd5917de62 100644 --- a/test/modules/http1/test_003_get.py +++ b/test/modules/http1/test_003_get.py @@ -1,4 +1,3 @@ -import re import socket import pytest diff --git a/test/modules/http1/test_004_post.py b/test/modules/http1/test_004_post.py index d4d5edcbf58..005a8c2fbcf 100644 --- a/test/modules/http1/test_004_post.py +++ b/test/modules/http1/test_004_post.py @@ -3,7 +3,6 @@ import inspect import json import os -import re import sys import pytest diff --git a/test/modules/http1/test_006_unsafe.py b/test/modules/http1/test_006_unsafe.py index b6882292c2f..eb832175139 100644 --- a/test/modules/http1/test_006_unsafe.py +++ b/test/modules/http1/test_006_unsafe.py @@ -1,6 +1,6 @@ import re import socket -from typing import Optional +from typing import List, Optional import pytest @@ -23,88 +23,88 @@ def _class_scope(self, env): # 1: any HTTP success # 200-500: specific HTTP status code # None: HTTPD should drop connection without error message - @pytest.mark.parametrize(["intext", "status"], [ - ["GET / HTTP/1.0\r\n\r\n", 1], - ["GET / HTTP/1.0\n\n", 1], - ["get / HTTP/1.0\r\n\r\n", 501], - ["G ET / HTTP/1.0\r\n\r\n", 400], - ["G\0ET / HTTP/1.0\r\n\r\n", 400], - ["G/T / HTTP/1.0\r\n\r\n", 501], - ["GET /\0 HTTP/1.0\r\n\r\n", 400], - ["GET / HTTP/1.0\0\r\n\r\n", 400], - ["GET\f/ HTTP/1.0\r\n\r\n", 400], - ["GET\r/ HTTP/1.0\r\n\r\n", 400], - ["GET\t/ HTTP/1.0\r\n\r\n", 400], - ["GET / HTT/1.0\r\n\r\n", 0], - ["GET / HTTP/1.0\r\nHost: localhost\r\n\r\n", 1], - ["GET / HTTP/2.0\r\nHost: localhost\r\n\r\n", 1], - ["GET / HTTP/1.2\r\nHost: localhost\r\n\r\n", 1], - ["GET / HTTP/1.11\r\nHost: localhost\r\n\r\n", 400], - ["GET / HTTP/10.0\r\nHost: localhost\r\n\r\n", 400], - ["GET / HTTP/1.0 \r\nHost: localhost\r\n\r\n", 200], - ["GET / HTTP/1.0 x\r\nHost: localhost\r\n\r\n", 400], - ["GET / HTTP/\r\nHost: localhost\r\n\r\n", 0], - ["GET / HTTP/0.9\r\n\r\n", 0], - ["GET / HTTP/0.8\r\n\r\n", 0], - ["GET /\x01 HTTP/1.0\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo:bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo: b\0ar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo: b\x01ar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\n: bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nX: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFoo bar:bash\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFoo :bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\n Foo:bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nF\x01o: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nF\ro: bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nF\to: bar\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nFo: b\tar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nFo: bar\r\r\n\r\n", 400], - ["GET / HTTP/1.0\r\r", None], - ["GET /\r\n", 90], - ["GET /#frag HTTP/1.0\r\n", 400], - ["GET / HTTP/1.0\r\nHost: localhost\r\nHost: localhost\r\n\r\n", 200], - ["GET http://017700000001/ HTTP/1.0\r\n\r\n", 200], - ["GET http://0x7f.1/ HTTP/1.0\r\n\r\n", 200], - ["GET http://127.0.0.1/ HTTP/1.0\r\n\r\n", 200], - ["GET http://127.01.0.1/ HTTP/1.0\r\n\r\n", 200], - ["GET http://%3127.0.0.1/ HTTP/1.0\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: localhost:80\r\nHost: localhost:80\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: localhost:80 x\r\n\r", 400], - ["GET http://localhost:80/ HTTP/1.0\r\n\r\n", 200], - ["GET http://localhost:80x/ HTTP/1.0\r\n\r\n", 400], - ["GET http://localhost:80:80/ HTTP/1.0\r\n\r\n", 400], - ["GET http://localhost::80/ HTTP/1.0\r\n\r\n", 400], - ["GET http://foo@localhost:80/ HTTP/1.0\r\n\r\n", 200], - ["GET http://[::1]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[::1:2]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd:1]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd::]/ HTTP/1.0\r\n\r\n", 400], - ["GET http://[4712:abcd::]/ HTTP/1.0\r\n\r\n", 1], - ["GET http://[4712::abcd]:8000/ HTTP/1.0\r\n\r\n", 1], - ["GET http://4713::abcd:8001/ HTTP/1.0\r\n\r\n", 400], - ["GET / HTTP/1.0\r\nHost: [::1]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [::1:2]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711::abcd]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711::abcd:1]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711:abcd::]\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: [4711::abcd]:8000\r\n\r\n", 1], - ["GET / HTTP/1.0\r\nHost: 4714::abcd:8001\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: abc\xa0\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: abc\\foo\r\n\r\n", 400], - ["GET http://foo/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET http://foo:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET http://[::1]:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET http://10.0.0.1:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: foo-bar.example.com\r\n\r\n", 200], - ["GET / HTTP/1.0\r\nHost: foo_bar.example.com\r\n\r\n", 200], - ["GET http://foo_bar/ HTTP/1.0\r\n\r\n", 200], + @pytest.mark.parametrize(["intext", "status", "lognos"], [ + ["GET / HTTP/1.0\r\n\r\n", 1, None], + ["GET / HTTP/1.0\n\n", 1, None], + ["get / HTTP/1.0\r\n\r\n", 501, ["AH00135"]], + ["G ET / HTTP/1.0\r\n\r\n", 400, None], + ["G\0ET / HTTP/1.0\r\n\r\n", 400, None], + ["G/T / HTTP/1.0\r\n\r\n", 501, ["AH00135"]], + ["GET /\0 HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTTP/1.0\0\r\n\r\n", 400, None], + ["GET\f/ HTTP/1.0\r\n\r\n", 400, None], + ["GET\r/ HTTP/1.0\r\n\r\n", 400, None], + ["GET\t/ HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTT/1.0\r\n\r\n", 0, None], + ["GET / HTTP/1.0\r\nHost: localhost\r\n\r\n", 1, None], + ["GET / HTTP/2.0\r\nHost: localhost\r\n\r\n", 1, None], + ["GET / HTTP/1.2\r\nHost: localhost\r\n\r\n", 1, None], + ["GET / HTTP/1.11\r\nHost: localhost\r\n\r\n", 400, None], + ["GET / HTTP/10.0\r\nHost: localhost\r\n\r\n", 400, None], + ["GET / HTTP/1.0 \r\nHost: localhost\r\n\r\n", 200, None], + ["GET / HTTP/1.0 x\r\nHost: localhost\r\n\r\n", 400, None], + ["GET / HTTP/\r\nHost: localhost\r\n\r\n", 0, None], + ["GET / HTTP/0.9\r\n\r\n", 0, None], + ["GET / HTTP/0.8\r\n\r\n", 0, None], + ["GET /\x01 HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo:bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo: b\0ar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo: b\x01ar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\n: bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nX: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFoo bar:bash\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFoo :bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\n Foo:bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nF\x01o: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nF\ro: bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nF\to: bar\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nFo: b\tar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nFo: bar\r\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\r", None, None], + ["GET /\r\n", 0, None], + ["GET /#frag HTTP/1.0\r\n", 400, None], + ["GET / HTTP/1.0\r\nHost: localhost\r\nHost: localhost\r\n\r\n", 200, None], + ["GET http://017700000001/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://0x7f.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://127.0.0.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://127.01.0.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://%3127.0.0.1/ HTTP/1.0\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: localhost:80\r\nHost: localhost:80\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: localhost:80 x\r\n\r", 400, None], + ["GET http://localhost:80/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://localhost:80x/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://localhost:80:80/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://localhost::80/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://foo@localhost:80/ HTTP/1.0\r\n\r\n", 200, None], + ["GET http://[::1]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[::1:2]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd:1]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd::]/ HTTP/1.0\r\n\r\n", 400, None], + ["GET http://[4712:abcd::,]/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://[4712::abcd]:8000/ HTTP/1.0\r\n\r\n", 1, None], + ["GET http://4713::abcd:8001/ HTTP/1.0\r\n\r\n", 400, None], + ["GET / HTTP/1.0\r\nHost: [::1]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [::1:2]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711::abcd]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711::abcd:1]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711:abcd::]\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: [4711::abcd]:8000\r\n\r\n", 1, None], + ["GET / HTTP/1.0\r\nHost: 4714::abcd:8001\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: abc\xa0\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: abc\\foo\r\n\r\n", 400, None], + ["GET http://foo/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET http://foo:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET http://[::1]:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET http://10.0.0.1:81/ HTTP/1.0\r\nHost: bar\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: foo-bar.example.com\r\n\r\n", 200, None], + ["GET / HTTP/1.0\r\nHost: foo_bar.example.com\r\n\r\n", 200, None], + ["GET http://foo_bar/ HTTP/1.0\r\n\r\n", 200, None], ]) - def test_h1_006_01(self, env, intext, status: Optional[int]): + def test_h1_006_01(self, env, intext, status: Optional[int], lognos: Optional[List[str]]): with socket.create_connection(('localhost', int(env.http_port))) as sock: # on some OS, the server does not see our connection until there is # something incoming @@ -119,14 +119,16 @@ def test_h1_006_01(self, env, intext, status: Optional[int]): rlines = msg.splitlines() response = rlines[0] m = re.match(r'^HTTP/1.1 (\d+)\s+(\S+)', response) - assert m or status == 90, f"unrecognized response: {rlines}" + assert m or status == 0, f"unrecognized response: {rlines}" if status == 1: assert int(m.group(1)) >= 200 - elif status == 90: + elif status == 0: # headerless 0.9 response, yuk assert len(rlines) >= 1, f"{rlines}" elif status > 0: assert int(m.group(1)) == status, f"{rlines}" else: assert int(m.group(1)) >= 400, f"{rlines}" - + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) diff --git a/test/modules/http1/test_007_strict.py b/test/modules/http1/test_007_strict.py index 7eee027a6f2..7c52f685a83 100644 --- a/test/modules/http1/test_007_strict.py +++ b/test/modules/http1/test_007_strict.py @@ -1,6 +1,6 @@ import re import socket -from typing import Optional +from typing import List, Optional import pytest @@ -68,17 +68,17 @@ def test_h1_007_01(self, env, intext, status: Optional[int]): else: assert int(m.group(1)) >= 400, f"{rlines}" - @pytest.mark.parametrize(["hvalue", "expvalue", "status"], [ - ['"123"', '123', 200], - ['"123 "', '123 ', 200], # trailing space stays - ['"123\t"', '123\t', 200], # trailing tab stays - ['" 123"', '123', 200], # leading space is stripped - ['" 123"', '123', 200], # leading spaces are stripped - ['"\t123"', '123', 200], # leading tab is stripped - ['"expr=%{unescape:123%0A 123}"', '', 500], # illegal char - ['" \t "', '', 200], # just ws + @pytest.mark.parametrize(["hvalue", "expvalue", "status", "lognos"], [ + ['"123"', '123', 200, None], + ['"123 "', '123 ', 200, None], # trailing space stays + ['"123\t"', '123\t', 200, None], # trailing tab stays + ['" 123"', '123', 200, None], # leading space is stripped + ['" 123"', '123', 200, None], # leading spaces are stripped + ['"\t123"', '123', 200, None], # leading tab is stripped + ['"expr=%{unescape:123%0A 123}"', '', 500, ["AH02430"]], # illegal char + ['" \t "', '', 200, None], # just ws ]) - def test_h1_007_02(self, env, hvalue, expvalue, status): + def test_h1_007_02(self, env, hvalue, expvalue, status, lognos: Optional[List[str]]): hname = 'ap-test-007' conf = H1Conf(env, extras={ f'test1.{env.http_tld}': [ @@ -95,6 +95,9 @@ def test_h1_007_02(self, env, hvalue, expvalue, status): assert r.response["status"] == status if int(status) < 400: assert r.response["header"][hname] == expvalue + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) @pytest.mark.parametrize(["hvalue", "expvalue"], [ ['123', '123'], diff --git a/test/modules/http2/conftest.py b/test/modules/http2/conftest.py index 55d0c3a21e3..c6f8ddee711 100644 --- a/test/modules/http2/conftest.py +++ b/test/modules/http2/conftest.py @@ -30,11 +30,8 @@ def env(pytestconfig) -> H2TestEnv: @pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - +def _h2_package_scope(env): + env.httpd_error_log.add_ignored_lognos([ + 'AH10400', # warning that 'enablereuse' has not effect in certain configs + 'AH00045', # child did not exit in time, SIGTERM was sent + ]) diff --git a/test/modules/http2/env.py b/test/modules/http2/env.py index 34d196d6bd6..bac1a841be4 100644 --- a/test/modules/http2/env.py +++ b/test/modules/http2/env.py @@ -1,7 +1,6 @@ import inspect import logging import os -import re import subprocess from typing import Dict, Any @@ -85,34 +84,6 @@ def __init__(self, pytestconfig=None): CertificateSpec(domains=[f"noh2.{self.http_tld}"], key_type='rsa2048'), ]) - self.httpd_error_log.set_ignored_lognos([ - 'AH02032', - 'AH01276', - 'AH01630', - 'AH00135', - 'AH02261', # Re-negotiation handshake failed (our test_101) - 'AH03490', # scoreboard full, happens on limit tests - 'AH02429', # invalid chars in response header names, see test_h2_200 - 'AH02430', # invalid chars in response header values, see test_h2_200 - 'AH10373', # SSL errors on uncompleted handshakes, see test_h2_105 - 'AH01247', # mod_cgid sometimes freaks out on load tests - 'AH01110', # error by proxy reading response - 'AH10400', # warning that 'enablereuse' has not effect in certain configs test_h2_600 - 'AH00045', # child did not exit in time, SIGTERM was sent - ]) - self.httpd_error_log.add_ignored_patterns([ - re.compile(r'.*malformed header from script \'hecho.py\': Bad header: x.*'), - re.compile(r'.*:tls_post_process_client_hello:.*'), - # OSSL 3 dropped the function name from the error description. Use the code instead: - # 0A0000C1 = no shared cipher -- Too restrictive SSLCipherSuite or using DSA server certificate? - re.compile(r'.*SSL Library Error: error:0A0000C1:.*'), - re.compile(r'.*:tls_process_client_certificate:.*'), - # OSSL 3 dropped the function name from the error description. Use the code instead: - # 0A0000C7 = peer did not return a certificate -- No CAs known to server for verification? - re.compile(r'.*SSL Library Error: error:0A0000C7:.*'), - re.compile(r'.*have incompatible TLS configurations.'), - ]) - def setup_httpd(self, setup: HttpdTestSetup = None): super().setup_httpd(setup=H2TestSetup(env=self)) diff --git a/test/modules/http2/test_007_ssi.py b/test/modules/http2/test_007_ssi.py index 97e38df0312..f5411bccd43 100644 --- a/test/modules/http2/test_007_ssi.py +++ b/test/modules/http2/test_007_ssi.py @@ -1,4 +1,3 @@ -import re import pytest from .env import H2Conf, H2TestEnv diff --git a/test/modules/http2/test_100_conn_reuse.py b/test/modules/http2/test_100_conn_reuse.py index 3ebac24d60b..103166fa301 100644 --- a/test/modules/http2/test_100_conn_reuse.py +++ b/test/modules/http2/test_100_conn_reuse.py @@ -48,6 +48,12 @@ def test_h2_100_04(self, env): hostname = ("noh2.%s" % env.http_tld) r = env.curl_get(url, 5, options=[ "-H", "Host:%s" % hostname ]) assert 421 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02032" # Hostname provided via SNI and hostname provided via HTTP have no compatible SSL setup + ] + ) # access an unknown vhost, after using ServerName in SNI def test_h2_100_05(self, env): @@ -55,3 +61,9 @@ def test_h2_100_05(self, env): hostname = ("unknown.%s" % env.http_tld) r = env.curl_get(url, 5, options=[ "-H", "Host:%s" % hostname ]) assert 421 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02032" # Hostname provided via SNI and hostname provided via HTTP have no compatible SSL setup + ] + ) diff --git a/test/modules/http2/test_101_ssl_reneg.py b/test/modules/http2/test_101_ssl_reneg.py index 66f2638a7b5..9b7f0eab2cb 100644 --- a/test/modules/http2/test_101_ssl_reneg.py +++ b/test/modules/http2/test_101_ssl_reneg.py @@ -56,6 +56,12 @@ def test_h2_101_01(self, env): assert 0 == r.exit_code, f"{r}" assert r.response assert 403 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01276" # No matching DirectoryIndex found + ] + ) # try to renegotiate the cipher, should fail with correct code def test_h2_101_02(self, env): @@ -66,6 +72,16 @@ def test_h2_101_02(self, env): assert 0 != r.exit_code assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_post_process_client_hello:.*', + r'.*SSL Library Error:.*:SSL routines::no shared cipher.*' + ] + ) # try to renegotiate a client certificate from Location # needs to fail with correct code @@ -75,6 +91,16 @@ def test_h2_101_03(self, env): assert 0 != r.exit_code assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_process_client_certificate:.*', + r'.*SSL Library Error:.*:SSL routines::peer did not return a certificate.*' + ] + ) # try to renegotiate a client certificate from Directory # needs to fail with correct code @@ -84,6 +110,16 @@ def test_h2_101_04(self, env): assert 0 != r.exit_code, f"{r}" assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_process_client_certificate:.*', + r'.*SSL Library Error:.*:SSL routines::peer did not return a certificate.*' + ] + ) # make 10 requests on the same connection, none should produce a status code # reported by erki@example.ee @@ -128,3 +164,13 @@ def test_h2_101_11(self, env): assert 0 != r.exit_code assert not r.response assert re.search(r'HTTP_1_1_REQUIRED \(err 13\)', r.stderr) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02261" # Re-negotiation handshake failed + ], + matches = [ + r'.*:tls_post_process_client_hello:.*', + r'.*SSL Library Error:.*:SSL routines::no shared cipher.*' + ] + ) diff --git a/test/modules/http2/test_102_require.py b/test/modules/http2/test_102_require.py index b7e4eaef6ed..4b0cad56a24 100644 --- a/test/modules/http2/test_102_require.py +++ b/test/modules/http2/test_102_require.py @@ -39,3 +39,9 @@ def test_h2_102_02(self, env): assert 0 == r.exit_code assert r.response assert 403 == r.response["status"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01630" # client denied by server configuration + ] + ) diff --git a/test/modules/http2/test_105_timeout.py b/test/modules/http2/test_105_timeout.py index f7d3859cafb..22160b45853 100644 --- a/test/modules/http2/test_105_timeout.py +++ b/test/modules/http2/test_105_timeout.py @@ -42,6 +42,13 @@ def test_h2_105_01(self, env): except Exception as ex: print(f"as expected: {ex}") sock.close() + # + time.sleep(1) # let the log flush + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10373" # SSL handshake was not completed + ] + ) # Check that mod_reqtimeout handshake setting takes effect def test_h2_105_02(self, env): @@ -77,6 +84,13 @@ def test_h2_105_02(self, env): except Exception as ex: print(f"as expected: {ex}") sock.close() + # + time.sleep(1) # let the log flush + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10373" # SSL handshake was not completed + ] + ) # Check that mod_reqtimeout handshake setting do no longer apply to handshaked # connections. See . diff --git a/test/modules/http2/test_106_shutdown.py b/test/modules/http2/test_106_shutdown.py index 83e143cef58..fab881bcac7 100644 --- a/test/modules/http2/test_106_shutdown.py +++ b/test/modules/http2/test_106_shutdown.py @@ -72,4 +72,10 @@ def test_h2_106_02(self, env): else: assert r.exit_code == 0, f"failed on {i}. request: {r.stdout} {r.stderr}" assert r.response["status"] == 200 - assert "HTTP/2" == r.response["protocol"] \ No newline at end of file + assert "HTTP/2" == r.response["protocol"] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH03490" # scoreboard is full, not at MaxRequestWorkers + ] + ) \ No newline at end of file diff --git a/test/modules/http2/test_200_header_invalid.py b/test/modules/http2/test_200_header_invalid.py index fe944878405..a68aaa77e09 100644 --- a/test/modules/http2/test_200_header_invalid.py +++ b/test/modules/http2/test_200_header_invalid.py @@ -28,6 +28,15 @@ def test_h2_200_01(self, env): assert 500 == r.response["status"], f'unexpected status for char 0x{x:02}' else: assert 0 != r.exit_code, f'unexpected exit code for char 0x{x:02}' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02429" # Response header name contains invalid characters + ], + matches = [ + r'.*malformed header from script \'hecho.py\': Bad header: x.*' + ] + ) # let the hecho.py CGI echo chars < 0x20 in field value # for almost all such characters, the stream returns a 500 @@ -46,6 +55,12 @@ def test_h2_200_02(self, env): assert 500 == r.response["status"], f'unexpected status for char 0x{x:02}' else: assert 0 != r.exit_code, "unexpected exit code for char 0x%02x" % x + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02430" # Response header value contains invalid characters + ] + ) # let the hecho.py CGI echo 0x10 and 0x7f in field name and value def test_h2_200_03(self, env): @@ -63,6 +78,13 @@ def test_h2_200_03(self, env): assert 500 == r.response["status"], f"unexpected exit code for char 0x{h:02}" else: assert 0 != r.exit_code + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH02429", # Response header name contains invalid characters + "AH02430" # Response header value contains invalid characters + ] + ) # test header field lengths check, LimitRequestLine (default 8190) def test_h2_200_10(self, env): diff --git a/test/modules/http2/test_203_rfc9113.py b/test/modules/http2/test_203_rfc9113.py index 9fc8f3b2242..1fe3e131595 100644 --- a/test/modules/http2/test_203_rfc9113.py +++ b/test/modules/http2/test_203_rfc9113.py @@ -1,4 +1,5 @@ import pytest +from typing import List, Optional from pyhttpd.env import HttpdTestEnv from .env import H2Conf @@ -22,17 +23,17 @@ def test_h2_203_01_ws_ignore(self, env): assert r.response["status"] == 200, f'curl output: {r.stdout}' # response header are also handled, but we strip ws before sending - @pytest.mark.parametrize(["hvalue", "expvalue", "status"], [ - ['"123"', '123', 200], - ['"123 "', '123', 200], # trailing space stripped - ['"123\t"', '123', 200], # trailing tab stripped - ['" 123"', '123', 200], # leading space is stripped - ['" 123"', '123', 200], # leading spaces are stripped - ['"\t123"', '123', 200], # leading tab is stripped - ['"expr=%{unescape:123%0A 123}"', '', 500], # illegal char - ['" \t "', '', 200], # just ws + @pytest.mark.parametrize(["hvalue", "expvalue", "status", "lognos"], [ + ['"123"', '123', 200, None], + ['"123 "', '123', 200, None], # trailing space stripped + ['"123\t"', '123', 200, None], # trailing tab stripped + ['" 123"', '123', 200, None], # leading space is stripped + ['" 123"', '123', 200, None], # leading spaces are stripped + ['"\t123"', '123', 200, None], # leading tab is stripped + ['"expr=%{unescape:123%0A 123}"', '', 500, ["AH02430"]], # illegal char + ['" \t "', '', 200, None], # just ws ]) - def test_h2_203_02(self, env, hvalue, expvalue, status): + def test_h2_203_02(self, env, hvalue, expvalue, status, lognos: Optional[List[str]]): hname = 'ap-test-007' conf = H2Conf(env, extras={ f'test1.{env.http_tld}': [ @@ -53,4 +54,7 @@ def test_h2_203_02(self, env, hvalue, expvalue, status): assert r.response["status"] == status if int(status) < 400: assert r.response["header"][hname] == expvalue + # + if lognos is not None: + env.httpd_error_log.ignore_recent(lognos = lognos) diff --git a/test/modules/http2/test_500_proxy.py b/test/modules/http2/test_500_proxy.py index 88a8ece3f6e..87e523c4a21 100644 --- a/test/modules/http2/test_500_proxy.py +++ b/test/modules/http2/test_500_proxy.py @@ -149,9 +149,21 @@ def test_h2_500_31(self, env, repeat): url = env.mkurl("https", "cgi", "/proxy/h2test/error?body_error=timeout") r = env.curl_get(url) assert r.exit_code != 0, r + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01110" # Network error reading response + ] + ) # produce an error, fail to generate an error bucket def test_h2_500_32(self, env, repeat): url = env.mkurl("https", "cgi", "/proxy/h2test/error?body_error=timeout&error_bucket=0") r = env.curl_get(url) assert r.exit_code != 0, r + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01110" # Network error reading response + ] + ) diff --git a/test/modules/http2/test_800_websockets.py b/test/modules/http2/test_800_websockets.py index 97e73737353..2e3d03a0e57 100644 --- a/test/modules/http2/test_800_websockets.py +++ b/test/modules/http2/test_800_websockets.py @@ -154,7 +154,6 @@ def test_h2_800_01_fail_proto(self, env: H2TestEnv, ws_server): r, infos, frames = ws_run(env, path='/ws/echo/', scenario='fail-proto') assert r.exit_code == 0, f'{r}' assert infos == ['[1] :status: 501', '[1] EOF'], f'{r}' - env.httpd_error_log.ignore_recent() # a correct CONNECT, send CLOSE, expect CLOSE, basic success def test_h2_800_02_ws_empty(self, env: H2TestEnv, ws_server): diff --git a/test/modules/md/conftest.py b/test/modules/md/conftest.py index 04165a2dfcd..192cd31a80b 100755 --- a/test/modules/md/conftest.py +++ b/test/modules/md/conftest.py @@ -1,6 +1,5 @@ import logging import os -import re import sys import pytest @@ -37,44 +36,11 @@ def env(pytestconfig) -> MDTestEnv: @pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - # we'd like to check the httpd error logs after the test suite has - # run to catch anything unusual. For this, we setup the ignore list - # of errors and warnings that we do expect. - env.httpd_error_log.set_ignored_lognos([ - 'AH10040', # mod_md, setup complain - 'AH10045', # mod_md complains that there is no vhost for an MDomain - 'AH10056', # mod_md, invalid params - 'AH10105', # mod_md does not find a vhost with SSL enabled for an MDomain - 'AH10085', # mod_ssl complains about fallback certificates - 'AH01909', # mod_ssl, cert alt name complains - 'AH10170', # mod_md, wrong config, tested - 'AH10171', # mod_md, wrong config, tested - 'AH10373', # SSL errors on uncompleted handshakes - 'AH10398', # test on global store lock +def _md_package_scope(env): + env.httpd_error_log.add_ignored_lognos([ + "AH10085" # There are no SSL certificates configured and no other module contributed any ]) - env.httpd_error_log.add_ignored_patterns([ - re.compile(r'.*urn:ietf:params:acme:error:.*'), - re.compile(r'.*None of the ACME challenge methods configured for this domain are suitable.*'), - re.compile(r'.*problem\[(challenge-mismatch|challenge-setup-failure|apache:eab-hmac-invalid)].*'), - re.compile(r'.*CA considers answer to challenge invalid.].*'), - re.compile(r'.*problem\[urn:org:apache:httpd:log:AH\d+:].*'), - re.compile(r'.*Unsuccessful in contacting ACME server at :*'), - re.compile(r'.*test-md-720-002-\S+.org: dns-01 setup command failed .*'), - re.compile(r'.*AH\d*: unable to obtain global registry lock, .*'), - ]) - if env.lacks_ocsp(): - env.httpd_error_log.add_ignored_patterns([ - re.compile(r'.*certificate with serial \S+ has no OCSP responder URL.*'), - ]) - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) - @pytest.fixture(scope="package") def acme(env): diff --git a/test/modules/md/test_300_conf_validate.py b/test/modules/md/test_300_conf_validate.py index 85371ba227b..f348f5f1789 100644 --- a/test/modules/md/test_300_conf_validate.py +++ b/test/modules/md/test_300_conf_validate.py @@ -24,6 +24,12 @@ def test_md_300_001(self, env): MDomain not-forbidden.org www.not-forbidden.org mail.not-forbidden.org """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomain definitions, non-overlapping def test_md_300_002(self, env): @@ -32,6 +38,12 @@ def test_md_300_002(self, env): MDomain example2.org www.example2.org mail.example2.org """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomain definitions, exactly the same def test_md_300_003(self, env): @@ -41,6 +53,12 @@ def test_md_300_003(self, env): MDomain not-forbidden.org www.not-forbidden.org mail.not-forbidden.org test3.not-forbidden.org """).install() assert env.apache_fail() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10038" # two Managed Domains have an overlap in domain + ] + ) # test case: two MDomain definitions, overlapping def test_md_300_004(self, env): @@ -50,6 +68,12 @@ def test_md_300_004(self, env): MDomain example2.org test3.not-forbidden.org www.example2.org mail.example2.org """).install() assert env.apache_fail() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10038" # two Managed Domains have an overlap in domain + ] + ) # test case: two MDomains, one inside a virtual host def test_md_300_005(self, env): @@ -60,6 +84,12 @@ def test_md_300_005(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomains, one correct vhost name def test_md_300_006(self, env): @@ -71,6 +101,12 @@ def test_md_300_006(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomains, two correct vhost names def test_md_300_007(self, env): @@ -85,6 +121,12 @@ def test_md_300_007(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: two MDomains, overlapping vhosts def test_md_300_008(self, env): @@ -102,6 +144,12 @@ def test_md_300_008(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: vhosts with overlapping MDs def test_md_300_009(self, env): @@ -118,7 +166,12 @@ def test_md_300_009(self, env): conf.install() assert env.apache_fail() == 0 env.apache_stop() - env.httpd_error_log.ignore_recent() + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10238" # 2 MDs match Virtualhost + ] + ) # test case: MDomain, vhost with matching ServerAlias def test_md_300_010(self, env): @@ -146,6 +199,9 @@ def test_md_300_011a(self, env): conf.install() assert env.apache_fail() == 0 env.apache_stop() + env.httpd_error_log.ignore_recent([ + "AH10040" # A requested MD certificate will not match ServerName + ]) # test case: MDomain, misses one ServerAlias, but auto add enabled def test_md_300_011b(self, env): @@ -171,6 +227,12 @@ def test_md_300_012(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10045" # No VirtualHost matches Managed Domain + ] + ) # test case: one md covers two vhosts def test_md_300_013(self, env): @@ -261,7 +323,6 @@ def test_md_300_020(self, env, line, exp_err_msg): MDConf(env, text=line).install() assert env.apache_fail() == 0, "Server accepted test config {}".format(line) assert exp_err_msg in env.apachectl_stderr - env.httpd_error_log.ignore_recent() # test case: alt-names incomplete detection, github isse #68 def test_md_300_021(self, env): @@ -294,6 +355,12 @@ def test_md_300_022(self, env): """).install() assert env.apache_restart() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10105" # MD secret.com does not match any VirtualHost with 'SSLEngine on' + ] + ) # test case: use MDRequireHttps not in 0 assert md['renewal']['last']['status-description'] == 'Connection refused' assert 'account' not in md['ca'] + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Unsuccessful in contacting ACME server + ], + matches = [ + r'.*Unsuccessful in contacting ACME server at .*' + ] + ) # Specify a valid http proxy def test_md_702_008a(self, env): @@ -335,6 +359,16 @@ def test_md_702_010(self, env): assert env.apache_restart() == 0 env.check_md(domains) assert env.await_completion([domain]) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10173", # None of the ACME challenge methods configured for this domain are suitable + "AH10056" # None of the ACME challenge methods configured for this domain are suitable + ], + matches = [ + r'.*None of the ACME challenge methods configured for this domain are suitable.*' + ] + ) def test_md_702_011(self, env): domain = self.test_domain @@ -364,6 +398,16 @@ def test_md_702_011(self, env): assert env.apache_restart() == 0 env.check_md(domains) assert env.await_completion([domain]) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10173", # None of the ACME challenge methods configured for this domain are suitable + "AH10056" # None of the ACME challenge methods configured for this domain are suitable + ], + matches = [ + r'.*None of the ACME challenge methods configured for this domain are suitable.*' + ] + ) # test case: one MD with several dns names. sign up. remove the *first* name # in the MD. restart. should find and keep the existing MD. @@ -648,6 +692,16 @@ def test_md_702_051(self, env): conf.install() assert env.apache_restart() == 0 assert env.await_error(domain) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10173", # None of the ACME challenge methods configured for this domain are suitable + "AH10056" # None of the ACME challenge methods configured for this domain are suitable + ], + matches = [ + r'.*None of the ACME challenge methods configured for this domain are suitable.*' + ] + ) # Make a setup using the base server without http:, but with acme-tls/1, should work. def test_md_702_052(self, env): diff --git a/test/modules/md/test_720_wildcard.py b/test/modules/md/test_720_wildcard.py index 23b311c3a47..916c47a5d85 100644 --- a/test/modules/md/test_720_wildcard.py +++ b/test/modules/md/test_720_wildcard.py @@ -44,6 +44,15 @@ def test_md_720_001(self, env): assert md assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'challenge-mismatch' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of offered challenge types + ], + matches = [ + r'.*problem\[challenge-mismatch\].*' + ] + ) # test case: a wildcard certificate with ACMEv2, only dns-01 configured, invalid command path def test_md_720_002(self, env): @@ -67,6 +76,16 @@ def test_md_720_002(self, env): assert md assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'challenge-setup-failure' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of offered challenge types + ], + matches = [ + r'.*problem\[challenge-setup-failure\].*', + r'.*setup command failed to execute.*' + ] + ) # variation, invalid cmd path, other challenges still get certificate for non-wildcard def test_md_720_002b(self, env): @@ -113,6 +132,15 @@ def test_md_720_003(self, env): assert md assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'challenge-setup-failure' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of offered challenge types + ], + matches = [ + r'.*problem\[challenge-setup-failure\].*' + ] + ) # test case: a wildcard name certificate with ACMEv2, only dns-01 configured def test_md_720_004(self, env): diff --git a/test/modules/md/test_730_static.py b/test/modules/md/test_730_static.py index f7f7b4b2cfe..891ae620bb8 100644 --- a/test/modules/md/test_730_static.py +++ b/test/modules/md/test_730_static.py @@ -115,3 +115,10 @@ def test_md_730_003(self, env): conf.add_vhost(domain) conf.install() assert env.apache_fail() == 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10170", # Managed Domain needs one MDCertificateKeyFile for each MDCertificateFile + "AH10171" # Managed Domain has MDCertificateKeyFile(s) but no MDCertificateFile + ] + ) diff --git a/test/modules/md/test_740_acme_errors.py b/test/modules/md/test_740_acme_errors.py index 670c9ab831a..364aaca6c8d 100644 --- a/test/modules/md/test_740_acme_errors.py +++ b/test/modules/md/test_740_acme_errors.py @@ -46,6 +46,15 @@ def test_md_740_000(self, env): assert md['renewal']['last']['detail'] == ( "Error creating new order :: Cannot issue for " "\"%s\": Domain name contains an invalid character" % domains[1]) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Order included DNS identifier with a value containing an illegal character + ], + matches = [ + r'.*urn:ietf:params:acme:error:malformed.*' + ] + ) # test case: MD with 3 names, 2 invalid # @@ -70,3 +79,12 @@ def test_md_740_001(self, env): "Error creating new order :: Cannot issue for") assert md['renewal']['last']['subproblems'] assert len(md['renewal']['last']['subproblems']) == 2 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Order included DNS identifier with a value containing an illegal character + ], + matches = [ + r'.*urn:ietf:params:acme:error:malformed.*' + ] + ) diff --git a/test/modules/md/test_741_setup_errors.py b/test/modules/md/test_741_setup_errors.py index 49b4e788c06..9ad79f0b1e9 100644 --- a/test/modules/md/test_741_setup_errors.py +++ b/test/modules/md/test_741_setup_errors.py @@ -46,3 +46,13 @@ def test_md_741_001(self, env): md = env.await_error(domain, errors=2, timeout=10) assert md assert md['renewal']['errors'] > 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # CA considers answer to challenge invalid + ], + matches = [ + r'.*The key authorization file from the server did not match this challenge.*', + r'.*CA considers answer to challenge invalid.*' + ] + ) diff --git a/test/modules/md/test_750_eab.py b/test/modules/md/test_750_eab.py index af1be95d05a..7d81917829e 100644 --- a/test/modules/md/test_750_eab.py +++ b/test/modules/md/test_750_eab.py @@ -37,6 +37,15 @@ def test_md_750_001(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_002(self, env): # md with known EAB KID and non base64 hmac key configured @@ -51,6 +60,15 @@ def test_md_750_002(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'apache:eab-hmac-invalid' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # external account binding HMAC value is not valid base64 + ], + matches = [ + r'.*problem\[apache:eab-hmac-invalid\].*' + ] + ) def test_md_750_003(self, env): # md with empty EAB KID configured @@ -65,6 +83,15 @@ def test_md_750_003(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # the field 'kid' references a key that is not known to the ACME server + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_004(self, env): # md with unknown EAB KID configured @@ -79,6 +106,15 @@ def test_md_750_004(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # the field 'kid' references a key that is not known to the ACME server + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_005(self, env): # md with known EAB KID but wrong HMAC configured @@ -93,6 +129,15 @@ def test_md_750_005(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # external account binding JWS verification error: square/go-jose: error in cryptographic primitive + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_010(self, env): # md with correct EAB configured @@ -125,6 +170,15 @@ def test_md_750_011(self, env): md = env.await_error(domain_b) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_012(self, env): # first one md without EAB, then one with @@ -144,6 +198,15 @@ def test_md_750_012(self, env): md = env.await_error(domain_a) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_013(self, env): # 2 mds with the same EAB, should one create a single account @@ -215,6 +278,15 @@ def test_md_750_015(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_016(self, env): # md with correct EAB, get cert, change to invalid EAB @@ -241,6 +313,15 @@ def test_md_750_016(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:unauthorized' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # the field 'kid' references a key that is not known to the ACME server + ], + matches = [ + r'.*urn:ietf:params:acme:error:unauthorized.*' + ] + ) def test_md_750_017(self, env): # md without EAB explicitly set to none @@ -257,6 +338,15 @@ def test_md_750_017(self, env): md = env.await_error(domain) assert md['renewal']['errors'] > 0 assert md['renewal']['last']['problem'] == 'urn:ietf:params:acme:error:externalAccountRequired' + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # ACME server policy requires newAccount requests must include a value for the 'externalAccountBinding' field + ], + matches = [ + r'.*urn:ietf:params:acme:error:externalAccountRequired.*' + ] + ) def test_md_750_018(self, env): # md with EAB file that does not exist diff --git a/test/modules/md/test_780_tailscale.py b/test/modules/md/test_780_tailscale.py index 84a266b2eb7..27a2df474aa 100644 --- a/test/modules/md/test_780_tailscale.py +++ b/test/modules/md/test_780_tailscale.py @@ -140,6 +140,12 @@ def test_md_780_001(self, env): assert md['renewal']['last']['status-description'] == 'No such file or directory' assert md['renewal']['last']['detail'] == \ f"tailscale socket not available, may not be up: {socket_path}" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # retrieving certificate from tailscale + ] + ) # create a MD using `tailscale` as protocol, path to faker, should succeed def test_md_780_002(self, env): @@ -184,3 +190,9 @@ def test_md_780_003(self, env): assert md['renewal']['errors'] > 0 assert md['renewal']['last']['status-description'] == 'No such file or directory' assert md['renewal']['last']['detail'] == "retrieving certificate from tailscale" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # retrieving certificate from tailscale + ] + ) diff --git a/test/modules/md/test_790_failover.py b/test/modules/md/test_790_failover.py index a93991233d3..696161fd4fd 100644 --- a/test/modules/md/test_790_failover.py +++ b/test/modules/md/test_790_failover.py @@ -63,6 +63,15 @@ def test_md_790_002(self, env): assert env.apache_restart() == 0 assert env.await_completion([domain]) env.check_md_complete(domain) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Unsuccessful in contacting ACME server + ], + matches = [ + r'.*Unsuccessful in contacting ACME server at .*' + ] + ) # set 3 ACME certificata authority, invalid + invalid + valid def test_md_790_003(self, env): @@ -85,3 +94,12 @@ def test_md_790_003(self, env): assert env.apache_restart() == 0 assert env.await_completion([domain]) env.check_md_complete(domain) + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # Unsuccessful in contacting ACME server + ], + matches = [ + r'.*Unsuccessful in contacting ACME server at .*' + ] + ) diff --git a/test/modules/md/test_900_notify.py b/test/modules/md/test_900_notify.py index 30e0742036c..9d18da54114 100644 --- a/test/modules/md/test_900_notify.py +++ b/test/modules/md/test_900_notify.py @@ -49,6 +49,12 @@ def test_md_900_001(self, env): assert env.await_error(self.domain) stat = env.get_md_status(self.domain) assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10108:" + # + env.httpd_error_log.ignore_recent( + matches = [ + r'.*urn:org:apache:httpd:log:AH10108:.*' + ] + ) # test: valid notify cmd that fails, check error def test_md_900_002(self, env): @@ -61,6 +67,14 @@ def test_md_900_002(self, env): assert env.await_error(self.domain) stat = env.get_md_status(self.domain) assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10108:" + # + env.httpd_error_log.ignore_recent( + matches = [ + r'.*urn:org:apache:httpd:log:AH10108:.*', + r'.*urn:org:apache:httpd:log:AH10109:.*' + r'.*problem\[challenge-setup-failure\].*', + ] + ) # test: valid notify that logs to file def test_md_900_010(self, env): diff --git a/test/modules/md/test_901_message.py b/test/modules/md/test_901_message.py index 8d03bfd6a31..b18cfd38d44 100644 --- a/test/modules/md/test_901_message.py +++ b/test/modules/md/test_901_message.py @@ -46,6 +46,16 @@ def test_md_901_001(self, env): stat = env.get_md_status(domain) # this command should have failed and logged an error assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of the offered challenge types + ], + matches = [ + r'.*urn:org:apache:httpd:log:AH10109:.*', + r'.*problem\[challenge-setup-failure\].*' + ] + ) # test: signup with configured message cmd that is valid but returns != 0 def test_md_901_002(self, env): @@ -63,6 +73,16 @@ def test_md_901_002(self, env): stat = env.get_md_status(domain) # this command should have failed and logged an error assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:" + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of the offered challenge types + ], + matches = [ + r'.*urn:org:apache:httpd:log:AH10109:.*', + r'.*problem\[challenge-setup-failure\].*' + ] + ) # test: signup with working message cmd and see that it logs the right things def test_md_901_003(self, env): @@ -247,7 +267,6 @@ def test_md_901_030(self, env): assert job["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:" break time.sleep(0.1) - env.httpd_error_log.ignore_recent() # reconfigure to a working notification command and restart conf = MDConf(env) @@ -294,4 +313,13 @@ def test_md_901_040(self, env): stat = env.get_md_status(domain) # this command should have failed and logged an error assert stat["renewal"]["last"]["problem"] == "challenge-setup-failure" - + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10056" # None of the offered challenge types + ], + matches = [ + r'.*urn:org:apache:httpd:log:AH10109:.*', + r'.*problem\[challenge-setup-failure\].*' + ] + ) diff --git a/test/modules/md/test_920_status.py b/test/modules/md/test_920_status.py index c89ce6d8d70..6ad708728c7 100644 --- a/test/modules/md/test_920_status.py +++ b/test/modules/md/test_920_status.py @@ -243,3 +243,9 @@ def test_md_920_020(self, env): assert ktype in stat['cert'] if env.acme_server == 'boulder': assert 'ocsp' in stat['cert'][ktype] + # + env.httpd_error_log.ignore_recent( + matches = [ + r'.*certificate with serial \w+ has no OCSP responder URL.*' + ] + ) diff --git a/test/modules/proxy/conftest.py b/test/modules/proxy/conftest.py index 23c5f14201f..7e6f4e7b09d 100644 --- a/test/modules/proxy/conftest.py +++ b/test/modules/proxy/conftest.py @@ -29,23 +29,3 @@ def env(pytestconfig) -> ProxyTestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - # we'd like to check the httpd error logs after the test suite has - # run to catch anything unusual. For this, we setup the ignore list - # of errors and warnings that we do expect. - env.httpd_error_log.set_ignored_lognos([ - 'AH01144', # No protocol handler was valid for the URL - ]) - - env.httpd_error_log.add_ignored_patterns([ - #re.compile(r'.*urn:ietf:params:acme:error:.*'), - ]) - yield - assert env.apache_stop() == 0 - errors, warnings = env.httpd_error_log.get_missed() - assert (len(errors), len(warnings)) == (0, 0),\ - f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ - "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) diff --git a/test/modules/proxy/env.py b/test/modules/proxy/env.py index 9ed635cd5fb..098d4d49485 100644 --- a/test/modules/proxy/env.py +++ b/test/modules/proxy/env.py @@ -1,7 +1,6 @@ import inspect import logging import os -import re import subprocess from typing import Dict, Any diff --git a/test/modules/proxy/test_02_unix.py b/test/modules/proxy/test_02_unix.py index 7f3d4d55b2b..0c39bc9c12c 100644 --- a/test/modules/proxy/test_02_unix.py +++ b/test/modules/proxy/test_02_unix.py @@ -153,6 +153,12 @@ def test_proxy_02_003(self, env, via, exp_status): r2 = self.parse_response(rlines) assert r2.response assert r2.response['status'] == exp_status + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01144" # No protocol handler was valid for the URL + ] + ) def parse_response(self, lines) -> ExecResult: exp_body = False diff --git a/test/modules/tls/conftest.py b/test/modules/tls/conftest.py index cde4be60714..c7cb85877d5 100644 --- a/test/modules/tls/conftest.py +++ b/test/modules/tls/conftest.py @@ -31,9 +31,3 @@ def env(pytestconfig) -> TlsTestEnv: env.apache_access_log_clear() env.httpd_error_log.clear_log() return env - - -@pytest.fixture(autouse=True, scope="package") -def _session_scope(env): - yield - assert env.apache_stop() == 0 diff --git a/test/modules/tls/test_03_sni.py b/test/modules/tls/test_03_sni.py index cf421c0fe81..cbd142afbc9 100644 --- a/test/modules/tls/test_03_sni.py +++ b/test/modules/tls/test_03_sni.py @@ -34,6 +34,12 @@ def test_tls_03_sni_unknown(self, env): domain_unknown = "unknown.test" r = env.tls_get(domain_unknown, "/index.json") assert r.exit_code != 0 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10353" # cannot decrypt peer's message + ] + ) def test_tls_03_sni_request_other_same_config(self, env): # do we see the first vhost response for another domain with different certs? @@ -44,6 +50,12 @@ def test_tls_03_sni_request_other_same_config(self, env): assert r.exit_code == 0 assert r.json is None assert r.response['status'] == 421 + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10345" # Connection host selected via SNI and request have incompatible TLS configurations + ] + ) def test_tls_03_sni_request_other_other_honor(self, env): # do we see the first vhost response for an unknown domain? @@ -60,6 +72,12 @@ def test_tls_03_sni_request_other_other_honor(self, env): # request denied assert r.exit_code == 0 assert r.json is None + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10345" # Connection host selected via SNI and request have incompatible TLS configurations + ] + ) @pytest.mark.skip('openssl behaviour changed on ventura, unreliable') def test_tls_03_sni_bad_hostname(self, env): diff --git a/test/modules/tls/test_06_ciphers.py b/test/modules/tls/test_06_ciphers.py index 2e60bdd7563..6f515e4d777 100644 --- a/test/modules/tls/test_06_ciphers.py +++ b/test/modules/tls/test_06_ciphers.py @@ -176,16 +176,18 @@ def test_tls_06_ciphers_pref_unknown(self, env): def test_tls_06_ciphers_pref_unsupported(self, env): # a warning on preferring a known, but not supported cipher - env.httpd_error_log.ignore_recent() conf = TlsTestConf(env=env, extras={ env.domain_b: "TLSCiphersPrefer TLS_NULL_WITH_NULL_NULL" }) conf.add_tls_vhosts(domains=[env.domain_a, env.domain_b]) conf.install() assert env.apache_restart() == 0 - (errors, warnings) = env.httpd_error_log.get_recent_count() - assert errors == 0 - assert warnings == 2 # once on dry run, once on start + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH10319" # Server has TLSCiphersPrefer configured that are not supported by rustls + ] + ) def test_tls_06_ciphers_supp_unknown(self, env): conf = TlsTestConf(env=env, extras={ @@ -197,13 +199,9 @@ def test_tls_06_ciphers_supp_unknown(self, env): def test_tls_06_ciphers_supp_unsupported(self, env): # no warnings on suppressing known, but not supported ciphers - env.httpd_error_log.ignore_recent() conf = TlsTestConf(env=env, extras={ env.domain_b: "TLSCiphersSuppress TLS_NULL_WITH_NULL_NULL" }) conf.add_tls_vhosts(domains=[env.domain_a, env.domain_b]) conf.install() assert env.apache_restart() == 0 - (errors, warnings) = env.httpd_error_log.get_recent_count() - assert errors == 0 - assert warnings == 0 diff --git a/test/modules/tls/test_14_proxy_ssl.py b/test/modules/tls/test_14_proxy_ssl.py index 79b2fb4b041..3118b4dda1e 100644 --- a/test/modules/tls/test_14_proxy_ssl.py +++ b/test/modules/tls/test_14_proxy_ssl.py @@ -48,6 +48,13 @@ def test_tls_14_proxy_ssl_get_local(self, env): # does not work, since SSLProxy* not configured data = env.tls_get_json(env.domain_b, "/proxy-local/index.json") assert data is None + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01961", # failed to enable ssl support [Hint: if using mod_ssl, see SSLProxyEngine] + "AH00961" # failed to enable ssl support (mod_proxy) + ] + ) def test_tls_14_proxy_ssl_h2_get(self, env): r = env.tls_get(env.domain_b, "/proxy-h2-ssl/index.json") diff --git a/test/modules/tls/test_15_proxy_tls.py b/test/modules/tls/test_15_proxy_tls.py index f2f670d7e99..ed881a034dc 100644 --- a/test/modules/tls/test_15_proxy_tls.py +++ b/test/modules/tls/test_15_proxy_tls.py @@ -1,4 +1,3 @@ -import re from datetime import timedelta import pytest @@ -53,6 +52,13 @@ def test_tls_15_proxy_tls_get_local(self, env): # does not work, since SSLProxy* not configured data = env.tls_get_json(env.domain_b, "/proxy-local/index.json") assert data is None + # + env.httpd_error_log.ignore_recent( + lognos = [ + "AH01961", # failed to enable ssl support [Hint: if using mod_ssl, see SSLProxyEngine] + "AH00961" # failed to enable ssl support (mod_proxy) + ] + ) def test_tls_15_proxy_tls_h2_get(self, env): r = env.tls_get(env.domain_b, "/proxy-h2-tls/index.json") diff --git a/test/pyhttpd/env.py b/test/pyhttpd/env.py index f8d27d04cd8..0df1fd7a70f 100644 --- a/test/pyhttpd/env.py +++ b/test/pyhttpd/env.py @@ -324,6 +324,12 @@ def setup_httpd(self, setup: HttpdTestSetup = None): for name in self._httpd_log_modules: self._log_interesting += f" {name}:{log_level}" + def check_error_log(self): + errors, warnings = self._error_log.get_missed() + assert (len(errors), len(warnings)) == (0, 0),\ + f"apache logged {len(errors)} errors and {len(warnings)} warnings: \n"\ + "{0}\n{1}\n".format("\n".join(errors), "\n".join(warnings)) + @property def curl(self) -> str: return self._curl @@ -558,16 +564,22 @@ def mkurl(self, scheme, hostname, path='/'): return f"{scheme}://{hostname}.{self.http_tld}:{port}{path}" def install_test_conf(self, lines: List[str]): + self.apache_stop() with open(self._test_conf, 'w') as fd: fd.write('\n'.join(self._httpd_base_conf)) fd.write('\n') fd.write(f"CoreDumpDirectory {self._server_dir}\n") - if self._verbosity >= 2: - fd.write(f"LogLevel core:trace5 {self.mpm_module}:trace5 http:trace5\n") + fd.write('\n') if self._verbosity >= 3: - fd.write(f"LogLevel dumpio:trace7\n") + fd.write(f"LogLevel trace7 ssl:trace6\n") fd.write(f"DumpIoOutput on\n") fd.write(f"DumpIoInput on\n") + elif self._verbosity >= 2: + fd.write(f"LogLevel debug core:trace5 {self.mpm_module}:trace5 ssl:trace5 http:trace5\n") + elif self._verbosity >= 1: + fd.write(f"LogLevel info\n") + else: + fd.write(f"LogLevel warn\n") if self._log_interesting: fd.write(self._log_interesting) fd.write('\n\n') diff --git a/test/pyhttpd/log.py b/test/pyhttpd/log.py index dff7623b246..17b0502e9de 100644 --- a/test/pyhttpd/log.py +++ b/test/pyhttpd/log.py @@ -8,33 +8,32 @@ class HttpdErrorLog: """Checking the httpd error log for errors and warnings, including - limiting checks from a last known position forward. + limiting checks from a recent known position forward. """ - RE_ERRLOG_ERROR = re.compile(r'.*\[(?P[^:]+):error].*') - RE_ERRLOG_WARN = re.compile(r'.*\[(?P[^:]+):warn].*') - RE_APLOGNO = re.compile(r'.*\[(?P[^:]+):(error|warn)].* (?PAH\d+): .+') - RE_SSL_LIB_ERR = re.compile(r'.*\[ssl:error].* SSL Library Error: error:(?P\S+):.+') + RE_ERRLOG_WARN = re.compile(r'.*\[[^:]+:warn].*') + RE_ERRLOG_ERROR = re.compile(r'.*\[[^:]+:error].*') + RE_APLOGNO = re.compile(r'.*\[[^:]+:(error|warn)].* (?PAH\d+): .+') def __init__(self, path: str): self._path = path - self._ignored_modules = [] + self._ignored_matches = [] self._ignored_lognos = set() - self._ignored_patterns = [] # remember the file position we started with self._start_pos = 0 if os.path.isfile(self._path): with open(self._path) as fd: self._start_pos = fd.seek(0, SEEK_END) - self._last_pos = self._start_pos - self._last_errors = [] - self._last_warnings = [] - self._observed_erros = set() - self._observed_warnings = set() + self._recent_pos = self._start_pos + self._recent_errors = [] + self._recent_warnings = [] + self._caught_errors = set() + self._caught_warnings = set() + self._caught_matches = set() def __repr__(self): - return f"HttpdErrorLog[{self._path}, errors: {' '.join(self._last_errors)}, " \ - f"warnings: {' '.join(self._last_warnings)}]" + return f"HttpdErrorLog[{self._path}, errors: {' '.join(self._recent_errors)}, " \ + f"warnings: {' '.join(self._recent_warnings)}]" @property def path(self) -> str: @@ -42,118 +41,108 @@ def path(self) -> str: def clear_log(self): if os.path.isfile(self.path): - os.remove(self.path) - self._start_pos = 0 - self._last_pos = self._start_pos - self._last_errors = [] - self._last_warnings = [] - self._observed_erros = set() - self._observed_warnings = set() + os.truncate(self.path, 0) + self._start_pos = self._recent_pos = 0 + self._recent_errors = [] + self._recent_warnings = [] + self._caught_errors = set() + self._caught_warnings = set() + self._caught_matches = set() + + def _lookup_matches(self, line: str, matches: List[str]) -> bool: + for m in matches: + if re.match(m, line): + return True + return False + + def _lookup_lognos(self, line: str, lognos: set) -> bool: + if len(lognos) > 0: + m = self.RE_APLOGNO.match(line) + if m and m.group('aplogno') in lognos: + return True + return False - def set_ignored_modules(self, modules: List[str]): - self._ignored_modules = modules.copy() if modules else [] + def clear_ignored_matches(self): + self._ignored_matches = [] - def set_ignored_lognos(self, lognos: List[str]): - if lognos: - for l in lognos: - self._ignored_lognos.add(l) + def add_ignored_matches(self, matches: List[str]): + for m in matches: + self._ignored_matches.append(re.compile(m)) - def add_ignored_patterns(self, patterns: List[Any]): - self._ignored_patterns.extend(patterns) + def clear_ignored_lognos(self): + self._ignored_lognos = set() + + def add_ignored_lognos(self, lognos: List[str]): + for l in lognos: + self._ignored_lognos.add(l) def _is_ignored(self, line: str) -> bool: - for p in self._ignored_patterns: - if p.match(line): - return True - m = self.RE_APLOGNO.match(line) - if m and m.group('aplogno') in self._ignored_lognos: + if self._lookup_matches(line, self._ignored_matches): + return True + if self._lookup_lognos(line, self._ignored_lognos): return True return False - def get_recent(self, advance=True) -> Tuple[List[str], List[str]]: - """Collect error and warning from the log since the last remembered position - :param advance: advance the position to the end of the log afterwards - :return: list of error and list of warnings as tuple - """ - self._last_errors = [] - self._last_warnings = [] + def ignore_recent(self, lognos: List[str] = [], matches: List[str] = []): + """After a test case triggered errors/warnings on purpose, add + those to our 'caught' list so the do not get reported as 'missed'. + """ + self._recent_errors = [] + self._recent_warnings = [] if os.path.isfile(self._path): with open(self._path) as fd: - fd.seek(self._last_pos, os.SEEK_SET) + fd.seek(self._recent_pos, os.SEEK_SET) + lognos_set = set(lognos) for line in fd: if self._is_ignored(line): continue - m = self.RE_ERRLOG_ERROR.match(line) - if m and m.group('module') not in self._ignored_modules: - self._last_errors.append(line) + if self._lookup_matches(line, matches): + self._caught_matches.add(line) continue m = self.RE_ERRLOG_WARN.match(line) - if m: - if m and m.group('module') not in self._ignored_modules: - self._last_warnings.append(line) - continue - if advance: - self._last_pos = fd.tell() - self._observed_erros.update(set(self._last_errors)) - self._observed_warnings.update(set(self._last_warnings)) - return self._last_errors, self._last_warnings - - def get_recent_count(self, advance=True): - errors, warnings = self.get_recent(advance=advance) - return len(errors), len(warnings) - - def ignore_recent(self): - """After a test case triggered errors/warnings on purpose, add - those to our 'observed' list so the do not get reported as 'missed'. - """ - self._last_errors = [] - self._last_warnings = [] - if os.path.isfile(self._path): - with open(self._path) as fd: - fd.seek(self._last_pos, os.SEEK_SET) - for line in fd: - if self._is_ignored(line): + if m and self._lookup_lognos(line, lognos_set): + self._caught_warnings.add(line) continue m = self.RE_ERRLOG_ERROR.match(line) - if m and m.group('module') not in self._ignored_modules: - self._observed_erros.add(line) + if m and self._lookup_lognos(line, lognos_set): + self._caught_errors.add(line) continue - m = self.RE_ERRLOG_WARN.match(line) - if m: - if m and m.group('module') not in self._ignored_modules: - self._observed_warnings.add(line) - continue - self._last_pos = fd.tell() + self._recent_pos = fd.tell() def get_missed(self) -> Tuple[List[str], List[str]]: errors = [] warnings = [] + self._recent_errors = [] + self._recent_warnings = [] if os.path.isfile(self._path): with open(self._path) as fd: fd.seek(self._start_pos, os.SEEK_SET) for line in fd: if self._is_ignored(line): continue + if line in self._caught_matches: + continue + m = self.RE_ERRLOG_WARN.match(line) + if m and line not in self._caught_warnings: + warnings.append(line) + continue m = self.RE_ERRLOG_ERROR.match(line) - if m and m.group('module') not in self._ignored_modules \ - and line not in self._observed_erros: + if m and line not in self._caught_errors: errors.append(line) continue - m = self.RE_ERRLOG_WARN.match(line) - if m: - if m and m.group('module') not in self._ignored_modules \ - and line not in self._observed_warnings: - warnings.append(line) - continue + self._start_pos = self._recent_pos = fd.tell() + self._caught_errors = set() + self._caught_warnings = set() + self._caught_matches = set() return errors, warnings - def scan_recent(self, pattern: re, timeout=10): + def scan_recent(self, pattern: re.Pattern, timeout=10): if not os.path.isfile(self.path): return False with open(self.path) as fd: end = datetime.now() + timedelta(seconds=timeout) while True: - fd.seek(self._last_pos, os.SEEK_SET) + fd.seek(self._recent_pos, os.SEEK_SET) for line in fd: if pattern.match(line): return True