Re: BUG: Tw is negative with lua sleep
> On 22 Aug 2018, at 06:00, Patrick Hemmer wrote:
>
>
>
> On 2018/7/18 09:03, Frederic Lecaille wrote:
>> Hello Patrick,
>>
>> On 07/17/2018 03:59 PM, Patrick Hemmer wrote:
>>> Ping?
>>>
>>> -Patrick
>>>
>>> On 2018/6/22 15:10, Patrick Hemmer wrote:
When using core.msleep in lua, the %Tw metric is a negative value.
For example with the following config:
haproxy.cfg:
global
lua-load /tmp/haproxy.lua
frontend f1
mode http
bind :8000
default_backend b1
log 127.0.0.1:1234 daemon
log-format Ta=%Ta\ Tc=%Tc\ Td=%Td\ Th=%Th\ Ti=%Ti\ Tq=%Tq\
TR=%TR\ Tr=%Tr\ Tt=%Tt\ Tw=%Tw
backend b1
mode http
http-request use-service lua.foo
haproxy.lua:
core.register_service("foo", "http", function(applet)
core.msleep(100)
applet:set_status(200)
applet:start_response()
end)
The log contains:
Ta=104 Tc=0 Td=0 Th=0 Ti=0 Tq=104 TR=104 Tr=104 Tt=104 Tw=-104
^ TR also looks wrong, as it did not take 104ms to receive the full
request.
This is built from the commit before current master: d8fd2af
-Patrick
>>>
>>
>> The patch attached to this mail fixes this issue at least for %TR field.
>>
>> But I am not sure at all it is correct or if there is no remaining issues.
>> For instance the LUA tcp callback also updates the tv_request log field.
>>
>> So, let's wait for Thierry's validation.
Hi,
Applets should be considered as server independent from HAProxy, so applet
should not
change HAProxy information like log times.
I guess that your patch works, and the function hlua_applet_tcp_fct() should
follow
the same way.
unfortunately I do not have free time to test all of this changes.
Thierry
>> Regards.
>>
>
> Any update on this?
>
> -Patrick
>
Re: BUG: Tw is negative with lua sleep
On 2018/7/18 09:03, Frederic Lecaille wrote:
> Hello Patrick,
>
> On 07/17/2018 03:59 PM, Patrick Hemmer wrote:
>> Ping?
>>
>> -Patrick
>>
>> On 2018/6/22 15:10, Patrick Hemmer wrote:
>>> When using core.msleep in lua, the %Tw metric is a negative value.
>>>
>>> For example with the following config:
>>> haproxy.cfg:
>>> global
>>> lua-load /tmp/haproxy.lua
>>>
>>> frontend f1
>>> mode http
>>> bind :8000
>>> default_backend b1
>>> log 127.0.0.1:1234 daemon
>>> log-format Ta=%Ta\ Tc=%Tc\ Td=%Td\ Th=%Th\ Ti=%Ti\
>>> Tq=%Tq\ TR=%TR\ Tr=%Tr\ Tt=%Tt\ Tw=%Tw
>>>
>>> backend b1
>>> mode http
>>> http-request use-service lua.foo
>>>
>>> haproxy.lua:
>>> core.register_service("foo", "http", function(applet)
>>> core.msleep(100)
>>> applet:set_status(200)
>>> applet:start_response()
>>> end)
>>>
>>> The log contains:
>>> Ta=104 Tc=0 Td=0 Th=0 Ti=0 Tq=104 TR=104 Tr=104 Tt=104 Tw=-104
>>>
>>> ^ TR also looks wrong, as it did not take 104ms to receive the full
>>> request.
>>>
>>> This is built from the commit before current master: d8fd2af
>>>
>>> -Patrick
>>
>
> The patch attached to this mail fixes this issue at least for %TR field.
>
> But I am not sure at all it is correct or if there is no remaining
> issues. For instance the LUA tcp callback also updates the tv_request
> log field.
>
> So, let's wait for Thierry's validation.
>
> Regards.
>
Any update on this?
-Patrick
Re: BUG: Tw is negative with lua sleep
Hello Patrick,
On 07/17/2018 03:59 PM, Patrick Hemmer wrote:
Ping?
-Patrick
On 2018/6/22 15:10, Patrick Hemmer wrote:
When using core.msleep in lua, the %Tw metric is a negative value.
For example with the following config:
haproxy.cfg:
global
lua-load /tmp/haproxy.lua
frontend f1
mode http
bind :8000
default_backend b1
log 127.0.0.1:1234 daemon
log-format Ta=%Ta\ Tc=%Tc\ Td=%Td\ Th=%Th\ Ti=%Ti\ Tq=%Tq\
TR=%TR\ Tr=%Tr\ Tt=%Tt\ Tw=%Tw
backend b1
mode http
http-request use-service lua.foo
haproxy.lua:
core.register_service("foo", "http", function(applet)
core.msleep(100)
applet:set_status(200)
applet:start_response()
end)
The log contains:
Ta=104 Tc=0 Td=0 Th=0 Ti=0 Tq=104 TR=104 Tr=104 Tt=104 Tw=-104
^ TR also looks wrong, as it did not take 104ms to receive the full
request.
This is built from the commit before current master: d8fd2af
-Patrick
The patch attached to this mail fixes this issue at least for %TR field.
But I am not sure at all it is correct or if there is no remaining
issues. For instance the LUA tcp callback also updates the tv_request
log field.
So, let's wait for Thierry's validation.
Regards.
>From e9866316cec76430a7b1f1b637e4a680406ec43b Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20L=C3=A9caille?=
Date: Wed, 18 Jul 2018 14:25:26 +0200
Subject: [PATCH] BUG/MINOR: lua: Bad HTTP client request duration.
HTTP LUA callback should not update the date on which the HTTP client requests
arrive. This was done just after the LUA applet has completed its job.
This patch simply removes the affected statement.
To reproduce this issue, as reported by Patrick Hemmer, implement an HTTP LUA applet
which sleeps a bit before replying:
core.register_service("foo", "http", function(applet)
core.msleep(100)
applet:set_status(200)
applet:start_response()
end)
This had as a consequence to log %TR field with approximatively the same value as
the LUA sleep time.
Thank you to Patrick Hemmer for having reported this issue.
Must be backported to 1.8, 1.7 and 1.6.
---
src/hlua.c | 3 +--
1 file changed, 1 insertion(+), 2 deletions(-)
diff --git a/src/hlua.c b/src/hlua.c
index 4715639..f456cd9 100644
--- a/src/hlua.c
+++ b/src/hlua.c
@@ -6750,9 +6750,8 @@ static void hlua_applet_http_fct(struct appctx *ctx)
/* close the connection. */
- /* status / log */
+ /* status */
strm->txn->status = ctx->ctx.hlua_apphttp.status;
- strm->logs.tv_request = now;
/* eat the whole request */
co_skip(si_oc(si), si_ob(si)->o);
--
2.1.4
Re: BUG: Tw is negative with lua sleep
Ping?
-Patrick
On 2018/6/22 15:10, Patrick Hemmer wrote:
> When using core.msleep in lua, the %Tw metric is a negative value.
>
> For example with the following config:
> haproxy.cfg:
> global
> lua-load /tmp/haproxy.lua
>
> frontend f1
> mode http
> bind :8000
> default_backend b1
> log 127.0.0.1:1234 daemon
> log-format Ta=%Ta\ Tc=%Tc\ Td=%Td\ Th=%Th\ Ti=%Ti\ Tq=%Tq\
> TR=%TR\ Tr=%Tr\ Tt=%Tt\ Tw=%Tw
>
> backend b1
> mode http
> http-request use-service lua.foo
>
> haproxy.lua:
> core.register_service("foo", "http", function(applet)
> core.msleep(100)
> applet:set_status(200)
> applet:start_response()
> end)
>
> The log contains:
> Ta=104 Tc=0 Td=0 Th=0 Ti=0 Tq=104 TR=104 Tr=104 Tt=104 Tw=-104
>
> ^ TR also looks wrong, as it did not take 104ms to receive the full
> request.
>
> This is built from the commit before current master: d8fd2af
>
> -Patrick
BUG: Tw is negative with lua sleep
When using core.msleep in lua, the %Tw metric is a negative value.
For example with the following config:
haproxy.cfg:
global
lua-load /tmp/haproxy.lua
frontend f1
mode http
bind :8000
default_backend b1
log 127.0.0.1:1234 daemon
log-format Ta=%Ta\ Tc=%Tc\ Td=%Td\ Th=%Th\ Ti=%Ti\ Tq=%Tq\
TR=%TR\ Tr=%Tr\ Tt=%Tt\ Tw=%Tw
backend b1
mode http
http-request use-service lua.foo
haproxy.lua:
core.register_service("foo", "http", function(applet)
core.msleep(100)
applet:set_status(200)
applet:start_response()
end)
The log contains:
Ta=104 Tc=0 Td=0 Th=0 Ti=0 Tq=104 TR=104 Tr=104 Tt=104 Tw=-104
^ TR also looks wrong, as it did not take 104ms to receive the full request.
This is built from the commit before current master: d8fd2af
-Patrick
