blob: af8ca8486828abd47b62988f683814a35a3ece4d [file] [log] [blame]
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +02001# 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 Herlantec4abde2018-11-13 20:15:49 -080011# It could be argued that we'd make a special case of these to immediately
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020012# 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écailledc1a3bd2019-03-29 15:07:24 +010021#REGTEST_TYPE=bug
22
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020023varnishtest "Wrong ip/port logging"
24feature ignore_unknown_macro
25
26server s1 {
27 rxreq
Christopher Faulet0dc100b2019-04-01 15:33:19 +020028 delay 0.02
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020029} -start
30
31syslog Slg_1 -level notice {
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020032 recv info
Willy Tarreauf95838c2018-10-28 19:19:48 +010033 expect ~ \"dip\":\"${h1_fe_1_addr}\",\"dport\":\"${h1_fe_1_port}.*\"ts\":\"[cC]D\",\"
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020034} -start
35
36haproxy h1 -conf {
37 global
38 log ${Slg_1_addr}:${Slg_1_port} local0
39
40defaults
41 log global
Willy Tarreauf6739232021-11-18 17:46:22 +010042 timeout connect "${HAPROXY_TEST_TIMEOUT-5s}"
Willy Tarreauf95838c2018-10-28 19:19:48 +010043 timeout client 1
Willy Tarreauf6739232021-11-18 17:46:22 +010044 timeout server "${HAPROXY_TEST_TIMEOUT-5s}"
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020045
46frontend 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
52backend be_app
PiBa-NLfefb9e32018-12-08 21:36:55 +010053 server app1 ${s1_addr}:${s1_port}
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020054} -start
55
56client c1 -connect ${h1_fe_1_sock} {
57 txreq -url "/"
Frédéric Lécaille5dfdd4a2019-05-07 12:00:36 +020058 expect_close
Frédéric Lécaille9b53b4c2018-06-20 07:26:44 +020059} -run
60
61syslog Slg_1 -wait
62