Hi Willy,
Op 19-9-2018 om 7:36 schreef Willy Tarreau:
Hi Pieter,
I took some time this morning to give it a test. For now it fails here,
after dumping 2200 lines of not really usable output that I didn't
investigate. From what I'm seeing it seems to moderately stress the
local machine so it has many reasons for failing (lack of source
ports, improperly tuned conntrack, ulimit, etc), and it takes far too
long a time to be usable as a default test, or this one alone will be
enough to discourage anyone from regularly running "make reg-tests".
Test takes like 5 seconds to run here, and while that is a bit long if
you get a hundred more similar tests and want to continue tweaking
developments while running tests in between. It wouldn't hurt to run
such a (series) of longer tests before creating a patch and submitting
it for inclusion on the official git repository in my opinion, or before
a release.?. My attempt was to test a bit differently than just looking
for regressions of known fixed bugs, and putting a little load on
haproxy so that threads and simultaneous actions 'might' get into
conflicts/locks/stuff which might by chance, show up, which is why i
choose to go a little higher on the number of round-trips with ever
slightly increasing payload..
For me the test produces like 345 lines of output as attached. which
seems not to bad (if the test succeeds).. Besides the 2 instances of cli
output for stats, its seems not that much different from other tests..
And with 1.8.13 on FreeBSD (without qkueue) it succeeds: # top TEST
./test/b00000-loadtest.vtc passed (4.800
Taking into account conntrack and ulimit, would that mean we can never
'reg-test' if haproxy can really handle like 10000 connections without
issue? Or should the environment be configured by the test?? ,that seems
very tricky at least and probably would be undesirable.. (i just today
figured i could run reg-tests also on my production box to compare if a
new build showed issues there that my test-box might not.. i wouldn't
want system settings to changed by a reg-test run..)
I think we should create a distinct category for such tests
Agreed, which is why i used the currently non-existing '/loadtest/'
folder. If '/heavy/' is better thats of course alright for me to.
, because
I see some value in it when it's made to reproduce a very specific
class of issues which is very unlikely to trigger unless someone is
working on it. In this case it is not a problem that it dumps a lot
of output, as it will be useful for the person knowing what to look
for there. Probably that such tests should be run by hand and dump
their log into a related file. Imagine for example that we would
have this :
$ make reg-tests/heavy/conn-counter-3000-req.log
I'm not exactly sure..("make: don't know how to make reg-tests. Stop").
i would still like to have a way to run all 'applicable' tests with 1
command, even if it takes a hour or so to verify haproxy is working
'perfectly'. But like abns@ tests cant work on FreeBSD, but they should
not 'fail', perhaps get skipped automatically though.?. Anyhow thats a
question for my other mail-topic (
https://www.mail-archive.com/haproxy@formilux.org/msg31195.html )
It would run the test on reg-tests/heavy/conn-counter-3000-req.vtc and
would produce the log into reg-tests/heavy/conn-counter-3000-req.log.
We could use a similar thing to test for select/poll/epoll/kqueue, to
test for timeouts, race conditions (eg show sess in threads). This is
very likely something to brainstorm about. You might have other ideas
related to certain issues you faced in the past. Fred is unavailable
this week but I'd be very interested in his opinion on such things.
Thus for now I'm not applying your patch, but I'm interested in seeing
what can be done with it.
Okay no problem :) , ill keep running this particular test myself for
the moment, it 'should' be able to pass normally.. (On my environment
anyhow..)
Thanks,
Willy
Thanks for your comments, and thoughts.
I'm interested in Fred's and anyone elses opinion ;) , and well maybe
this particular test-case could be replaced by something simpler/faster/
with more or less the same likelihood of catching yet unknown issues..?
Looking forward to reactions :) .
Thanks and regards,
PiBa-NL (Pieter)
**** top 0.0 extmacro def pwd=/usr/ports/net/haproxy-devel
**** top 0.0 extmacro def localhost=127.0.0.1
**** top 0.0 extmacro def bad_backend=127.0.0.1 58530
**** top 0.0 extmacro def bad_ip=192.0.2.255
**** top 0.0 macro def testdir=/usr/ports/net/haproxy-devel/./test
**** top 0.0 macro def tmpdir=/tmp/vtc.35996.290f74a9
* top 0.0 TEST ./test/b00000-loadtest.vtc starting
** top 0.0 === varnishtest "Seamless reload issue with abns sockets"
* top 0.0 TEST Seamless reload issue with abns sockets
** top 0.0 === feature ignore_unknown_macro
** top 0.0 === server s1 {
** s1 0.0 Starting server
**** s1 0.0 macro def s1_addr=127.0.0.1
**** s1 0.0 macro def s1_port=58531
**** s1 0.0 macro def s1_sock=127.0.0.1 58531
* s1 0.0 Listen on 127.0.0.1 58531
** top 0.0 === syslog Slg_1 -level notice {
** Slg_1 0.0 Starting syslog server
**** Slg_1 0.0 macro def Slg_1_addr=127.0.0.1
**** Slg_1 0.0 macro def Slg_1_port=13952
**** Slg_1 0.0 macro def Slg_1_sock=127.0.0.1 13952
* Slg_1 0.0 Bound on 127.0.0.1 13952
** s1 0.0 Started on 127.0.0.1 58531
*** s1 0.0 Iteration 0
** top 0.0 === haproxy h1 -W -D -conf {
** Slg_1 0.0 Started on 127.0.0.1 13952 (level: 5)
*** Slg_1 0.0 Iteration 0
** Slg_1 0.0 === recv
**** h1 0.0 macro def h1_cli_sock=::1 58532
**** h1 0.0 macro def h1_cli_addr=::1
**** h1 0.0 macro def h1_cli_port=58532
**** h1 0.0 setenv(cli, 6)
**** h1 0.0 macro def h1_fe_1_sock=::1 58533
**** h1 0.0 macro def h1_fe_1_addr=::1
**** h1 0.0 macro def h1_fe_1_port=58533
**** h1 0.0 setenv(fe_1, 7)
**** h1 0.0 macro def h1_fe_2_sock=::1 58534
**** h1 0.0 macro def h1_fe_2_addr=::1
**** h1 0.0 macro def h1_fe_2_port=58534
**** h1 0.0 setenv(fe_2, 8)
**** h1 0.0 conf| global
**** h1 0.0 conf|\tstats socket /tmp/vtc.35996.290f74a9/h1/stats.sock level
admin mode 600
**** h1 0.0 conf| stats socket "fd@${cli}" level admin
**** h1 0.0 conf|
**** h1 0.0 conf| global
**** h1 0.0 conf| nbthread 3
**** h1 0.0 conf| log 127.0.0.1:13952 local0
**** h1 0.0 conf| maxconn 500000
**** h1 0.0 conf| nokqueue
**** h1 0.0 conf|
**** h1 0.0 conf| defaults
**** h1 0.0 conf| mode http
**** h1 0.0 conf| option dontlog-normal
**** h1 0.0 conf| log global
**** h1 0.0 conf| option httplog
**** h1 0.0 conf| timeout connect 3s
**** h1 0.0 conf| timeout client 4s
**** h1 0.0 conf| timeout server 15s
**** h1 0.0 conf|
**** h1 0.0 conf| frontend fe1
**** h1 0.0 conf| maxconn 20001
**** h1 0.0 conf| bind "fd@${fe_1}"
**** h1 0.0 conf| acl donelooping hdr(TEST) -m len 1000
**** h1 0.0 conf| http-request set-header TEST "%[hdr(TEST)]x"
**** h1 0.0 conf| use_backend b2 if donelooping
**** h1 0.0 conf| default_backend b1
**** h1 0.0 conf|
**** h1 0.0 conf| backend b1
**** h1 0.0 conf| fullconn 20000
**** h1 0.0 conf| server srv1 ::1:58533 maxconn 20000
**** h1 0.0 conf|
**** h1 0.0 conf| frontend fe2
**** h1 0.0 conf| bind "fd@${fe_2}"
**** h1 0.0 conf| default_backend b2
**** h1 0.0 conf|
**** h1 0.0 conf| backend b2
**** h1 0.0 conf| # haproxy 1.8 does not have the ,length converter.
**** h1 0.0 conf| acl OK hdr(TEST) -m len 1000
**** h1 0.0 conf| http-request deny deny_status 200 if OK
**** h1 0.0 conf| http-request deny deny_status 400
**** h1 0.0 conf|
**** h1 0.0 conf| # haproxy 1.9 does have a ,length converter.
**** h1 0.0 conf| #http-request set-header TESTsize "%[hdr(TEST),length]"
**** h1 0.0 conf| #http-request del-header TEST
**** h1 0.0 conf| #server srv2 127.0.0.1:58531
**** h1 0.0 conf|
** h1 0.0 haproxy_start
**** h1 0.0 opt_worker 1 opt_daemon 1 opt_check_mode 0
**** h1 0.0 argv|exec haproxy -D -W -f /tmp/vtc.35996.290f74a9/h1/cfg -p
/tmp/vtc.35996.290f74a9/h1/pid
**** h1 0.0 XXX 10 @586
*** h1 0.0 PID: 36000
**** h1 0.0 macro def h1_pid=36000
**** h1 0.0 macro def h1_name=/tmp/vtc.35996.290f74a9/h1
*** h1 0.0 wait-pid-file
**** Slg_1 0.0 syslog|<133>Sep 19 20:50:29 haproxy[36000]: Proxy fe1 started.
*** Slg_1 0.0 shutting fd 4
*** Slg_1 0.0 Iteration 1
** Slg_1 0.0 === recv
**** Slg_1 0.0 syslog|<133>Sep 19 20:50:29 haproxy[36000]: Proxy b1 started.
*** Slg_1 0.0 shutting fd 4
*** Slg_1 0.0 Iteration 2
** Slg_1 0.0 === recv
**** Slg_1 0.0 syslog|<133>Sep 19 20:50:29 haproxy[36000]: Proxy fe2 started.
*** Slg_1 0.0 shutting fd 4
*** Slg_1 0.0 Iteration 3
** Slg_1 0.0 === recv
**** Slg_1 0.0 syslog|<133>Sep 19 20:50:29 haproxy[36000]: Proxy b2 started.
*** Slg_1 0.0 shutting fd 4
*** Slg_1 0.0 Iteration 4
** Slg_1 0.0 === recv
*** h1 0.0 debug|[WARNING] 261/205029 (36000) : [haproxy.main()] FD limit
(234909) too low for maxconn=500000/maxsock=1000042. Please raise 'ulimit-n' to
1000042 or more to avoid any trouble.
** h1 0.0 haproxy PID 36001 successfully started
** top 0.0 === barrier b1 cond 3
** top 0.0 === client c1 -connect ${h1_fe_1_sock} {
** c1 0.0 Starting client
** top 0.0 === client c2 -connect ${h1_fe_1_sock} {
** c2 0.0 Starting client
*** c1 0.0 Connect to ::1 58533
** top 0.0 === client c3 -connect ${h1_fe_1_sock} {
** c3 0.0 Starting client
*** c1 0.0 connected fd 9 from ::1 58535 to ::1 58533
** c1 0.0 === timeout 17
** c1 0.0 === barrier b1 sync
**** c1 0.0 Barrier(b1) wait 1 of 3
*** c2 0.0 Connect to ::1 58533
** top 0.0 === client c1 -wait
** c1 0.0 Waiting for client
*** c2 0.0 connected fd 12 from ::1 58536 to ::1 58533
** c2 0.0 === timeout 17
** c2 0.0 === barrier b1 sync
**** c2 0.0 Barrier(b1) wait 2 of 3
*** c3 0.0 Connect to ::1 58533
*** c3 0.0 connected fd 13 from ::1 58537 to ::1 58533
** c3 0.0 === timeout 17
** c3 0.0 === barrier b1 sync
**** c3 0.0 Barrier(b1) wake 3
** c3 0.0 === txreq -url "/"
** c2 0.0 === txreq -url "/"
** c1 0.0 === txreq -url "/"
**** c3 0.0 txreq|GET / HTTP/1.1\r
**** c3 0.0 txreq|Host: 127.0.0.1\r
**** c3 0.0 txreq|\r
**** c2 0.0 txreq|GET / HTTP/1.1\r
**** c2 0.0 txreq|Host: 127.0.0.1\r
**** c2 0.0 txreq|\r
**** c1 0.0 txreq|GET / HTTP/1.1\r
**** c1 0.0 txreq|Host: 127.0.0.1\r
**** c1 0.0 txreq|\r
** c2 0.0 === rxresp
** c1 0.0 === rxresp
** c3 0.0 === rxresp
**** h1 0.1 STDOUT poll 0x11
**** Slg_1 1.8 syslog|<134>Sep 19 20:50:31 haproxy[36002]: ::1:61511
[19/Sep/2018:20:50:31.249] fe1 b2/<NOSRV> 0/-1/-1/-1/1 200 146 - - PR--
2978/2978/0/0/3 0/0 "GET / HTTP/1.1"
**** Slg_1 1.8 syslog|<134>Sep 19 20:50:31 haproxy[36002]: ::1:61534
[19/Sep/2018:20:50:31.270] fe1 b2/<NOSRV> 0/-1/-1/-1/1 200 146 - - PR--
2989/2989/1/0/3 0/0 "GET / HTTP/1.1"
**** Slg_1 1.8 syslog|<134>Sep 19 20:50:31 haproxy[36002]: ::1:61535
[19/Sep/2018:20:50:31.271] fe1 b2/<NOSRV> 0/-1/-1/-1/0 200 146 - - PR--
2988/2988/0/0/3 0/0 "GET / HTTP/1.1"
**** c2 2.6 rxhdr|HTTP/1.0 200 OK\r
**** c2 2.6 rxhdr|Cache-Control: no-cache\r
**** c2 2.6 rxhdr|Content-Type: text/html\r
**** c2 2.6 rxhdr|\r
**** c2 2.6 rxhdrlen = 69
**** c2 2.6 http[ 0] |HTTP/1.0
**** c2 2.6 http[ 1] |200
**** c2 2.6 http[ 2] |OK
**** c2 2.6 http[ 3] |Cache-Control: no-cache
**** c2 2.6 http[ 4] |Content-Type: text/html
**** c2 2.6 rxeof|<html><body><h1>200 OK</h1>
**** c2 2.6 rxeof|Service ready.
**** c2 2.6 rxeof|</body></html>
**** c2 2.6 bodylen = 58
** c2 2.6 === expect resp.status == 200
**** c2 2.6 EXPECT resp.status (200) == "200" match
*** c2 2.6 closing fd 12
** c2 2.6 Ending
**** c1 2.6 rxhdr|HTTP/1.0 200 OK\r
**** c1 2.6 rxhdr|Cache-Control: no-cache\r
**** c1 2.6 rxhdr|Content-Type: text/html\r
**** c1 2.6 rxhdr|\r
**** c1 2.6 rxhdrlen = 69
**** c1 2.6 http[ 0] |HTTP/1.0
**** c1 2.6 http[ 1] |200
**** c1 2.6 http[ 2] |OK
**** c1 2.6 http[ 3] |Cache-Control: no-cache
**** c1 2.6 http[ 4] |Content-Type: text/html
**** c1 2.7 rxeof|<html><body><h1>200 OK</h1>
**** c1 2.7 rxeof|Service ready.
**** c1 2.7 rxeof|</body></html>
**** c1 2.7 bodylen = 58
** c1 2.7 === expect resp.status == 200
**** c1 2.7 EXPECT resp.status (200) == "200" match
*** c1 2.7 closing fd 9
** c1 2.7 Ending
**** c3 2.7 rxhdr|HTTP/1.0 200 OK\r
**** c3 2.7 rxhdr|Cache-Control: no-cache\r
**** c3 2.7 rxhdr|Content-Type: text/html\r
**** c3 2.7 rxhdr|\r
**** c3 2.7 rxhdrlen = 69
**** c3 2.7 http[ 0] |HTTP/1.0
**** c3 2.7 http[ 1] |200
**** c3 2.7 http[ 2] |OK
**** c3 2.7 http[ 3] |Cache-Control: no-cache
**** c3 2.7 http[ 4] |Content-Type: text/html
**** c3 2.7 rxeof|<html><body><h1>200 OK</h1>
**** c3 2.7 rxeof|Service ready.
**** c3 2.7 rxeof|</body></html>
**** c3 2.7 bodylen = 58
** c3 2.7 === expect resp.status == 200
**** c3 2.7 EXPECT resp.status (200) == "200" match
*** c3 2.7 closing fd 13
** c3 2.7 Ending
** top 2.7 === client c2 -wait
** c2 2.7 Waiting for client
** top 2.7 === client c3 -wait
** c3 2.7 Waiting for client
** top 2.7 === haproxy h1 -cli {
** h1 2.7 CLI starting
** h1 2.7 CLI waiting
*** h1 2.7 CLI connected fd 9 from ::1 61536 to ::1 58532
** h1 2.7 === send "show info"
**** h1 2.7 CLI send|show info
** h1 2.7 === expect ~ "CumConns: 3001"
**** h1 2.7 CLI connection normally closed
*** h1 2.7 CLI closing fd 9
**** h1 2.7 CLI recv|Name: HAProxy
**** h1 2.7 CLI recv|Version: 1.8.13
**** h1 2.7 CLI recv|Release_date: 2018/07/30
**** h1 2.7 CLI recv|Nbthread: 3
**** h1 2.7 CLI recv|Nbproc: 1
**** h1 2.7 CLI recv|Process_num: 1
**** h1 2.7 CLI recv|Pid: 36002
**** h1 2.7 CLI recv|Uptime: 0d 0h00m03s
**** h1 2.7 CLI recv|Uptime_sec: 3
**** h1 2.7 CLI recv|Memmax_MB: 0
**** h1 2.7 CLI recv|PoolAlloc_MB: 11
**** h1 2.7 CLI recv|PoolUsed_MB: 0
**** h1 2.7 CLI recv|PoolFailed: 0
**** h1 2.7 CLI recv|Ulimit-n: 1000042
**** h1 2.7 CLI recv|Maxsock: 1000042
**** h1 2.7 CLI recv|Maxconn: 500000
**** h1 2.7 CLI recv|Hard_maxconn: 500000
**** h1 2.7 CLI recv|CurrConns: 0
**** h1 2.7 CLI recv|CumConns: 3001
**** h1 2.7 CLI recv|CumReq: 3001
**** h1 2.7 CLI recv|MaxSslConns: 0
**** h1 2.7 CLI recv|CurrSslConns: 0
**** h1 2.7 CLI recv|CumSslConns: 0
**** h1 2.7 CLI recv|Maxpipes: 0
**** h1 2.7 CLI recv|PipesUsed: 0
**** h1 2.7 CLI recv|PipesFree: 0
**** h1 2.7 CLI recv|ConnRate: 358
**** h1 2.7 CLI recv|ConnRateLimit: 0
**** h1 2.7 CLI recv|MaxConnRate: 1837
**** h1 2.7 CLI recv|SessRate: 358
**** h1 2.7 CLI recv|SessRateLimit: 0
**** h1 2.7 CLI recv|MaxSessRate: 1837
**** h1 2.7 CLI recv|SslRate: 0
**** h1 2.7 CLI recv|SslRateLimit: 0
**** h1 2.7 CLI recv|MaxSslRate: 0
**** h1 2.7 CLI recv|SslFrontendKeyRate: 0
**** h1 2.7 CLI recv|SslFrontendMaxKeyRate: 0
**** h1 2.7 CLI recv|SslFrontendSessionReuse_pct: 0
**** h1 2.7 CLI recv|SslBackendKeyRate: 0
**** h1 2.7 CLI recv|SslBackendMaxKeyRate: 0
**** h1 2.7 CLI recv|SslCacheLookups: 0
**** h1 2.7 CLI recv|SslCacheMisses: 0
**** h1 2.7 CLI recv|CompressBpsIn: 0
**** h1 2.7 CLI recv|CompressBpsOut: 0
**** h1 2.7 CLI recv|CompressBpsRateLim: 0
**** h1 2.7 CLI recv|ZlibMemUsage: 0
**** h1 2.7 CLI recv|MaxZlibMemUsage: 0
**** h1 2.7 CLI recv|Tasks: 7
**** h1 2.7 CLI recv|Run_queue: 1
**** h1 2.7 CLI recv|Idle_pct: 76
**** h1 2.7 CLI recv|node: freebsd11
**** h1 2.7 CLI recv|
**** h1 2.7 CLI expect match ~ "CumConns: 3001"
** h1 2.7 === send "show info"
*** h1 2.7 CLI connected fd 9 from ::1 61537 to ::1 58532
**** h1 2.7 CLI send|show info
** h1 2.7 === expect ~ "CumReq: 3002"
**** h1 2.7 CLI connection normally closed
*** h1 2.7 CLI closing fd 9
**** h1 2.7 CLI recv|Name: HAProxy
**** h1 2.7 CLI recv|Version: 1.8.13
**** h1 2.7 CLI recv|Release_date: 2018/07/30
**** h1 2.7 CLI recv|Nbthread: 3
**** h1 2.7 CLI recv|Nbproc: 1
**** h1 2.7 CLI recv|Process_num: 1
**** h1 2.7 CLI recv|Pid: 36002
**** h1 2.7 CLI recv|Uptime: 0d 0h00m03s
**** h1 2.7 CLI recv|Uptime_sec: 3
**** h1 2.7 CLI recv|Memmax_MB: 0
**** h1 2.7 CLI recv|PoolAlloc_MB: 11
**** h1 2.7 CLI recv|PoolUsed_MB: 0
**** h1 2.7 CLI recv|PoolFailed: 0
**** h1 2.7 CLI recv|Ulimit-n: 1000042
**** h1 2.7 CLI recv|Maxsock: 1000042
**** h1 2.7 CLI recv|Maxconn: 500000
**** h1 2.7 CLI recv|Hard_maxconn: 500000
**** h1 2.7 CLI recv|CurrConns: 0
**** h1 2.7 CLI recv|CumConns: 3002
**** h1 2.7 CLI recv|CumReq: 3002
**** h1 2.7 CLI recv|MaxSslConns: 0
**** h1 2.7 CLI recv|CurrSslConns: 0
**** h1 2.7 CLI recv|CumSslConns: 0
**** h1 2.7 CLI recv|Maxpipes: 0
**** h1 2.7 CLI recv|PipesUsed: 0
**** h1 2.7 CLI recv|PipesFree: 0
**** h1 2.7 CLI recv|ConnRate: 358
**** h1 2.7 CLI recv|ConnRateLimit: 0
**** h1 2.7 CLI recv|MaxConnRate: 1837
**** h1 2.7 CLI recv|SessRate: 358
**** h1 2.7 CLI recv|SessRateLimit: 0
**** h1 2.7 CLI recv|MaxSessRate: 1837
**** h1 2.7 CLI recv|SslRate: 0
**** h1 2.7 CLI recv|SslRateLimit: 0
**** h1 2.7 CLI recv|MaxSslRate: 0
**** h1 2.7 CLI recv|SslFrontendKeyRate: 0
**** h1 2.7 CLI recv|SslFrontendMaxKeyRate: 0
**** h1 2.7 CLI recv|SslFrontendSessionReuse_pct: 0
**** h1 2.7 CLI recv|SslBackendKeyRate: 0
**** h1 2.7 CLI recv|SslBackendMaxKeyRate: 0
**** h1 2.7 CLI recv|SslCacheLookups: 0
**** h1 2.7 CLI recv|SslCacheMisses: 0
**** h1 2.7 CLI recv|CompressBpsIn: 0
**** h1 2.7 CLI recv|CompressBpsOut: 0
**** h1 2.7 CLI recv|CompressBpsRateLim: 0
**** h1 2.7 CLI recv|ZlibMemUsage: 0
**** h1 2.7 CLI recv|MaxZlibMemUsage: 0
**** h1 2.7 CLI recv|Tasks: 7
**** h1 2.7 CLI recv|Run_queue: 1
**** h1 2.7 CLI recv|Idle_pct: 75
**** h1 2.7 CLI recv|node: freebsd11
**** h1 2.7 CLI recv|
**** h1 2.7 CLI expect match ~ "CumReq: 3002"
** h1 2.7 CLI ending
* top 2.7 RESETTING after ./test/b00000-loadtest.vtc
** h1 2.7 Reset and free h1 haproxy 36001
** h1 2.7 Wait
** h1 2.7 Stop HAproxy pid=36001
**** h1 2.7 Kill(2)=0: No error: 0
** s1 4.8 Waiting for server (3/-1)
** Slg_1 4.8 Waiting for syslog server (4)
* top 4.8 TEST ./test/b00000-loadtest.vtc completed
# top TEST ./test/b00000-loadtest.vtc passed (4.800)
