diff options
Diffstat (limited to 'reg-tests/log')
-rw-r--r-- | reg-tests/log/last_rule.vtc | 165 | ||||
-rw-r--r-- | reg-tests/log/load_balancing.vtc | 159 | ||||
-rw-r--r-- | reg-tests/log/log_backend.vtc | 185 | ||||
-rw-r--r-- | reg-tests/log/log_forward.vtc | 57 | ||||
-rw-r--r-- | reg-tests/log/log_uri.vtc | 61 | ||||
-rw-r--r-- | reg-tests/log/wrong_ip_port_logging.vtc | 62 |
6 files changed, 689 insertions, 0 deletions
diff --git a/reg-tests/log/last_rule.vtc b/reg-tests/log/last_rule.vtc new file mode 100644 index 0000000..f2b89e4 --- /dev/null +++ b/reg-tests/log/last_rule.vtc @@ -0,0 +1,165 @@ +varnishtest "Verify logging of last final rule" + +feature cmd "$HAPROXY_PROGRAM -cc 'version_atleast(2.6-dev0)'" +feature ignore_unknown_macro + +server s1 { + rxreq + txresp +} -repeat 15 -start + +syslog Slg_1 -level info { + recv + # /trqacc1 + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:30" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:31" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:32" + recv + # /trsacc1 + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:36" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:37" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:38" + recv + # /hrqvar + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*-:-" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:41" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:42" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:43" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:44" + recv + # /hrsacc1 + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:46" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:47" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:48" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* lr=.*/h1/cfg:49" +} -start + +haproxy h1 -conf { + global + nbthread 1 + + defaults + mode http + option httplog + option http-server-close + timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" + timeout client "${HAPROXY_TEST_TIMEOUT-5s}" + timeout server "${HAPROXY_TEST_TIMEOUT-5s}" + + frontend fe1 + bind "fd@${fe_1}" + log ${Slg_1_addr}:${Slg_1_port} local0 + log-format "ci:%cp [%tr] lr=%[last_rule_file]:%[last_rule_line]" + default_backend be + + backend be + # handle these URLs: + # /trqacc1, /trqrej1, /trqrej2, /trsacc1, /trsrej1, /trsrej2 + # /hrqvar, /hrqacc1, /hrqred1, /hrqrej1, /hrqrej2, + # /hrsacc1, /hrsred1, /hrsrej1, /hrsrej2 + + tcp-response inspect-delay 100ms + tcp-request content set-var(txn.path) path # must have no effect + tcp-request content accept if { var(txn.path) -m beg /trqacc1 /hrqrej1 } + tcp-request content reject if { var(txn.path) -m beg /trqrej1 } + tcp-request content reject if { var(txn.path) -m beg /trqrej2 } + + tcp-response content reject unless WAIT_END + tcp-response content set-var(txn.foo) var(txn.path) # must have no effect + tcp-response content accept if { var(txn.path) -m beg /trsacc1 /hrsrej1 } + tcp-response content reject if { var(txn.path) -m beg /trsrej1 } + tcp-response content reject if { var(txn.path) -m beg /trsrej2 } + + http-request set-var(txn.bar) var(txn.path) if { path_beg /hrqvar } # must have no effect + http-request allow if { var(txn.path) -m beg /hrqacc1 /hrsrej2 } + http-request redirect location / if { var(txn.path) -m beg /hrqred1 } + http-request deny if { var(txn.path) -m beg /hrqrej1 } # accepted by tcp-rq above + http-request deny if { var(txn.path) -m beg /hrqrej2 } + + http-response allow if { var(txn.path) -m beg /hrsacc1 } + http-response redirect location / if { var(txn.path) -m beg /hrsred1 } + http-response deny if { var(txn.path) -m beg /hrsrej1 } # accepted by tcp-rs above + http-response deny if { var(txn.path) -m beg /hrsrej2 } # accepted by http-rq above + http-response deny if { var(txn.path) -m beg /hrsrej3 } + + server app1 ${s1_addr}:${s1_port} +} -start + +client c1 -connect ${h1_fe_1_sock} { + txreq -url /trqacc1 + rxresp + + txreq -url /trqrej1 + expect_close +} -run + +# The following client are started in background and synchronized +client c2 -connect ${h1_fe_1_sock} { + txreq -url /trqrej2 + expect_close +} -run + +client c3 -connect ${h1_fe_1_sock} { + txreq -url /trsacc1 + rxresp + expect resp.status == 200 + + txreq -url /trsrej1 + expect_close +} -run + +client c4 -connect ${h1_fe_1_sock} { + txreq -url /trsrej2 + expect_close +} -run + +client c5 -connect ${h1_fe_1_sock} { + txreq -url /hrqvar + rxresp + expect resp.status == 200 + + txreq -url /hrqacc1 + rxresp + expect resp.status == 200 + + txreq -url /hrqred1 + rxresp + expect resp.status == 302 + + txreq -url /hrqrej1 + rxresp + expect resp.status == 403 + + txreq -url /hrqrej2 + rxresp + expect resp.status == 403 + + txreq -url /hrsacc1 + rxresp + expect resp.status == 200 + + txreq -url /hrsred1 + rxresp + expect resp.status == 302 + + txreq -url /hrsrej1 + rxresp + expect resp.status == 502 + + txreq -url /hrsrej2 + rxresp + expect resp.status == 502 +} -run + +syslog Slg_1 -wait diff --git a/reg-tests/log/load_balancing.vtc b/reg-tests/log/load_balancing.vtc new file mode 100644 index 0000000..5c56e65 --- /dev/null +++ b/reg-tests/log/load_balancing.vtc @@ -0,0 +1,159 @@ +varnishtest "Basic log load-balancing test" +feature ignore_unknown_macro + +barrier b1 cond 2 -cyclic +barrier b2 cond 2 -cyclic +barrier b3 cond 2 -cyclic +barrier b4 cond 2 -cyclic +barrier b5 cond 2 -cyclic + +server s1 { + rxreq + txresp +} -repeat 500 -start + +syslog Slg_1 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c1 HTTP/1.1\"" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c2 HTTP/1.1\"" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c3 HTTP/1.1\"" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c4 HTTP/1.1\"" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c5 HTTP/1.1\"" +} -repeat 50 -start + +# Here are the syslog messages received by Slg_2: +syslog Slg_2 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c6 HTTP/1.1\"" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c8 HTTP/1.1\"" +} -repeat 50 -start + +haproxy h1 -conf { + global + nbthread 1 + + defaults + mode http + option httplog + timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" + timeout client "${HAPROXY_TEST_TIMEOUT-5s}" + timeout server "${HAPROXY_TEST_TIMEOUT-5s}" + + frontend fe1 + bind "fd@${fe_1}" + log ${Slg_1_addr}:${Slg_1_port} local0 + default_backend be + + frontend fe2 + bind "fd@${fe_2}" + log ${Slg_2_addr}:${Slg_2_port} sample 1,3:5 local0 + default_backend be + + backend be + server app1 ${s1_addr}:${s1_port} +} -start + +# The following client are started in background and synchronized +client c1 -connect ${h1_fe_1_sock} { + txreq -url "/client_c1" + rxresp + expect resp.status == 200 + barrier b1 sync + barrier b5 sync +} -repeat 50 -start + +client c2 -connect ${h1_fe_1_sock} { + barrier b1 sync + txreq -url "/client_c2" + rxresp + expect resp.status == 200 + barrier b2 sync +} -repeat 50 -start + +client c3 -connect ${h1_fe_1_sock} { + barrier b2 sync + txreq -url "/client_c3" + rxresp + expect resp.status == 200 + barrier b3 sync +} -repeat 50 -start + +client c4 -connect ${h1_fe_1_sock} { + barrier b3 sync + txreq -url "/client_c4" + rxresp + expect resp.status == 200 + barrier b4 sync +} -repeat 50 -start + +client c5 -connect ${h1_fe_1_sock} { + barrier b4 sync + txreq -url "/client_c5" + rxresp + expect resp.status == 200 + barrier b5 sync +} -repeat 50 -start + +syslog Slg_1 -wait + +client c1 -wait +client c2 -wait +client c3 -wait +client c4 -wait +client c5 -wait + +# Same test as before but with fe2 frontend. +# The following client are started in background and synchronized +client c6 -connect ${h1_fe_2_sock} { + txreq -url "/client_c6" + rxresp + expect resp.status == 200 + barrier b1 sync + barrier b5 sync +} -repeat 50 -start + +client c7 -connect ${h1_fe_2_sock} { + barrier b1 sync + txreq -url "/client_c7" + rxresp + expect resp.status == 200 + barrier b2 sync +} -repeat 50 -start + +client c8 -connect ${h1_fe_2_sock} { + barrier b2 sync + txreq -url "/client_c8" + rxresp + expect resp.status == 200 + barrier b3 sync +} -repeat 50 -start + +client c9 -connect ${h1_fe_2_sock} { + barrier b3 sync + txreq -url "/client_c9" + rxresp + expect resp.status == 200 + barrier b4 sync +} -repeat 50 -start + +client c10 -connect ${h1_fe_2_sock} { + barrier b4 sync + txreq -url "/client_c10" + rxresp + expect resp.status == 200 + barrier b5 sync +} -repeat 50 -start + +syslog Slg_2 -wait + +client c6 -wait +client c7 -wait +client c8 -wait +client c9 -wait +client c10 -wait + diff --git a/reg-tests/log/log_backend.vtc b/reg-tests/log/log_backend.vtc new file mode 100644 index 0000000..a9223ee --- /dev/null +++ b/reg-tests/log/log_backend.vtc @@ -0,0 +1,185 @@ +varnishtest "Test the log backend target" +feature cmd "$HAPROXY_PROGRAM -cc 'version_atleast(2.9-dev0)'" +feature ignore_unknown_macro + +server s1 { + rxreq + txresp +} -repeat 500 -start + +syslog Slg1 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /0 HTTP/1.1\"" +} -repeat 100 -start + +syslog Slg2 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /1 HTTP/1.1\"" +} -repeat 100 -start + +syslog Slg21 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /srv1 HTTP/1.1\"" +} -repeat 1 -start + +syslog Slg22 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /srv2 HTTP/1.1\"" +} -repeat 1 -start + +syslog Slg23 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /srv3 HTTP/1.1\"" +} -repeat 2 -start + +syslog Slg24 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /backup HTTP/1.1\"" +} -repeat 1 -start + +haproxy h1 -conf { + defaults + mode http + option httplog + timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" + timeout client "${HAPROXY_TEST_TIMEOUT-5s}" + timeout server "${HAPROXY_TEST_TIMEOUT-5s}" + + frontend fe1 + bind "fd@${fe_1}" + log backend@mylog-tcp local0 + log backend@mylog-udp local0 + default_backend be + + frontend fe2 + bind "fd@${fe_2}" + log backend@mylog-failover local0 + default_backend be + + backend be + server app1 ${s1_addr}:${s1_port} + + backend mylog-tcp + mode log + server s1 tcp@127.0.0.1:1514 #TCP: to log-forward + + backend mylog-udp + mode log + + # extract id (integer) from URL in the form "GET /id" and use it as hash key + balance log-hash 'field(-2,\"),field(2,/),field(1, )' + hash-type map-based none + + server s1 udp@${Slg1_addr}:${Slg1_port} # syslog 1 only receives "GET /0" requests + server s2 udp@${Slg2_addr}:${Slg2_port} # syslog 2 only receives "GET /1" requests + + log-forward syslog2udp + bind 127.0.0.1:1514 + log backend@mylog-udp local0 # Back to UDP log backend + + backend mylog-failover + mode log + balance sticky + + server s1 udp@${Slg21_addr}:${Slg21_port} # only receives "GET /srv1" request + server s2 udp@${Slg22_addr}:${Slg22_port} # only receives "GET /srv2" request + server s3 udp@${Slg23_addr}:${Slg23_port} # only receives "GET /srv3" request + + server s4 udp@${Slg24_addr}:${Slg24_port} backup # only receives "GET /backup" request +} -start + +# Test log distribution reliability + +# all logs should go to s1 +client c1 -connect ${h1_fe_1_sock} { + txreq -url "/0" + rxresp + expect resp.status == 200 +} -repeat 50 -start + +# all logs should go to s2 +client c2 -connect ${h1_fe_1_sock} { + txreq -url "/1" + rxresp + expect resp.status == 200 +} -repeat 50 -start + +syslog Slg1 -wait +syslog Slg2 -wait + +# Test server queue/dequeue/failover mechanism + +# s1 should handle this +client c21 -connect ${h1_fe_2_sock} { + txreq -url "/srv1" + rxresp + expect resp.status == 200 +} -run + +haproxy h1 -cli { + send "disable server mylog-failover/s1" + expect ~ ".*" +} + +# s2 should handle this +client c22 -connect ${h1_fe_2_sock} { + txreq -url "/srv2" + rxresp + expect resp.status == 200 +} -run + +haproxy h1 -cli { + send "disable server mylog-failover/s2" + expect ~ ".*" +} + +haproxy h1 -cli { + send "enable server mylog-failover/s1" + expect ~ ".*" +} + +# s3 should handle this +client c23 -connect ${h1_fe_2_sock} { + txreq -url "/srv3" + rxresp + expect resp.status == 200 +} -run + +haproxy h1 -cli { + send "disable server mylog-failover/s1" + expect ~ ".*" +} + +haproxy h1 -cli { + send "disable server mylog-failover/s3" + expect ~ ".*" +} + +# backup should handle this +client c24 -connect ${h1_fe_2_sock} { + txreq -url "/backup" + rxresp + expect resp.status == 200 +} -run + +haproxy h1 -cli { + send "enable server mylog-failover/s3" + expect ~ ".*" +} + +haproxy h1 -cli { + send "enable server mylog-failover/s2" + expect ~ ".*" +} + +# s3 should handle this +client c25 -connect ${h1_fe_2_sock} { + txreq -url "/srv3" + rxresp + expect resp.status == 200 +} -run + +syslog Slg21 -wait +syslog Slg22 -wait +syslog Slg23 -wait +syslog Slg24 -wait diff --git a/reg-tests/log/log_forward.vtc b/reg-tests/log/log_forward.vtc new file mode 100644 index 0000000..3977f4c --- /dev/null +++ b/reg-tests/log/log_forward.vtc @@ -0,0 +1,57 @@ +varnishtest "Test the TCP load-forward" +feature cmd "$HAPROXY_PROGRAM -cc 'version_atleast(2.3-dev1)'" +feature ignore_unknown_macro + +server s1 { + rxreq + txresp +} -repeat 500 -start + +syslog Slg1 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* \"GET /client_c1 HTTP/1.1\"" +} -repeat 50 -start + +haproxy h1 -conf { + defaults + mode http + option httplog + timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" + timeout client "${HAPROXY_TEST_TIMEOUT-5s}" + timeout server "${HAPROXY_TEST_TIMEOUT-5s}" + + frontend fe1 + bind "fd@${fe_1}" + log 127.0.0.1:1514 local0 +# log ${Slg1_addr}:${Slg1_port} local0 + default_backend be + + backend be + server app1 ${s1_addr}:${s1_port} + + ring myring + description "My local buffer" + format rfc5424 + maxlen 1200 + size 32764 + timeout connect 5s + timeout server 10s + # syslog tcp server + server mysyslogsrv 127.0.0.1:2514 + + log-forward syslog2tcp + dgram-bind 127.0.0.1:1514 + log ring@myring local0 # To TCP log + + log-forward syslog2local + bind 127.0.0.1:2514 + log ${Slg1_addr}:${Slg1_port} local0 # To VTest syslog +} -start + +client c1 -connect ${h1_fe_1_sock} { + txreq -url "/client_c1" + rxresp + expect resp.status == 200 +} -repeat 50 -start + +syslog Slg1 -wait diff --git a/reg-tests/log/log_uri.vtc b/reg-tests/log/log_uri.vtc new file mode 100644 index 0000000..6dd50d2 --- /dev/null +++ b/reg-tests/log/log_uri.vtc @@ -0,0 +1,61 @@ +varnishtest "Verify logging of relative/absolute URI path" +feature ignore_unknown_macro + +#REQUIRE_VERSION=2.4 + +server s1 { + rxreq + txresp -hdr "Connection: close" +} -repeat 4 -start + +syslog Slg_1 -level info { + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* hpo=/r/1 hp=/r/1 hu=/r/1 hq=" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* hpo=/r/2 hp=/r/2 hu=/r/2\\?q=2 hq=\\?q=2" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* hpo=/r/3 hp=http://localhost/r/3 hu=http://localhost/r/3 hq=" + recv + expect ~ "[^:\\[ ]\\[${h1_pid}\\]: .* hpo=/r/4 hp=http://localhost/r/4 hu=http://localhost/r/4\\?q=4 hq=\\?q=4" +} -start + +haproxy h1 -conf { + global + nbthread 1 + + defaults + mode http + option httplog + timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" + timeout client "${HAPROXY_TEST_TIMEOUT-5s}" + timeout server "${HAPROXY_TEST_TIMEOUT-5s}" + + frontend fe1 + bind "fd@${fe_1}" + log ${Slg_1_addr}:${Slg_1_port} local0 + log-format "ci:%cp [%tr] hpo=%HPO hp=%HP hu=%HU hq=%HQ" + default_backend be + + backend be + server app1 ${s1_addr}:${s1_port} +} -start + +# The following client are started in background and synchronized +client c1 -connect ${h1_fe_1_sock} { + txreq -url "/r/1" + rxresp + expect resp.status == 200 + txreq -url "/r/2?q=2" + rxresp + expect resp.status == 200 + txreq -url "http://localhost/r/3" -hdr "host: localhost" + rxresp + expect resp.status == 200 + txreq -url "http://localhost/r/4?q=4" -hdr "host: localhost" + rxresp + expect resp.status == 200 +} -start + +syslog Slg_1 -wait + +client c1 -wait diff --git a/reg-tests/log/wrong_ip_port_logging.vtc b/reg-tests/log/wrong_ip_port_logging.vtc new file mode 100644 index 0000000..af8ca84 --- /dev/null +++ b/reg-tests/log/wrong_ip_port_logging.vtc @@ -0,0 +1,62 @@ +# commit d02286d +# BUG/MINOR: log: pin the front connection when front ip/ports are logged +# +# Mathias Weiersmueller reported an interesting issue with logs which Lukas +# diagnosed as dating back from commit 9b061e332 (1.5-dev9). When front +# connection information (ip, port) are logged in TCP mode and the log is +# emitted at the end of the connection (eg: because %B or any log tag +# requiring LW_BYTES is set), the log is emitted after the connection is +# closed, so the address and ports cannot be retrieved anymore. +# +# It could be argued that we'd make a special case of these to immediately +# retrieve the source and destination addresses from the connection, but it +# seems cleaner to simply pin the front connection, marking it "tracked" by +# adding the LW_XPRT flag to mention that we'll need some of these elements +# at the last moment. Only LW_FRTIP and LW_CLIP are affected. Note that after +# this change, LW_FRTIP could simply be removed as it's not used anywhere. +# +# Note that the problem doesn't happen when using %[src] or %[dst] since +# all sample expressions set LW_XPRT. + +#REGTEST_TYPE=bug + +varnishtest "Wrong ip/port logging" +feature ignore_unknown_macro + +server s1 { + rxreq + delay 0.02 +} -start + +syslog Slg_1 -level notice { + recv info + expect ~ \"dip\":\"${h1_fe_1_addr}\",\"dport\":\"${h1_fe_1_port}.*\"ts\":\"[cC]D\",\" +} -start + +haproxy h1 -conf { + global + log ${Slg_1_addr}:${Slg_1_port} local0 + +defaults + log global + timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" + timeout client 1 + timeout server "${HAPROXY_TEST_TIMEOUT-5s}" + +frontend fe1 + bind "fd@${fe_1}" + mode tcp + log-format {\"dip\":\"%fi\",\"dport\":\"%fp\",\"c_ip\":\"%ci\",\"c_port\":\"%cp\",\"fe_name\":\"%ft\",\"be_name\":\"%b\",\"s_name\":\"%s\",\"ts\":\"%ts\",\"bytes_read\":\"%B\"} + default_backend be_app + +backend be_app + server app1 ${s1_addr}:${s1_port} +} -start + +client c1 -connect ${h1_fe_1_sock} { + txreq -url "/" + expect_close +} -run + +syslog Slg_1 -wait + |