Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 1 | # commit d02286d |
| 2 | # BUG/MINOR: log: pin the front connection when front ip/ports are logged |
| 3 | # |
| 4 | # Mathias Weiersmueller reported an interesting issue with logs which Lukas |
| 5 | # diagnosed as dating back from commit 9b061e332 (1.5-dev9). When front |
| 6 | # connection information (ip, port) are logged in TCP mode and the log is |
| 7 | # emitted at the end of the connection (eg: because %B or any log tag |
| 8 | # requiring LW_BYTES is set), the log is emitted after the connection is |
| 9 | # closed, so the address and ports cannot be retrieved anymore. |
| 10 | # |
Joseph Herlant | ec4abde | 2018-11-13 20:15:49 -0800 | [diff] [blame] | 11 | # It could be argued that we'd make a special case of these to immediately |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 12 | # retrieve the source and destination addresses from the connection, but it |
| 13 | # seems cleaner to simply pin the front connection, marking it "tracked" by |
| 14 | # adding the LW_XPRT flag to mention that we'll need some of these elements |
| 15 | # at the last moment. Only LW_FRTIP and LW_CLIP are affected. Note that after |
| 16 | # this change, LW_FRTIP could simply be removed as it's not used anywhere. |
| 17 | # |
| 18 | # Note that the problem doesn't happen when using %[src] or %[dst] since |
| 19 | # all sample expressions set LW_XPRT. |
| 20 | |
Frédéric Lécaille | dc1a3bd | 2019-03-29 15:07:24 +0100 | [diff] [blame] | 21 | #REGTEST_TYPE=bug |
| 22 | |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 23 | varnishtest "Wrong ip/port logging" |
| 24 | feature ignore_unknown_macro |
| 25 | |
| 26 | server s1 { |
| 27 | rxreq |
Christopher Faulet | 0dc100b | 2019-04-01 15:33:19 +0200 | [diff] [blame] | 28 | delay 0.02 |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 29 | } -start |
| 30 | |
| 31 | syslog Slg_1 -level notice { |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 32 | recv info |
Willy Tarreau | f95838c | 2018-10-28 19:19:48 +0100 | [diff] [blame] | 33 | expect ~ \"dip\":\"${h1_fe_1_addr}\",\"dport\":\"${h1_fe_1_port}.*\"ts\":\"[cC]D\",\" |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 34 | } -start |
| 35 | |
| 36 | haproxy h1 -conf { |
| 37 | global |
| 38 | log ${Slg_1_addr}:${Slg_1_port} local0 |
| 39 | |
| 40 | defaults |
| 41 | log global |
Willy Tarreau | f673923 | 2021-11-18 17:46:22 +0100 | [diff] [blame^] | 42 | timeout connect "${HAPROXY_TEST_TIMEOUT-5s}" |
Willy Tarreau | f95838c | 2018-10-28 19:19:48 +0100 | [diff] [blame] | 43 | timeout client 1 |
Willy Tarreau | f673923 | 2021-11-18 17:46:22 +0100 | [diff] [blame^] | 44 | timeout server "${HAPROXY_TEST_TIMEOUT-5s}" |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 45 | |
| 46 | frontend fe1 |
| 47 | bind "fd@${fe_1}" |
| 48 | mode tcp |
| 49 | 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\"} |
| 50 | default_backend be_app |
| 51 | |
| 52 | backend be_app |
PiBa-NL | fefb9e3 | 2018-12-08 21:36:55 +0100 | [diff] [blame] | 53 | server app1 ${s1_addr}:${s1_port} |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 54 | } -start |
| 55 | |
| 56 | client c1 -connect ${h1_fe_1_sock} { |
| 57 | txreq -url "/" |
Frédéric Lécaille | 5dfdd4a | 2019-05-07 12:00:36 +0200 | [diff] [blame] | 58 | expect_close |
Frédéric Lécaille | 9b53b4c | 2018-06-20 07:26:44 +0200 | [diff] [blame] | 59 | } -run |
| 60 | |
| 61 | syslog Slg_1 -wait |
| 62 | |