Haproxy и openload: 40ms проблема

При тестировании сервисов за реверс-прокси HAProxy посредством утилиты openload обнаружилась занимательная вещь: любой запрос выполняется не быстрее, нежели за 40 мс! Даже с "monitor-uri /TESTME" (при наличии этой директивы во фронтэнде HAProxy сам обрабатывает запрос, сообщая о состоянии текущего фронтэнда).

Запросы openload через HAProxy:

$ openload http://127.0.0.1/TESTME 1
URL: http://127.0.0.1:80/TESTME
Clients: 1
MaTps 25.00, Tps 25.00, Resp Time 0.040, Err 0%, Count 25
MaTps 25.00, Tps 25.00, Resp Time 0.040, Err 0%, Count 50
MaTps 25.00, Tps 25.00, Resp Time 0.040, Err 0%, Count 75
MaTps 25.00, Tps 25.00, Resp Time 0.040, Err 0%, Count 100

Прямое подключение openload к серверу:

$ openload http://127.0.0.1/TESTME 1
URL: http://127.0.0.1:80/TESTME
Clients: 1
MaTps 2590.64, Tps 2590.64, Resp Time 0.000, Err 0%, Count 2601
MaTps 2609.15, Tps 2775.79, Resp Time 0.000, Err 0%, Count 5399
MaTps 2644.94, Tps 2967.00, Resp Time 0.000, Err 0%, Count 8366
MaTps 2649.39, Tps 2689.48, Resp Time 0.000, Err 0%, Count 11077

Как выяснилось, проблема таится в кривом сетевом коде openload: мало того, что сильно нагружается CPU и о тестировании производительных сервисов стоит забыть сразу, так еще и возникает указанный выше таймаут.

Забавно, конечно, что автор openload побайтово работает с данными - видимо, в Индии процессоры мощные, а интернет медленный :D Комментарий от Willy:

What is shown below clearly indicates that it will never be possible
to reach medium to high loads with this tool, it receives the response
one byte at a time ! Anyway, this is unrelated to what you're observing.

> recvfrom(3, 0x507340, 1, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable)
> select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
> select(4, [3], [], [3], {0, 200000}) = 1 (in [3], left {0, 160000})
> recvfrom(3, "H", 1, 0, NULL, NULL) = 1
> recvfrom(3, "T", 1, 0, NULL, NULL) = 1
> recvfrom(3, "T", 1, 0, NULL, NULL) = 1
> recvfrom(3, "P", 1, 0, NULL, NULL) = 1
> recvfrom(3, "/", 1, 0, NULL, NULL) = 1

Как обходной путь, для работы с openload можно добавить в конфиг фронтэндов HAProxy директиву "no option tcp-smart-accept". После тестирования лучше отключить эту директиву - для работы браузеров и т.п. она не нужна, а эффективность работы сети снижает.

Разбор проблемы от Willy:

Hehe as you can see the client's but is even more visible here,
with 40ms betweeen the two parts :

1) the connection comes in and the first half of the request is received :

10:05:38.831751 accept(4, 0x7fff071de650, [128]) = -1 EAGAIN (Resource temporarily unavailable) <0.000000>
10:05:38.831751 recvfrom(1, "GET /README HTTP/1.1\r\n", 8192, 0, NULL, NULL) = 22 <0.000000>
10:05:38.831751 recvfrom(1, 0x6a8096, 8170, 0, 0, 0) = -1 EAGAIN (Resource temporarily unavailable) <0.000000>
10:05:38.831751 epoll_ctl(0, EPOLL_CTL_ADD, 1, {EPOLLIN, {u32=1, u64=1}}) = 0 <0.000000>
10:05:38.831751 epoll_wait(0, {}, 5, 0) = 0 <0.000000>
10:05:38.831751 gettimeofday({1309413938, 831751}, NULL) = 0 <0.000000>

2) the clients remains silent for 40 ms, we're waiting for it to talk :

10:05:38.831751 epoll_wait(0, {{EPOLLIN, {u32=1, u64=1}}}, 5, 1000) = 1 <0.040000>
10:05:38.871751 gettimeofday({1309413938, 871751}, NULL) = 0 <0.000000>

3) the client finally decides to send the last part 40 ms later :

10:05:38.871751 recvfrom(1, "Connection: Close\r\nHost: 127.0.0.1\r\n\r\n", 8170, 0, NULL, NULL) = 38 <0.000000>

Большое спасибо Willy Tarreau (автор HAProxy) за помощь. Выше были приведены некоторые части нашей переписки для получения ясного представления о происхождении и решении проблемы.