Hello All
I have made small http server benchmark tool base on libcurl library ( https://github.com/ajax16384/ahsbt). There are plenty number of tools with same functionality but they have some disadvantages: - ab (https://httpd.apache.org/docs/2.4/programs/ab.html) and wrk ( https://github.com/wg/wrk) lack http2 support - h2load (https://nghttp2.org/documentation/h2load.1.html) has no non keep alive mode - go based tools (https://github.com/rakyll/hey, https://github.com/tsenart/vegeta) has non user land friendly thread-process usage So tool creates threads with single multi-curl and curl_multi_wait- curl_multi_perform loop and constantly readd easy-curl handles until all requests are done. Now I am stuck on strange libcurl behaviour: then I'm trying to run test without reusing same socket connection (CURLOPT_FORBID_REUSE==1), program starts to perform very slow and with higher CPU usage compared to apache ab tool with same run parameters. Test environment: Nginx with static page (http://172.19.161.85/resp200/). ./ahsbt --tcpnagle --noreuse --connections=1 --threads=1 --requests=50000 http://172.19.161.85/resp200/ Another HTTP Server Benchmark Test 0.1 Using libcurl/7.58.0 OpenSSL/1.1.1 zlib/1.2.11 libidn2/2.0.4 libpsl/0.19.1 (+libidn2/2.0.4) nghttp2/1.30.0 librtmp/2.3 Url: http://172.19.161.85/resp200/ No Reuse TCP Nagle Connections count: 1 Requests count: 50000 Threads count: 1 Testing ... Total requests count: 50000 Transfer errors count: 18825 [ 37.65% ] Response errors count: 0 [ 0.00% ] Min request time: 0.00 sec Avg request time: 0.00 sec Max request time: 0.01 sec Measured total time: 61.67 sec Requests per second: 810.72 ab -c 1 -n 50000 http://172.19.161.85/resp200/ Concurrency Level: 1 Time taken for tests: 6.294 seconds Complete requests: 50000 Failed requests: 0 Total transferred: 7800000 bytes HTML transferred: 0 bytes Requests per second: 7944.47 [#/sec] (mean) Time per request: 0.126 [ms] (mean) Time per request: 0.126 [ms] (mean, across all concurrent requests) Transfer rate: 1210.29 [Kbytes/sec] received >From strace point of view libcurl and ab doing essentially the same (except getsockopt,getpeername,getsockname which are insignficant according to perf): Libcurl: [pid 12716] socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 3 [pid 12716] fcntl(3, F_GETFL) = 0x2 (flags O_RDWR) [pid 12716] fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 [pid 12716] connect(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("172.19.161.85")}, 16) = -1 EINPROGRESS (Operation now in progress) [pid 12716] poll([{fd=3, events=POLLOUT|POLLWRNORM}], 1, 0) = 1 ([{fd=3, revents=POLLOUT|POLLWRNORM}]) [pid 12716] getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 [pid 12716] getpeername(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("172.19.161.85")}, [128->16]) = 0 [pid 12716] getsockname(3, {sa_family=AF_INET, sin_port=htons(43058), sin_addr=inet_addr("172.19.161.88")}, [128->16]) = 0 [pid 12716] sendto(3, "GET /resp200/ HTTP/1.1\r\nHost: 17"..., 60, MSG_NOSIGNAL, NULL, 0) = 60 [pid 12716] poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) [pid 12716] poll([{fd=3, events=POLLIN}], 1, 0) = 1 ([{fd=3, revents=POLLIN}]) [pid 12716] poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1 ([{fd=3, revents=POLLIN|POLLRDNORM}]) [pid 12716] recvfrom(3, "HTTP/1.1 200 OK\r\nServer: nginx/1"..., 16384, 0, NULL, NULL) = 184 [pid 12716] close(3) = 0 Ab: socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_IP) = 6 fcntl(6, F_GETFL) = 0x2 (flags O_RDWR) fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0 connect(6, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("172.19.161.85")}, 16) = -1 EINPROGRESS (Operation now in progress) epoll_ctl(5, EPOLL_CTL_ADD, 6, {EPOLLOUT, {u32=364313568, u64=94867601947616}}) = 0 epoll_wait(5, [{EPOLLOUT, {u32=364313568, u64=94867601947616}}], 1, 30000) = 1 connect(6, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("172.19.161.85")}, 16) = 0 epoll_ctl(5, EPOLL_CTL_DEL, 6, 0x7ffdeb1151bc) = 0 epoll_ctl(5, EPOLL_CTL_ADD, 6, {EPOLLIN, {u32=364313568, u64=94867601947616}}) = 0 write(6, "", 0) = 0 write(6, "GET /resp200/ HTTP/1.0\r\nHost: 17"..., 89) = 89 epoll_wait(5, [{EPOLLIN, {u32=364313568, u64=94867601947616}}], 1, 30000) = 1 read(6, "HTTP/1.1 200 OK\r\nServer: nginx/1"..., 8192) = 156 epoll_wait(5, [{EPOLLIN, {u32=364313568, u64=94867601947616}}], 1, 30000) = 1 read(6, "", 8192) = 0 epoll_ctl(5, EPOLL_CTL_DEL, 6, 0x7ffdeb1150cc) = 0 close(6) = 0 "perf record -F 1000 --call-graph dwarf -g" points to system "connect", but it's arguments are the same as in apache ab. Samples: 59K of event 'cpu-clock', Event count (approx.): 59066000000 Children Self Command Shared Object Symbol - 99.98% 0.03% ahsbt ahsbt [.] _Z12ThreadMethodP11SThreadDataPKcmmbbbbbl - 99.95% _Z12ThreadMethodP11SThreadDataPKcmmbbbbbl - 99.48% curl_multi_perform - 99.42% multi_runsingle - 97.56% Curl_connect - 96.95% Curl_setup_conn - 96.93% Curl_connecthost - 96.90% singleipconnect - 95.98% __libc_connect - 95.94% entry_SYSCALL_64_after_hwframe - 95.94% do_syscall_64 + 95.91% sys_connect 0.51% create_conn (inlined) + 0.57% multi_do (inlined) Issue can be observed without real network (http://localhost tests) It would be great if You help to resolve this issue or even if You have any idea why libcurl socket serial re-connection are so slow compared to apache "ab" ( it may be my ignorense in libcurl api usage etc or it's a libcurl bug) . Thanks Andrei
------------------------------------------------------------------- Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library Etiquette: https://curl.haxx.se/mail/etiquette.html
