Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 1 | # 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 | # |
| 7 | # This patch simply removes the affected statement. The same fixe has been applied |
| 8 | # 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 | |
| 22 | varnishtest "LUA bug" |
Christopher Faulet | fdafd9a | 2018-12-19 11:50:17 +0100 | [diff] [blame] | 23 | #REQUIRE_OPTIONS=LUA |
Frédéric Lécaille | dc1a3bd | 2019-03-29 15:07:24 +0100 | [diff] [blame] | 24 | #REGTEST_TYPE=bug |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 25 | |
| 26 | feature ignore_unknown_macro |
| 27 | |
| 28 | syslog Slog { |
| 29 | recv notice |
Willy Tarreau | 9c27ea0 | 2018-11-16 15:54:23 +0100 | [diff] [blame] | 30 | expect ~ "[^:\\[ ]*\\[[0-9]*\\]: Proxy f1 started" |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 31 | |
| 32 | recv notice |
Willy Tarreau | 9c27ea0 | 2018-11-16 15:54:23 +0100 | [diff] [blame] | 33 | expect ~ "[^:\\[ ]\\[[0-9]*\\]: Proxy f2 started" |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 34 | |
| 35 | recv info |
Willy Tarreau | 9c27ea0 | 2018-11-16 15:54:23 +0100 | [diff] [blame] | 36 | 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écaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 37 | |
| 38 | recv info |
Willy Tarreau | 9c27ea0 | 2018-11-16 15:54:23 +0100 | [diff] [blame] | 39 | expect ~ "[^:\\[ ]\\[[0-9]*\\]: Tc=[0-9]* Td=[0-9]* Th=[0-9]* Tt=[0-9]* Tw=[0-9]*$" |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 40 | } -start |
| 41 | |
| 42 | haproxy h1 -conf { |
| 43 | global |
Frédéric Lécaille | b894f92 | 2019-03-29 16:13:48 +0100 | [diff] [blame] | 44 | lua-load ${testdir}/bad_http_clt_req_duration.lua |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 45 | |
| 46 | defaults |
| 47 | timeout client 1s |
| 48 | timeout server 1s |
| 49 | timeout connect 1s |
| 50 | |
| 51 | frontend f1 |
| 52 | mode http |
Christopher Faulet | 8f16148 | 2018-12-19 11:49:39 +0100 | [diff] [blame] | 53 | ${no-htx} option http-use-htx |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 54 | 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 Faulet | 8f16148 | 2018-12-19 11:49:39 +0100 | [diff] [blame] | 61 | ${no-htx} option http-use-htx |
Frédéric Lécaille | b083c83 | 2018-08-23 18:06:35 +0200 | [diff] [blame] | 62 | 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 | |
| 74 | client c1 -connect "${h1_f1_sock}" { |
| 75 | txreq |
| 76 | rxresp |
| 77 | } -run |
| 78 | |
| 79 | client c2 -connect "${h1_f2_sock}" { |
| 80 | txreq |
| 81 | rxresp |
| 82 | } -run |
| 83 | |
| 84 | syslog Slog -wait |