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
Received on 2019-02-27