blob: ae46ea114ed1801f69578945bcfa91ce2dd2fcd9 [file] [log] [blame]
Frédéric Lécailleb083c832018-08-23 18:06:35 +02001# commit 7b6cc52784526c32efda44b873a4258d3ae0b8c7
2# BUG/MINOR: lua: Bad HTTP client request duration.
3#
4# HTTP LUA applet callback should not update the date on which the HTTP client requests
5# arrive. This was done just after the LUA applet has completed its job.
6#
Ilya Shipitsin47d17182020-06-21 21:42:57 +05007# This patch simply removes the affected statement. The same fix has been applied
Frédéric Lécailleb083c832018-08-23 18:06:35 +02008# to TCP LUA applet callback.
9#
10# To reproduce this issue, as reported by Patrick Hemmer, implement an HTTP LUA applet
11# which sleeps a bit before replying:
12#
13# core.register_service("foo", "http", function(applet)
14# core.msleep(100)
15# applet:set_status(200)
16# applet:start_response()
17# end)
18#
19# This had as a consequence to log %TR field with approximatively the same value as
20# the LUA sleep time.
21
22varnishtest "LUA bug"
Christopher Fauletfdafd9a2018-12-19 11:50:17 +010023#REQUIRE_OPTIONS=LUA
Frédéric Lécailledc1a3bd2019-03-29 15:07:24 +010024#REGTEST_TYPE=bug
Frédéric Lécailleb083c832018-08-23 18:06:35 +020025
26feature ignore_unknown_macro
27
28syslog Slog {
29 recv notice
Willy Tarreau9c27ea02018-11-16 15:54:23 +010030 expect ~ "[^:\\[ ]*\\[[0-9]*\\]: Proxy f1 started"
Frédéric Lécailleb083c832018-08-23 18:06:35 +020031
32 recv notice
Willy Tarreau9c27ea02018-11-16 15:54:23 +010033 expect ~ "[^:\\[ ]\\[[0-9]*\\]: Proxy f2 started"
Frédéric Lécailleb083c832018-08-23 18:06:35 +020034
35 recv info
Willy Tarreau9c27ea02018-11-16 15:54:23 +010036 expect ~ "[^:\\[ ]\\[[0-9]*\\]: Ta=[0-9]* Tc=[0-9]* Td=[0-9]* Th=[0-9]* Ti=[0-9]* Tq=[0-9]* TR=[0-9]* Tr=[0-9]* Tt=[0-9]* Tw=[0-9]*$"
Frédéric Lécailleb083c832018-08-23 18:06:35 +020037
38 recv info
Willy Tarreau9c27ea02018-11-16 15:54:23 +010039 expect ~ "[^:\\[ ]\\[[0-9]*\\]: Tc=[0-9]* Td=[0-9]* Th=[0-9]* Tt=[0-9]* Tw=[0-9]*$"
Frédéric Lécailleb083c832018-08-23 18:06:35 +020040} -start
41
42haproxy h1 -conf {
43 global
Frédéric Lécailleb894f922019-03-29 16:13:48 +010044 lua-load ${testdir}/bad_http_clt_req_duration.lua
Frédéric Lécailleb083c832018-08-23 18:06:35 +020045
46 defaults
47 timeout client 1s
48 timeout server 1s
49 timeout connect 1s
50
51 frontend f1
52 mode http
Christopher Faulet8f161482018-12-19 11:49:39 +010053 ${no-htx} option http-use-htx
Frédéric Lécailleb083c832018-08-23 18:06:35 +020054 bind "fd@${f1}"
55 log ${Slog_addr}:${Slog_port} daemon
56 log-format Ta=%Ta\ Tc=%Tc\ Td=%Td\ Th=%Th\ Ti=%Ti\ Tq=%Tq\ TR=%TR\ Tr=%Tr\ Tt=%Tt\ Tw=%Tw
57 default_backend b1
58
59 backend b1
60 mode http
Christopher Faulet8f161482018-12-19 11:49:39 +010061 ${no-htx} option http-use-htx
Frédéric Lécailleb083c832018-08-23 18:06:35 +020062 http-request use-service lua.foo.http
63
64 frontend f2
65 mode tcp
66 bind "fd@${f2}"
67 log ${Slog_addr}:${Slog_port} daemon
68 log-format Tc=%Tc\ Td=%Td\ Th=%Th\ Tt=%Tt\ Tw=%Tw
69
70 tcp-request inspect-delay 1s
71 tcp-request content use-service lua.foo.tcp
72} -start
73
74client c1 -connect "${h1_f1_sock}" {
75 txreq
76 rxresp
77} -run
78
79client c2 -connect "${h1_f2_sock}" {
80 txreq
81 rxresp
82} -run
83
84syslog Slog -wait