Welcome! Log In Create A New Profile

Advanced

lua socket settimeout has no effect

Posted by Sachin Shetty 
Sachin Shetty
lua socket settimeout has no effect
July 26, 2018 08:00PM
Hi,

We are using a http-req lua action to dynamically set some app specific
metadata headers. The lua handler connects to a upstream memcache like
service over tcp to fetch additional metadata.

Functionally everything works ok, but I am seeing that socket.settimeout
has no effect. Irrespective of what I set in settimeout if the upstream
service is unreachable, connect always timesout at 5 seconds, and read
timeout around 10 seconds. It seems like settimeout has no effect and it
always picks defaults of 5 seconds for connect timeout and 10 seconds for
read timeout.

Haproxy conf call:

http-request lua.get_proxy

Lua code sample:

function get_proxy(txn)
local sock = core.tcp()
sock:settimeout(2)
status, error = sock:connect(gds_host, gds_port)
if not status then
core.Alert("1 Error in connecting:" .. key .. ":" .. error)
return result, "Error: " .. error
end
sock:send(key .. "\r\n")
....
....


core.register_action("get_proxy", { "http-req" }, get_proxy)

Haproxy version:

HA-Proxy version 1.7.8 2017/07/07
Copyright 2000-2017 Willy Tarreau <[email protected]>

Build options :
TARGET = linux2628
CPU = generic
CC = gcc
CFLAGS = -O2 -g -fno-strict-aliasing -Wdeclaration-after-statement
-fwrapv -DTCP_USER_TIMEOUT=18
OPTIONS = USE_LINUX_TPROXY=1 USE_ZLIB=1 USE_REGPARM=1 USE_OPENSSL=1
USE_LUA=1 USE_PCRE=1

Default settings :
maxconn = 2000, bufsize = 16384, maxrewrite = 1024, maxpollevents = 200

Encrypted password support via crypt(3): yes
Built with zlib version : 1.2.7
Running on zlib version : 1.2.7
Compression algorithms supported : identity("identity"),
deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
Built with OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
Running on OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
OpenSSL library supports TLS extensions : yes
OpenSSL library supports SNI : yes
OpenSSL library supports prefer-server-ciphers : yes
Built with PCRE version : 8.32 2012-11-30
Running on PCRE version : 8.32 2012-11-30
PCRE library supports JIT : no (USE_PCRE_JIT not set)
Built with Lua version : Lua 5.3.2
Built with transparent proxy support using: IP_TRANSPARENT IPV6_TRANSPARENT
IP_FREEBIND

Available polling systems :
epoll : pref=300, test result OK
poll : pref=200, test result OK
select : pref=150, test result OK
Total: 3 (3 usable), will use epoll.

Available filters :
[COMP] compression
[TRACE] trace
[SPOE] spoe



Thanks
Sachin
Cyril Bonté
Re: lua socket settimeout has no effect
July 27, 2018 02:00AM
Hi,

Le 26/07/2018 à 19:54, Sachin Shetty a écrit :
> Hi,
>
> We are using a http-req lua action to dynamically set some app specific
> metadata headers. The lua handler connects to a upstream memcache like
> service over tcp to fetch additional metadata.
>
> Functionally everything works ok, but I am seeing that socket.settimeout
> has no effect. Irrespective of what I set in settimeout if the upstream
> service is unreachable, connect always timesout at 5 seconds, and read
> timeout around 10 seconds. It seems like  settimeout has no effect and
> it always picks defaults of 5 seconds for connect timeout and 10 seconds
> for read timeout.

For the connect timeout, it seems this is a hardcoded default value in
src/hlua.c:
socket_proxy.timeout.connect = 5000; /* By default the timeout
connection is 5s. */

If it's possible, can you try the patch attached (for the 1.7.x branch)
? But please don't use it in production yet ;-)

>
> Haproxy conf call:
>
> http-request lua.get_proxy
>
> Lua code sample:
>
> function get_proxy(txn)
>     local sock = core.tcp()
>     sock:settimeout(2)
>     status, error = sock:connect(gds_host, gds_port)
>     if not status then
>         core.Alert("1 Error in connecting:" .. key .. ":" .. error)
>         return result, "Error: " .. error
>     end
>     sock:send(key .. "\r\n")
>     ....
>     ....
>
>
> core.register_action("get_proxy", { "http-req" }, get_proxy)
>
> Haproxy version:
>
> HA-Proxy version 1.7.8 2017/07/07
> Copyright 2000-2017 Willy Tarreau <[email protected]
> <mailto:[email protected]>>
>
> Build options :
>   TARGET  = linux2628
>   CPU     = generic
>   CC      = gcc
>   CFLAGS  = -O2 -g -fno-strict-aliasing -Wdeclaration-after-statement
> -fwrapv -DTCP_USER_TIMEOUT=18
>   OPTIONS = USE_LINUX_TPROXY=1 USE_ZLIB=1 USE_REGPARM=1 USE_OPENSSL=1
> USE_LUA=1 USE_PCRE=1
>
> Default settings :
>   maxconn = 2000, bufsize = 16384, maxrewrite = 1024, maxpollevents = 200
>
> Encrypted password support via crypt(3): yes
> Built with zlib version : 1.2.7
> Running on zlib version : 1.2.7
> Compression algorithms supported : identity("identity"),
> deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
> Built with OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
> Running on OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
> OpenSSL library supports TLS extensions : yes
> OpenSSL library supports SNI : yes
> OpenSSL library supports prefer-server-ciphers : yes
> Built with PCRE version : 8.32 2012-11-30
> Running on PCRE version : 8.32 2012-11-30
> PCRE library supports JIT : no (USE_PCRE_JIT not set)
> Built with Lua version : Lua 5.3.2
> Built with transparent proxy support using: IP_TRANSPARENT
> IPV6_TRANSPARENT IP_FREEBIND
>
> Available polling systems :
>       epoll : pref=300,  test result OK
>        poll : pref=200,  test result OK
>      select : pref=150,  test result OK
> Total: 3 (3 usable), will use epoll.
>
> Available filters :
>     [COMP] compression
>     [TRACE] trace
>     [SPOE] spoe
>
>
>
> Thanks
> Sachin


--
Cyril Bonté
Sachin Shetty
Re: lua socket settimeout has no effect
July 27, 2018 10:00AM
Thankyou Cyril, your patch fixed the connect issue.

Read timeout still seems a bit weird though, at settimeout(1), readtimeout
kicks in at about 4 seconds, and at settimeout(2), readtimeout kicks in at
about 8 seconds.

is that expected? I couldn't find read timeout explicitly set anywhere in
the same source file.

Thanks
Sachin

On Fri, Jul 27, 2018 at 5:18 AM, Cyril Bonté <[email protected]> wrote:

> Hi,
>
> Le 26/07/2018 à 19:54, Sachin Shetty a écrit :
>
>> Hi,
>>
>> We are using a http-req lua action to dynamically set some app specific
>> metadata headers. The lua handler connects to a upstream memcache like
>> service over tcp to fetch additional metadata.
>>
>> Functionally everything works ok, but I am seeing that socket.settimeout
>> has no effect. Irrespective of what I set in settimeout if the upstream
>> service is unreachable, connect always timesout at 5 seconds, and read
>> timeout around 10 seconds. It seems like settimeout has no effect and it
>> always picks defaults of 5 seconds for connect timeout and 10 seconds for
>> read timeout.
>>
>
> For the connect timeout, it seems this is a hardcoded default value in
> src/hlua.c:
> socket_proxy.timeout.connect = 5000; /* By default the timeout
> connection is 5s. */
>
> If it's possible, can you try the patch attached (for the 1.7.x branch) ?
> But please don't use it in production yet ;-)
>
>
>> Haproxy conf call:
>>
>> http-request lua.get_proxy
>>
>> Lua code sample:
>>
>> function get_proxy(txn)
>> local sock = core.tcp()
>> sock:settimeout(2)
>> status, error = sock:connect(gds_host, gds_port)
>> if not status then
>> core.Alert("1 Error in connecting:" .. key .. ":" .. error)
>> return result, "Error: " .. error
>> end
>> sock:send(key .. "\r\n")
>> ....
>> ....
>>
>>
>> core.register_action("get_proxy", { "http-req" }, get_proxy)
>>
>> Haproxy version:
>>
>> HA-Proxy version 1.7.8 2017/07/07
>> Copyright 2000-2017 Willy Tarreau <[email protected] <mailto:
>> [email protected]>>
>>
>>
>> Build options :
>> TARGET = linux2628
>> CPU = generic
>> CC = gcc
>> CFLAGS = -O2 -g -fno-strict-aliasing -Wdeclaration-after-statement
>> -fwrapv -DTCP_USER_TIMEOUT=18
>> OPTIONS = USE_LINUX_TPROXY=1 USE_ZLIB=1 USE_REGPARM=1 USE_OPENSSL=1
>> USE_LUA=1 USE_PCRE=1
>>
>> Default settings :
>> maxconn = 2000, bufsize = 16384, maxrewrite = 1024, maxpollevents = 200
>>
>> Encrypted password support via crypt(3): yes
>> Built with zlib version : 1.2.7
>> Running on zlib version : 1.2.7
>> Compression algorithms supported : identity("identity"),
>> deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
>> Built with OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
>> Running on OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
>> OpenSSL library supports TLS extensions : yes
>> OpenSSL library supports SNI : yes
>> OpenSSL library supports prefer-server-ciphers : yes
>> Built with PCRE version : 8.32 2012-11-30
>> Running on PCRE version : 8.32 2012-11-30
>> PCRE library supports JIT : no (USE_PCRE_JIT not set)
>> Built with Lua version : Lua 5.3.2
>> Built with transparent proxy support using: IP_TRANSPARENT
>> IPV6_TRANSPARENT IP_FREEBIND
>>
>> Available polling systems :
>> epoll : pref=300, test result OK
>> poll : pref=200, test result OK
>> select : pref=150, test result OK
>> Total: 3 (3 usable), will use epoll.
>>
>> Available filters :
>> [COMP] compression
>> [TRACE] trace
>> [SPOE] spoe
>>
>>
>>
>> Thanks
>> Sachin
>>
>
>
> --
> Cyril Bonté
>
Sachin Shetty
Re: lua socket settimeout has no effect
August 12, 2018 08:50AM
Hi Cyril,

Any idea how I can deterministically set the readtimeout as well?

Thanks
Sachin

On Fri, Jul 27, 2018 at 1:23 PM, Sachin Shetty <[email protected]> wrote:

> Thankyou Cyril, your patch fixed the connect issue.
>
> Read timeout still seems a bit weird though, at settimeout(1), readtimeout
> kicks in at about 4 seconds, and at settimeout(2), readtimeout kicks in at
> about 8 seconds.
>
> is that expected? I couldn't find read timeout explicitly set anywhere in
> the same source file.
>
> Thanks
> Sachin
>
> On Fri, Jul 27, 2018 at 5:18 AM, Cyril Bonté <[email protected]> wrote:
>
>> Hi,
>>
>> Le 26/07/2018 à 19:54, Sachin Shetty a écrit :
>>
>>> Hi,
>>>
>>> We are using a http-req lua action to dynamically set some app specific
>>> metadata headers. The lua handler connects to a upstream memcache like
>>> service over tcp to fetch additional metadata.
>>>
>>> Functionally everything works ok, but I am seeing that socket.settimeout
>>> has no effect. Irrespective of what I set in settimeout if the upstream
>>> service is unreachable, connect always timesout at 5 seconds, and read
>>> timeout around 10 seconds. It seems like settimeout has no effect and it
>>> always picks defaults of 5 seconds for connect timeout and 10 seconds for
>>> read timeout.
>>>
>>
>> For the connect timeout, it seems this is a hardcoded default value in
>> src/hlua.c:
>> socket_proxy.timeout.connect = 5000; /* By default the timeout
>> connection is 5s. */
>>
>> If it's possible, can you try the patch attached (for the 1.7.x branch) ?
>> But please don't use it in production yet ;-)
>>
>>
>>> Haproxy conf call:
>>>
>>> http-request lua.get_proxy
>>>
>>> Lua code sample:
>>>
>>> function get_proxy(txn)
>>> local sock = core.tcp()
>>> sock:settimeout(2)
>>> status, error = sock:connect(gds_host, gds_port)
>>> if not status then
>>> core.Alert("1 Error in connecting:" .. key .. ":" .. error)
>>> return result, "Error: " .. error
>>> end
>>> sock:send(key .. "\r\n")
>>> ....
>>> ....
>>>
>>>
>>> core.register_action("get_proxy", { "http-req" }, get_proxy)
>>>
>>> Haproxy version:
>>>
>>> HA-Proxy version 1.7.8 2017/07/07
>>> Copyright 2000-2017 Willy Tarreau <[email protected] <mailto:
>>> [email protected]>>
>>>
>>>
>>> Build options :
>>> TARGET = linux2628
>>> CPU = generic
>>> CC = gcc
>>> CFLAGS = -O2 -g -fno-strict-aliasing -Wdeclaration-after-statement
>>> -fwrapv -DTCP_USER_TIMEOUT=18
>>> OPTIONS = USE_LINUX_TPROXY=1 USE_ZLIB=1 USE_REGPARM=1 USE_OPENSSL=1
>>> USE_LUA=1 USE_PCRE=1
>>>
>>> Default settings :
>>> maxconn = 2000, bufsize = 16384, maxrewrite = 1024, maxpollevents =
>>> 200
>>>
>>> Encrypted password support via crypt(3): yes
>>> Built with zlib version : 1.2.7
>>> Running on zlib version : 1.2.7
>>> Compression algorithms supported : identity("identity"),
>>> deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
>>> Built with OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
>>> Running on OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
>>> OpenSSL library supports TLS extensions : yes
>>> OpenSSL library supports SNI : yes
>>> OpenSSL library supports prefer-server-ciphers : yes
>>> Built with PCRE version : 8.32 2012-11-30
>>> Running on PCRE version : 8.32 2012-11-30
>>> PCRE library supports JIT : no (USE_PCRE_JIT not set)
>>> Built with Lua version : Lua 5.3.2
>>> Built with transparent proxy support using: IP_TRANSPARENT
>>> IPV6_TRANSPARENT IP_FREEBIND
>>>
>>> Available polling systems :
>>> epoll : pref=300, test result OK
>>> poll : pref=200, test result OK
>>> select : pref=150, test result OK
>>> Total: 3 (3 usable), will use epoll.
>>>
>>> Available filters :
>>> [COMP] compression
>>> [TRACE] trace
>>> [SPOE] spoe
>>>
>>>
>>>
>>> Thanks
>>> Sachin
>>>
>>
>>
>> --
>> Cyril Bonté
>>
>
>
Cyril Bonté
Re: lua socket settimeout has no effect
August 12, 2018 12:40PM
Hi,

Le 12/08/2018 à 08:41, Sachin Shetty a écrit :
> Hi Cyril,
>
> Any idea how I can deterministically set the readtimeout as well?

Well, currently I can't reproduce this at all. Can you provide some more
details ? or even a full configuration providing the test case ?
From the tests I've made, read and write timeouts work as expected.


>
> Thanks
> Sachin
>
> On Fri, Jul 27, 2018 at 1:23 PM, Sachin Shetty <[email protected]
> <mailto:[email protected]>> wrote:
>
> Thankyou Cyril, your patch fixed the connect issue.
>
> Read timeout still seems a bit weird though, at settimeout(1),
> readtimeout kicks in at about 4 seconds, and at settimeout(2),
> readtimeout kicks in at about 8 seconds.
>
> is that expected? I couldn't find read timeout explicitly set
> anywhere in the same source file.
>
> Thanks
> Sachin
>
> On Fri, Jul 27, 2018 at 5:18 AM, Cyril Bonté <[email protected]
> <mailto:[email protected]>> wrote:
>
> Hi,
>
> Le 26/07/2018 à 19:54, Sachin Shetty a écrit :
>
> Hi,
>
> We are using a http-req lua action to dynamically set some
> app specific metadata headers. The lua handler connects to a
> upstream memcache like service over tcp to fetch additional
> metadata.
>
> Functionally everything works ok, but I am seeing that
> socket.settimeout has no effect. Irrespective of what I set
> in settimeout if the upstream service is unreachable,
> connect always timesout at 5 seconds, and read timeout
> around 10 seconds. It seems like  settimeout has no effect
> and it always picks defaults of 5 seconds for connect
> timeout and 10 seconds for read timeout.
>
>
> For the connect timeout, it seems this is a hardcoded default
> value in src/hlua.c:
>   socket_proxy.timeout.connect = 5000; /* By default the
> timeout connection is 5s. */
>
> If it's possible, can you try the patch attached (for the 1.7.x
> branch) ? But please don't use it in production yet ;-)
>
>
> Haproxy conf call:
>
> http-request lua.get_proxy
>
> Lua code sample:
>
> function get_proxy(txn)
>      local sock = core.tcp()
>      sock:settimeout(2)
>      status, error = sock:connect(gds_host, gds_port)
>      if not status then
>          core.Alert("1 Error in connecting:" .. key .. ":"
> .. error)
>          return result, "Error: " .. error
>      end
>      sock:send(key .. "\r\n")
>      ....
>      ....
>
>
> core.register_action("get_proxy", { "http-req" }, get_proxy)
>
> Haproxy version:
>
> HA-Proxy version 1.7.8 2017/07/07
> Copyright 2000-2017 Willy Tarreau <[email protected]
> <mailto:[email protected]rg> <mailto:[email protected]
> <mailto:[email protected]>>>
>
>
> Build options :
>    TARGET  = linux2628
>    CPU     = generic
>    CC      = gcc
>    CFLAGS  = -O2 -g -fno-strict-aliasing
> -Wdeclaration-after-statement -fwrapv -DTCP_USER_TIMEOUT=18
>    OPTIONS = USE_LINUX_TPROXY=1 USE_ZLIB=1 USE_REGPARM=1
> USE_OPENSSL=1 USE_LUA=1 USE_PCRE=1
>
> Default settings :
>    maxconn = 2000, bufsize = 16384, maxrewrite = 1024,
> maxpollevents = 200
>
> Encrypted password support via crypt(3): yes
> Built with zlib version : 1.2.7
> Running on zlib version : 1.2.7
> Compression algorithms supported : identity("identity"),
> deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
> Built with OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
> Running on OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
> OpenSSL library supports TLS extensions : yes
> OpenSSL library supports SNI : yes
> OpenSSL library supports prefer-server-ciphers : yes
> Built with PCRE version : 8.32 2012-11-30
> Running on PCRE version : 8.32 2012-11-30
> PCRE library supports JIT : no (USE_PCRE_JIT not set)
> Built with Lua version : Lua 5.3.2
> Built with transparent proxy support using: IP_TRANSPARENT
> IPV6_TRANSPARENT IP_FREEBIND
>
> Available polling systems :
>        epoll : pref=300,  test result OK
>         poll : pref=200,  test result OK
>       select : pref=150,  test result OK
> Total: 3 (3 usable), will use epoll.
>
> Available filters :
>      [COMP] compression
>      [TRACE] trace
>      [SPOE] spoe
>
>
>
> Thanks
> Sachin
>
>
>
> --
> Cyril Bonté
>
>
>


--
Cyril Bonté
Sachin Shetty
Re: lua socket settimeout has no effect
August 12, 2018 06:30PM
Hi Cyril,

I have created a very simple config to reproduce this. This config always
read timesout in 9 seconds.

To create a timingout service, you can just use nc as follows
nc -l 8888

--------------------
Haproxy Conf:
--------------------
global
pidfile /var/run/haproxy/l1_webui.pid
log /dev/log local0 info alert
log-tag haproxy_l1_webui
user haproxy
group haproxy
chroot /var/lib/haproxy
lua-load /home/sshetty/l1_rework_unit_test/gds.lua

defaults
mode tcp
log global
option httplog
timeout client 300s # Client and server timeout must match the longest
timeout server 300s # time we may wait for a response from the server..
timeout queue 30s # Don't queue requests too long if saturated.
timeout connect 4s # There's no reason to change this one.
timeout http-request 5s
maxconn 20000
retries 2
option redispatch
option dontlognull
option http-server-close

frontend http_l1_webui
bind-process 1
# http front end since some webdav and image requests are made over
http, send as is to L1
mode http
option httplog

bind 0.0.0.0:80
http-request lua.get_proxy

default_backend apache_l1

backend apache_l1
mode http


--------------
Lua code:
--------------
gds_host="127.0.0.1"
gds_port=8888

function get_from_gds(key)

local sock = core.tcp()
-- Connect timeout after patch
sock:settimeout(3)
local result = DOMAIN_NOT_FOUND
local status, error = sock:connect(gds_host, gds_port)
if not status then
core.Alert("Error in connecting:" .. key .. ":" .. error)
return "Error", "Error: " .. error
end
sock:settimeout(2)
sock:send(key .. "\r\n")
while true do
local s, status, partial = sock:receive("*l")
if s == "END" then break end
result = s
end
sock:close()
core.Alert("Returning from GDS:" .. key .. ":" .. result)
return result

end

function protected_get_from_gds(key)

local status, result = pcall(get_from_gds, key)
if not status then
core.Alert("Error in getting key: " .. key .. ":" .. result)
return "Error"
end
return result
end

function get_proxy(txn)
local time = os.time()
local host = txn.sf:req_fhdr("host")
local fqn = host
host = host:gsub("%..*", "")
core.Alert("Getting proxy for domain:" .. host .. ", connecting to " ..
gds_host .. ":" .. gds_port)
local result = protected_get_from_gds("get apache." .. host)
core.Alert("Received Response:" .. host .. ":" .. result .. "<")
end

core.register_action("get_proxy", { "http-req" }, get_proxy)

------------------------------------------------
Sample log timing out in 9 seconds
------------------------------------------------
Aug 12 16:16:12 l1ratelimit01 haproxy_l1_webui[23965]: Getting proxy for
domain:qaus16march2017, connecting to 127.0.0.1:8888
Aug 12 16:16:21 l1ratelimit01 haproxy_l1_webui[23965]: Error in getting
key: get apache.qaus16march2017:execution timeout
Aug 12 16:16:21 l1ratelimit01 haproxy_l1_webui[23965]: Received
Response:qaus16march2017:Error<
Aug 12 16:16:21 l1ratelimit01 haproxy_l1_webui[23965]: 127.0.0.1:39304
[12/Aug/2018:16:16:12.164] http_l1_webui apache_l1/<NOSRV>
9026/-1/-1/-1/9026 503 212 - - SC-- 0/0/0/0/0 0/0 "GET /123 HTTP/1.1"




On Sun, Aug 12, 2018 at 4:02 PM, Cyril Bonté <[email protected]> wrote:

> Hi,
>
> Le 12/08/2018 à 08:41, Sachin Shetty a écrit :
>
>> Hi Cyril,
>>
>> Any idea how I can deterministically set the readtimeout as well?
>>
>
> Well, currently I can't reproduce this at all. Can you provide some more
> details ? or even a full configuration providing the test case ?
> From the tests I've made, read and write timeouts work as expected.
>
>
>
>> Thanks
>> Sachin
>>
>> On Fri, Jul 27, 2018 at 1:23 PM, Sachin Shetty <[email protected]
>> <mailto:[email protected]>> wrote:
>>
>> Thankyou Cyril, your patch fixed the connect issue.
>>
>> Read timeout still seems a bit weird though, at settimeout(1),
>> readtimeout kicks in at about 4 seconds, and at settimeout(2),
>> readtimeout kicks in at about 8 seconds.
>>
>> is that expected? I couldn't find read timeout explicitly set
>> anywhere in the same source file.
>>
>> Thanks
>> Sachin
>>
>> On Fri, Jul 27, 2018 at 5:18 AM, Cyril Bonté <[email protected]
>> <mailto:[email protected]>> wrote:
>>
>> Hi,
>>
>> Le 26/07/2018 à 19:54, Sachin Shetty a écrit :
>>
>> Hi,
>>
>> We are using a http-req lua action to dynamically set some
>> app specific metadata headers. The lua handler connects to a
>> upstream memcache like service over tcp to fetch additional
>> metadata.
>>
>> Functionally everything works ok, but I am seeing that
>> socket.settimeout has no effect. Irrespective of what I set
>> in settimeout if the upstream service is unreachable,
>> connect always timesout at 5 seconds, and read timeout
>> around 10 seconds. It seems like settimeout has no effect
>> and it always picks defaults of 5 seconds for connect
>> timeout and 10 seconds for read timeout.
>>
>>
>> For the connect timeout, it seems this is a hardcoded default
>> value in src/hlua.c:
>> socket_proxy.timeout.connect = 5000; /* By default the
>> timeout connection is 5s. */
>>
>> If it's possible, can you try the patch attached (for the 1.7.x
>> branch) ? But please don't use it in production yet ;-)
>>
>>
>> Haproxy conf call:
>>
>> http-request lua.get_proxy
>>
>> Lua code sample:
>>
>> function get_proxy(txn)
>> local sock = core.tcp()
>> sock:settimeout(2)
>> status, error = sock:connect(gds_host, gds_port)
>> if not status then
>> core.Alert("1 Error in connecting:" .. key .. ":"
>> .. error)
>> return result, "Error: " .. error
>> end
>> sock:send(key .. "\r\n")
>> ....
>> ....
>>
>>
>> core.register_action("get_proxy", { "http-req" }, get_proxy)
>>
>> Haproxy version:
>>
>> HA-Proxy version 1.7.8 2017/07/07
>> Copyright 2000-2017 Willy Tarreau <[email protected]
>> <mailto:[email protected]> <mailto:[email protected]
>>
>> <mailto:[email protected]>>>
>>
>>
>> Build options :
>> TARGET = linux2628
>> CPU = generic
>> CC = gcc
>> CFLAGS = -O2 -g -fno-strict-aliasing
>> -Wdeclaration-after-statement -fwrapv -DTCP_USER_TIMEOUT=18
>> OPTIONS = USE_LINUX_TPROXY=1 USE_ZLIB=1 USE_REGPARM=1
>> USE_OPENSSL=1 USE_LUA=1 USE_PCRE=1
>>
>> Default settings :
>> maxconn = 2000, bufsize = 16384, maxrewrite = 1024,
>> maxpollevents = 200
>>
>> Encrypted password support via crypt(3): yes
>> Built with zlib version : 1.2.7
>> Running on zlib version : 1.2.7
>> Compression algorithms supported : identity("identity"),
>> deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
>> Built with OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
>> Running on OpenSSL version : OpenSSL 1.0.1e-fips 11 Feb 2013
>> OpenSSL library supports TLS extensions : yes
>> OpenSSL library supports SNI : yes
>> OpenSSL library supports prefer-server-ciphers : yes
>> Built with PCRE version : 8.32 2012-11-30
>> Running on PCRE version : 8.32 2012-11-30
>> PCRE library supports JIT : no (USE_PCRE_JIT not set)
>> Built with Lua version : Lua 5.3.2
>> Built with transparent proxy support using: IP_TRANSPARENT
>> IPV6_TRANSPARENT IP_FREEBIND
>>
>> Available polling systems :
>> epoll : pref=300, test result OK
>> poll : pref=200, test result OK
>> select : pref=150, test result OK
>> Total: 3 (3 usable), will use epoll.
>>
>> Available filters :
>> [COMP] compression
>> [TRACE] trace
>> [SPOE] spoe
>>
>>
>>
>> Thanks
>> Sachin
>>
>>
>>
>> -- Cyril Bonté
>>
>>
>>
>>
>
> --
> Cyril Bonté
>
Cyril Bonté
Re: lua socket settimeout has no effect
August 12, 2018 11:00PM
Le 12/08/2018 à 18:21, Sachin Shetty a écrit :
> Hi Cyril,
>
> I have created a very simple config to reproduce this. This config
> always read timesout in 9 seconds.

I think there are 3 issues.

> [...]
> function get_from_gds(key)
> [...]
>     local sock = core.tcp()
>     -- Connect timeout after patch
>     sock:settimeout(3)
>     local result = DOMAIN_NOT_FOUND
>     local status, error = sock:connect(gds_host, gds_port)
>     if not status then
>         core.Alert("Error in connecting:" .. key .. ":" .. error)
>         return "Error", "Error: " .. error
>     end
>     sock:settimeout(2)
>     sock:send(key .. "\r\n")
>     while true do
>         local s, status, partial = sock:receive("*l")

1. The first one is in the LUA code, where you don't check the return
code after calling sock:receive(). In this case, you enter in an
"infinite" loop, adding an extra time to the response almost equal to
tune.lua.session-timeout (4s by default).
You may want to add this :
if not s then
core.Alert("Error reading:" .. status)
return "Error", status
end

Now, 2 other issues seems to be in haproxy, but I'm not sure if it's the
right way to fix this (I add Willy and Thierry to the thread) :
2. hlua_socket_settimeout() initializes rto/wto values, maybe it should
also compute the rex/wex values :
socket->s->req.rex = tick_add_ifset(now_ms, tmout);
socket->s->req.wex = tick_add_ifset(now_ms, tmout);
socket->s->res.rex = tick_add_ifset(now_ms, tmout);
socket->s->res.wex = tick_add_ifset(now_ms, tmout);
3. It may require to wake up the task if a new timeout is set after a
first one was already set (in your case the task doesn't wake up after 2
secondes because a first timeout was set to 3 seconds) :
task_wakeup(socket->s->task, TASK_WOKEN_OTHER);

At least, it seems to fix the issue but before sending a patch, I want
to be sure that's how we should fix this.

--
Cyril Bonté
Sachin Shetty
Re: lua socket settimeout has no effect
August 13, 2018 08:10AM
Hi Cyril,

Thankyou for the response.

Please ignore the second timeout setting, I was testing different things.

I have changed the lua code as you suggested - thanks for the hint there.

function get_from_gds(key)

local sock = core.tcp()
-- Connect timeout after patch
sock:settimeout(3)
local result = DOMAIN_NOT_FOUND
local status, error = sock:connect(gds_host, gds_port)
if not status then
core.Alert("Error in connecting:" .. key .. ":" .. error)
return "Error", "Error: " .. error
end
sock:send(key .. "\r\n")
while true do
local s, status, partial = sock:receive("*l")
if not s then
core.Alert("Error reading:" .. status)
return "Error", status
end
if s == "END" then break end
result = s
end
sock:close()
core.Alert("Returning from GDS:" .. key .. ":" .. result)
return result

end

but the receive still does not timeout in 3 seconds.

On Mon, Aug 13, 2018 at 2:19 AM, Cyril Bonté <[email protected]> wrote:

> Le 12/08/2018 à 18:21, Sachin Shetty a écrit :
>
>> Hi Cyril,
>>
>> I have created a very simple config to reproduce this. This config always
>> read timesout in 9 seconds.
>>
>
> I think there are 3 issues.
>
> [...]
>> function get_from_gds(key)
>> [...] local sock = core.tcp()
>> -- Connect timeout after patch
>> sock:settimeout(3)
>> local result = DOMAIN_NOT_FOUND
>> local status, error = sock:connect(gds_host, gds_port)
>> if not status then
>> core.Alert("Error in connecting:" .. key .. ":" .. error)
>> return "Error", "Error: " .. error
>> end
>> sock:settimeout(2)
>> sock:send(key .. "\r\n")
>> while true do
>> local s, status, partial = sock:receive("*l")
>>
>
> 1. The first one is in the LUA code, where you don't check the return code
> after calling sock:receive(). In this case, you enter in an "infinite"
> loop, adding an extra time to the response almost equal to
> tune.lua.session-timeout (4s by default).
> You may want to add this :
> if not s then
> core.Alert("Error reading:" .. status)
> return "Error", status
> end
>
> Now, 2 other issues seems to be in haproxy, but I'm not sure if it's the
> right way to fix this (I add Willy and Thierry to the thread) :
> 2. hlua_socket_settimeout() initializes rto/wto values, maybe it should
> also compute the rex/wex values :
> socket->s->req.rex = tick_add_ifset(now_ms, tmout);
> socket->s->req.wex = tick_add_ifset(now_ms, tmout);
> socket->s->res.rex = tick_add_ifset(now_ms, tmout);
> socket->s->res.wex = tick_add_ifset(now_ms, tmout);
> 3. It may require to wake up the task if a new timeout is set after a
> first one was already set (in your case the task doesn't wake up after 2
> secondes because a first timeout was set to 3 seconds) :
> task_wakeup(socket->s->task, TASK_WOKEN_OTHER);
>
> At least, it seems to fix the issue but before sending a patch, I want to
> be sure that's how we should fix this.
>
> --
> Cyril Bonté
>
Willy Tarreau
Re: lua socket settimeout has no effect
August 13, 2018 09:40AM
Hi Cyril,

On Sun, Aug 12, 2018 at 10:49:13PM +0200, Cyril Bonté wrote:
> 2. hlua_socket_settimeout() initializes rto/wto values, maybe it should also
> compute the rex/wex values :
> socket->s->req.rex = tick_add_ifset(now_ms, tmout);
> socket->s->req.wex = tick_add_ifset(now_ms, tmout);
> socket->s->res.rex = tick_add_ifset(now_ms, tmout);
> socket->s->res.wex = tick_add_ifset(now_ms, tmout);

You're absolutely right, it's indeed incorrect to set {r,w}to without
updating the expire date. It only works when the timeout is extended,
but not when it's shortened.

> 3. It may require to wake up the task if a new timeout is set after a first
> one was already set (in your case the task doesn't wake up after 2 secondes
> because a first timeout was set to 3 seconds) :
> task_wakeup(socket->s->task, TASK_WOKEN_OTHER);

Normally it should not be needed, however it needs to be requeued to
take care of the fact that the timeout might have been shortened :

socket->s->task->expire = tick_add_ifset(now_ms, tmout);
task_queue(socket->s->task);

> At least, it seems to fix the issue but before sending a patch, I want to be
> sure that's how we should fix this.

If you can just validate that the two lines above are enough, that would
be great. Avoiding to call process_stream() just to update a timeout is
desirable. If for any reason it doesn't work or seems more complicated,
then the wakeup as you proposed should indeed work.

Thanks,
Willy
Cyril Bonté
Re: lua socket settimeout has no effect
August 14, 2018 01:40AM
Hi Willy,

Le 13/08/2018 à 09:28, Willy Tarreau a écrit :
> Hi Cyril,
>
> On Sun, Aug 12, 2018 at 10:49:13PM +0200, Cyril Bonté wrote:
>> 2. hlua_socket_settimeout() initializes rto/wto values, maybe it should also
>> compute the rex/wex values :
>> socket->s->req.rex = tick_add_ifset(now_ms, tmout);
>> socket->s->req.wex = tick_add_ifset(now_ms, tmout);
>> socket->s->res.rex = tick_add_ifset(now_ms, tmout);
>> socket->s->res.wex = tick_add_ifset(now_ms, tmout);
>
> You're absolutely right, it's indeed incorrect to set {r,w}to without
> updating the expire date. It only works when the timeout is extended,
> but not when it's shortened.
>
>> 3. It may require to wake up the task if a new timeout is set after a first
>> one was already set (in your case the task doesn't wake up after 2 secondes
>> because a first timeout was set to 3 seconds) :
>> task_wakeup(socket->s->task, TASK_WOKEN_OTHER);
>
> Normally it should not be needed, however it needs to be requeued to
> take care of the fact that the timeout might have been shortened :
>
> socket->s->task->expire = tick_add_ifset(now_ms, tmout);
> task_queue(socket->s->task);
>
>> At least, it seems to fix the issue but before sending a patch, I want to be
>> sure that's how we should fix this.
>
> If you can just validate that the two lines above are enough, that would
> be great. Avoiding to call process_stream() just to update a timeout is
> desirable. If for any reason it doesn't work or seems more complicated,
> then the wakeup as you proposed should indeed work.

Thanks for the feedback. I've made some tests withe the lines of code
you suggested and it looks to work fine. I'll prepare the patches tomorrow.

--
Cyril Bonté
Cyril Bonté
Re: lua socket settimeout has no effect
August 17, 2018 01:10AM
Hi Willy and Sachin,

Le 14/08/2018 à 01:27, Cyril Bonté a écrit :
> Thanks for the feedback. I've made some tests with the lines of code
> you suggested and it looks to work fine. I'll prepare the patches tomorrow.

OK, some updates on the patch.
It was working well with haproxy 1.7, the same with haproxy 1.8.
But when I prepared the patch for the 1.9 branch, I discovered a strange
behaviour, where the timeout was approximaterly delayed by 500ms. I
spent some time tonight, until I discovered it was under my eyes some
lines earlier :)

The culprit is commit #56cc12509 [1] where the rounding calculation is
wrong :
/* round up for inputs that are fractions and convert to millis */
dtmout = (0.5 + MAY_LJMP(luaL_checknumber(L, 2))) * 1000;

Well, now it's identified, I'll (really) send the patch tomorrow and
will see in another patch how we can fix #56cc12509.


[1]
http://git.haproxy.org/?p=haproxy.git;a=blobdiff;f=src/hlua.c;h=60cf8f948437677b72adabc50602ca99d80349bf;hp=633841c6d7aecce3e5cf893e01b5eed1cfe64e0f;hb=56cc12509;hpb=7741c854cd908dd4947325c36a6feb8203748d16


--
Cyril Bonté
Willy Tarreau
Re: lua socket settimeout has no effect
August 17, 2018 05:30AM
Hi Cyril,

On Fri, Aug 17, 2018 at 01:02:52AM +0200, Cyril Bonté wrote:
> Hi Willy and Sachin,
>
> Le 14/08/2018 à 01:27, Cyril Bonté a écrit :
> > Thanks for the feedback. I've made some tests with the lines of code you
> > suggested and it looks to work fine. I'll prepare the patches tomorrow.
>
> OK, some updates on the patch.
> It was working well with haproxy 1.7, the same with haproxy 1.8.
> But when I prepared the patch for the 1.9 branch, I discovered a strange
> behaviour, where the timeout was approximaterly delayed by 500ms. I spent
> some time tonight, until I discovered it was under my eyes some lines
> earlier :)
>
> The culprit is commit #56cc12509 [1] where the rounding calculation is wrong
> :
> /* round up for inputs that are fractions and convert to millis */
> dtmout = (0.5 + MAY_LJMP(luaL_checknumber(L, 2))) * 1000;

Ah an interesting one :-)

> Well, now it's identified, I'll (really) send the patch tomorrow and will
> see in another patch how we can fix #56cc12509.

Great, thank you!

Willy
Sorry, only registered users may post in this forum.

Click here to login