Как можно измерить производительность http сервера?

Question

[calculator212]

Прочитал статью там почти любой сервер может обработать 3-4 тыс. запрос за секунду и больше.

Я решил провести небольшое нагрузочное тестирование на таком сервере. Но результаты тестирования меня удивили. Показано всего 10 rps. Причём сервер на asio(c++) показал такие же результаты. И я пришел к выводу, что я скорее всего неправильно тестирую. Поэтому прошу мне помочь о объяснить как правильно можно проверить, какую нагрузку выдержит сервер.

Тестировал так

siege -t10S -v 127.0.0.1:8080

результаты
Response time: 2.26 secs
Transaction rate: 10.63 trans/sec
Throughput: 0.06 MB/sec

package main

import (
	"log"
	"net/http"
)

func main() {

	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		w.WriteHeader(200)
		w.Write([]byte("Hello"))
	})

	log.Fatal(http.ListenAndServe(":8080", nil))

}

Answer 1

[Евгений Мамонов]

Для подобного тестового кода можно использовать ab (Apache HTTP server benchmarking tool)

Например так
ab -n 10000 -c 1000 http://localhost:8080/

Где:
-n это количество запросов, которое нужно сделать
-с это количество одновременных запросов

Запустил у себя на одном из серверов, результат вот такой

Server Software:
Server Hostname:        localhost
Server Port:            8080

Document Path:          /
Document Length:        5 bytes

Concurrency Level:      1000
Time taken for tests:   0.509 seconds
Complete requests:      10000
Failed requests:        0
Write errors:           0
Total transferred:      1210000 bytes
HTML transferred:       50000 bytes
Requests per second:    19627.39 [#/sec] (mean)
Time per request:       50.949 [ms] (mean)
Time per request:       0.051 [ms] (mean, across all concurrent requests)
Transfer rate:          2319.25 [Kbytes/sec] received

Т.е. при 1000 одновременных запросов сервер сможет обрабатывать в среднем 19627 запросов в секунду

Но важно понимать, что в реальном проекте у вас будет не один endpoint, и что каждый endpoint, в зависимости от того, что он будет делать - будет показывать разный RPS.

Например если сейчас вы добавите еще один endpoint и будете делать запросы в базу для формирования ответа - RPS будет значительно меньше.

Comments

[calculator212]

Запустил такую команду,

ab -n 1000 -c 100 localhost:3000

но получилось примерно так
Requests per second: 34.65 [#/sec] (mean)
Time per request: 2885.699 [ms] (mean)

полный лог

erver Software:        
Server Hostname:        localhost
Server Port:            3000

Document Path:          /
Document Length:        1754 bytes

Concurrency Level:      100
Time taken for tests:   28.857 seconds
Complete requests:      1000
Failed requests:        0
Total transferred:      1857000 bytes
HTML transferred:       1754000 bytes
Requests per second:    34.65 [#/sec] (mean)
Time per request:       2885.699 [ms] (mean)
Time per request:       28.857 [ms] (mean, across all concurrent requests)
Transfer rate:          62.84 [Kbytes/sec] received

[calculator212]

Грубо говоря 30 rps, как-то странно. Например Через Postman отправляю запрос, то первый ответ от него идет около 2 секунд а потом по 2-3 мс.

[Евгений Мамонов]

Вы тестируете этот скрипт?
Если да - тогда запрос приходит куда-то не туда (не в Go сервер), у вас Document Length должен быть 5 байт (Hello), а у вас 1754 байта. Но что-то ооочень медленно.

[calculator212]

https://github.com/wg/wrk а через эту штуку с такой командой
./wrk -c 200 -d 10 127.0.0.1:3000

показывает такие цифры

2 threads and 200 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 97.84ms 313.58ms 1.69s 91.41%
Req/Sec 34.62k 4.71k 40.00k 93.75%
552905 requests in 10.01s, 0.96GB read
Requests/sec: 55212.51
Transfer/sec: 97.78MB

[Евгений Мамонов]

выполните ab -v 4 http://localhost:3000/, чтобы убедиться, что получаете верное содержимое ответа, чтобы быть на 100% уверенным, что отвечает именно сервер Go
Должно быть что-то подобное

---
GET / HTTP/1.0
Host: localhost:11223
User-Agent: ApacheBench/2.3
Accept: */*


---
LOG: header received:
HTTP/1.0 200 OK
Date: Tue, 28 Dec 2021 14:29:27 GMT
Content-Length: 5
Content-Type: text/plain; charset=utf-8

Hello
LOG: Response code = 200
..done

[Евгений Мамонов]

После этого уже можно будет продолжить искать причину

[calculator212]

Евгений Мамонов,

Всё поправил(был запущен еще один сервер). Но в целом ничего не изменилось

Total transferred: 121000 bytes
HTML transferred: 5000 bytes
Requests per second: 38.07 [#/sec] (mean)
Time per request: 2626.594 [ms] (mean)

ab -v 4 localhost:8080

spoiler

Benchmarking localhost (be patient)...INFO: GET header ==
---
GET / HTTP/1.0
Host: localhost:8080
User-Agent: ApacheBench/2.3
Accept: */*

---
LOG: header received:
HTTP/1.0 200 OK
Date: Tue, 28 Dec 2021 14:41:49 GMT
Content-Length: 5
Content-Type: text/plain; charset=utf-8

Hello
LOG: Response code = 200
..done

Server Software:
Server Hostname: localhost
Server Port: 8080

Document Path: /
Document Length: 5 bytes

Concurrency Level: 1
Time taken for tests: 0.012 seconds
Complete requests: 1
Failed requests: 0
Total transferred: 121 bytes
HTML transferred: 5 bytes
Requests per second: 83.74 [#/sec] (mean)
Time per request: 11.942 [ms] (mean)
Time per request: 11.942 [ms] (mean, across all concurrent requests)
Transfer rate: 9.89 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 12 12 0.0 12 12
Processing: 0 0 0.0 0 0
Waiting: 0 0 0.0 0 0
Total: 12 12 0.0 12 12

ab -n 1000 -c 100 localhost:8080

spoiler

Server Software:
Server Hostname: localhost
Server Port: 8080

Document Path: /
Document Length: 5 bytes

Concurrency Level: 100
Time taken for tests: 26.266 seconds
Complete requests: 1000
Failed requests: 0
Total transferred: 121000 bytes
HTML transferred: 5000 bytes
Requests per second: 38.07 [#/sec] (mean)
Time per request: 2626.594 [ms] (mean)
Time per request: 26.266 [ms] (mean, across all concurrent requests)
Transfer rate: 4.50 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 12 356 191.4 432 646
Processing: 1997 2068 100.2 2041 2537
Waiting: 1997 2048 102.9 2013 2534
Total: 2019 2424 190.2 2502 2723

Percentage of the requests served within a certain time (ms)
50% 2502
66% 2544
75% 2580
80% 2599
90% 2643
95% 2669
98% 2688
99% 2722
100% 2723 (longest request)

[Евгений Мамонов]

Выглядит неправдоподобно даже для локальной машины.
Насколько на этой машине нагружены диск и CPU?
Windows/Linux/Mac?

[calculator212]

Евгений Мамонов, уже только завтра смогу проверить, и ответить. Но похоже вы правы и на машине, что-то не так с диском(процессор точно не сильно нагружен).
Я проверил на другой машине, такое же тестирование показало
Requests per second: 12469.59 [#/sec] (mean)

[Евгений Мамонов]

Вот это уже похоже на правду.
Этот тест не может показывать плохие результаты, т.к. в endpoint'e нет ничего такого, что могло бы вызывать такие "тормоза".

Даже слабый сервер на таком коде должен успевать обрабатывать тысячи запросов в секунду.
И даже старый домашний ноутбук )))

При тех показателях, что у вас - определённо что-то не так с самим компьютером.
Скорее всего какой то процесс вызывает огромную нагрузку.

Чаще всего это бывает неправильно настроенный бэкап, когда параллельно делается дамп файлов, базы и т.д., когда load avg взлетает до небес, может даже вирус какой то-то.
Но скорее всего что-то программное.

Запустите top и посмотрите что вызывает такую нагрузку.
Обратите внимание на параметр (io wait), может быть написан как wa.
Если он большой - значит нагрузка на диск большая, запустите iotop или что-то подобное и посмотрите какой процесс "ест" ресурсы.

[calculator212]

Евгений Мамонов,
wa может поднимается до 30

top - 12:30:37 up 43 min, 1 user, load average: 1.52, 2.70, 2.35
Tasks: 441 total, 1 running, 440 sleeping, 0 stopped, 0 zombie
%Cpu(s): 1.3 us, 0.7 sy, 0.0 ni, 98.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
MiB Mem : 15919.4 total, 6726.5 free, 3153.9 used, 6039.0 buff/cache
MiB Swap: 4096.0 total, 4096.0 free, 0.0 used. 12356.7 avail Mem

есть явно проблемы с записью на диск (при старте системы показывало от 80 до 200 мб/с)
dd if=/dev/zero of=/tmp/test1.img bs=1M count=1024 oflag=dsync
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 346.377 s, 3.1 MB/s

чтение
Timing cached reads: 42970 MB in 2.00 seconds = 21531.72 MB/sec
Timing buffered disk reads: 512 MB in 3.00 seconds = 170.58 MB/sec

sudo hdparm -Tt /dev/sdb

[Евгений Мамонов]

По этим данным очень трудно понять действительно ли есть проблемы с диском или нет
У вас может быть нагрузка на базу большая и по этому нагрузка на диск большая и в вашей ситуации для этого сервера это может быть вообще нормой.
Хотя wa 30 - это многовато.

Что у вас на этом сервере работает?

Нужно понять кто "ест" ресурсы диска, запустите iotop, сразу станет понятно.

[calculator212]

Евгений Мамонов, При запуске этой команды dd if=/dev/zero of=/tmp/test1.img bs=1M count=1024 oflag=dsync показывает 3-4 мб на запись и загрузку на 100%, если ничего не запускать то в основном по нулям, иногда происходят небольшие записи, которые грузят диск от 20 до 50%. Если запустить сервер и тестировать его, то ничего не меняется. Я загрузил диск полностью и провёл тестирование, но результаты такие же, не уверен, но возможно упирается не в диск.

[Евгений Мамонов]

Это виртуальная машина или отдельный сервер?,
Какие у него параметры?
Посмотрите внимательно логи в /var/log всё, что есть.
Load avg какой когда "всё тихо"?
Если сервер ничем не нагружен выглядит как аппаратная проблема.