Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[D] Serverino debug/test #7409

Merged
merged 4 commits into from Apr 29, 2024
Merged

Conversation

cyrusmsk
Copy link
Contributor

Can you try to run this code for full test please?

Test other option for serverino
@cyrusmsk cyrusmsk requested a review from waghanza as a code owner April 22, 2024 08:34
@cyrusmsk
Copy link
Contributor Author

cyrusmsk commented Apr 22, 2024

@waghanza it seems some error in running script..

@waghanza
Copy link
Collaborator

@cyrusmsk

object.Exception@/root/.dub/packages/serverino/0.7.2/serverino/source/serverino/config.d(231): Configuration error. Must be minWorkers <= maxWorkers

Added MaxWorkers
@cyrusmsk
Copy link
Contributor Author

Oh it seems it was this error.
Now probably it should work

@waghanza
Copy link
Collaborator

Unfortunately no @cyrusmsk . Could you enqble logging / debug mode ?

@trikko server hang I mean I built the container, and run ito in. on an other terminal with curl http://172.17.0.2:3000 -v, I have

*   Trying 172.17.0.2:3000...
* Connected to 172.17.0.2 (172.17.0.2) port 3000 (#0)
> GET / HTTP/1.1
> Host: 172.17.0.2:3000
> User-Agent: curl/8.0.1
> Accept: */*
>
* Recv failure: Connexion ré-initialisée par le correspondant
* Closing connection 0
curl: (56) Recv failure: Connexion ré-initialisée par le correspondant

@waghanza waghanza closed this Apr 22, 2024
@waghanza waghanza reopened this Apr 22, 2024
@cyrusmsk
Copy link
Contributor Author

In my local test I received this:
curl http://localhost:3000 -v

  • Trying 127.0.0.1:3000...
  • Connected to localhost (127.0.0.1) port 3000 (#0)

GET / HTTP/1.1
Host: localhost:3000
User-Agent: curl/7.87.0
Accept: /

  • Mark bundle as not supporting multiuse
    < HTTP/1.1 200 OK
    < connection: keep-alive
    < content-length: 0
    < content-type: text/html;charset=utf-8
    <
  • Connection #0 to host localhost left intact

Bumped version to 0.7.2
@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

Is 172.17.0.2 the right ip of docker?

@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

@waghanza if you start docker with -p 3000:3000 and then you execute curl -v localhost:3000, what happens?

@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

What is serverino log saying? That could help a lot!

@waghanza
Copy link
Collaborator

where are logs produced by serverino ?

@waghanza waghanza closed this Apr 22, 2024
@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

On stderr, of course. Redirect with ./your_serverino_exe 2>log.txt

@waghanza
Copy link
Collaborator

when using curl http://172.17.0.2:3000 -v

I have

*   Trying 172.17.0.2:3000...
* Connected to 172.17.0.2 (172.17.0.2) port 3000 (#0)
> GET / HTTP/1.1
> Host: 172.17.0.2:3000
> User-Agent: curl/8.0.1
> Accept: */*
>

on server side, I have

nobody@493a850a94bd:/opt/web$ ./server
* [000008] [i] 2024-04-22 21:37 [daemon.d:0259] Daemon started.
* [000008] [i] 2024-04-22 21:37 [daemon.d:0283] Listening on http://0.0.0.0:3000/
  [000010] [l] 2024-04-22 21:38 [worker.d:0123] Worker started. (user=nobody group=nogroup)

I tried with -p @trikko

@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

Is that the complete log? It seems there's only one worker running.

If you use -p, try localhost:3000 (or the ip of the machine where it is running)

@waghanza
Copy link
Collaborator

It is what I do. Using docker inspect for that

@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

-p 3000:3000 map the docker port 3000 on the server port 3000.
So if you're running docker on your pc you can try curl localhost:3000 rather than curl 172.x.x.x:3000.

@waghanza
Copy link
Collaborator

Same @trikko

@waghanza
Copy link
Collaborator

Workers starts after a long time on server side.

Maybe we can activate some verbose level

@waghanza waghanza reopened this Apr 22, 2024
@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

Workers starts after a long time on server side.

What?! Is it the log lagging or the timestamps confirm that they start slowly? They should start in a fraction of second!

Maybe this setting will work better
@trikko
Copy link
Contributor

trikko commented Apr 22, 2024

This is serverino running on a raspberry pi (not a really powerful machine). Check the startup times!

Video.del.22-04-2024.22.32.15.webm

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

@waghanza where are you running the whole thing? On your computer? On a server? (aws? digitalocean? which kind of instance)

@waghanza
Copy link
Collaborator

On a local machine (fedora Linux) with docker, will investigate on that

@waghanza
Copy link
Collaborator

I see @trikko . I have compiled on the docker container, copied it to my local machine and execute the binary, and the results are

[waghanza@localhost:~] $ wrk -H 'Connection: keep-alive' --connections 64 --threads 8 --duration 15 --timeout 1 --script /home/waghanza/workspace/benchmark/web/pipeline_post.lua http://127.0.0.1:3000/user
Running 15s test @ http://127.0.0.1:3000/user
  8 threads and 64 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     3.70ms   31.07ms 904.99ms   98.20%
    Req/Sec     8.61k     4.18k   18.13k    75.88%
  461928 requests in 15.10s, 44.49MB read
  Socket errors: connect 0, read 10, write 0, timeout 12
Requests/sec:  30591.29
Transfer/sec:      2.95MB

@waghanza
Copy link
Collaborator

but I have a lot of errors

[waghanza@localhost:~/workspace … eb/d/serverino] serverino_test+* 12m48s ± /tmp/server 
* [018379] [i] 2024-04-23 21:36 [daemon.d:0259] Daemon started.
* [018379] [i] 2024-04-23 21:36 [daemon.d:0283] Listening on http://0.0.0.0:3000/
  [018381] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018384] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018387] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018390] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018393] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018396] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018399] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
  [018402] [l] 2024-04-23 21:36 [worker.d:0123] Worker started. (user=waghanza group=waghanza)
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer
* [018379] [l] 2024-04-23 21:36 [communicator.d:0375] Socket error on read. Connection reset by peer

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

Slow computer! rpi get 15k req/s :)

How many times did you run the test?

Typically those are not errors, but warnings. In fact wrk does not bother to close the connection at the end of the timeout but turns off the program suddenly and serverino detects an interrupted communication. So normally at the end of each test with wrk you will find a message like this for each worker.

If you try other programs (for example: bombardier) that smoothly and correctly close the connection when they are finished, you will not see any errors.

@waghanza
Copy link
Collaborator

8 core (AMD FX-8320E Eight-Core Processor) qnd 16G of RAM

and quit the same with bombardier

Bombarding http://127.0.0.1:3000 for 10s using 125 connection(s)
[========================================================================================================================================================================================================================================] 10s
Done!
Statistics        Avg      Stdev        Max
 Reqs/sec     30196.52    1558.81   33198.69
 Latency        4.13ms    83.49ms      4.00s
 HTTP codes:
   1xx - 0, 2xx - 301968, 3xx - 0, 4xx - 0, 5xx - 0
   others - 0
 Throughput:     4.70MB/s

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

Nice, no errors with bombardier, right?
It seems too slow, anyway.

I tested the version 0.7.2 on rpi4, right now:

Running 10s test @ http://localhost:8080
  8 threads and 64 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     9.82ms   75.85ms   1.64s    97.93%
    Req/Sec     5.05k     4.66k   20.77k    58.20%
  224159 requests in 10.10s, 21.59MB read
  Socket errors: connect 0, read 5, write 0, timeout 28
Requests/sec:  22197.15
Transfer/sec:      2.14MB

On my laptop (i7-12700H) I get 140-150k with both bombardier and wrk (without scripts).

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

I'm not joking!

pibench.webm

@waghanza
Copy link
Collaborator

weird on the same workstation, some nim frameworks are aroun 200K rps ;-)

but anyway, still not understand the docker layer troubles, because the problem here is not about performances, is about running or not, and why CI is OK ;-)

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

There's a good chance all this things are related in some way, isn't it?

@cyrusmsk
Copy link
Contributor Author

weird on the same workstation, some nim frameworks are aroun 200K rps ;-)

some frameworks are cheating :)

@waghanza
Copy link
Collaborator

Yes, I'm sure this is located to my machine, on github action the container is up and running, https://github.com/the-benchmarker/web-frameworks/actions/runs/8790164134/job/24121594878?pr=7409#step:7:2091

I plan to run all thos benchmark on a brand new workstation, this server is old

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

weird on the same workstation, some nim frameworks are aroun 200K rps ;-)

Yeah I know, but at least some of them I've tried are not real server. They are made just for win benchmarks, they don't even parse headers or request correctly. Not the point anyway.

@cyrusmsk
Copy link
Contributor Author

cyrusmsk commented Apr 23, 2024

don't even parse headers or request correctly.

Btw maybe worth to add such tests and requests into benchmark. To make it more "real testing", rather than absolutely synthetic and our of the real business cases.

Not the point anyway.

Agree.

But I don't understand why Docker could be the problem..

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

A simple test you can try is uploading a file with curl, it's not handled correctly by many server including httpbeast, the fastest one.

Uploading a big file (150MB!) on serverino:

andrea ~ > time curl -X POST -H "content-type: octet/stream" --data-binary @sdserverino.mp4  http://localhost:8080 -v
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 127.0.0.1:8080...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> POST / HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.81.0
> Accept: */*
> content-type: octet/stream
> Content-Length: 157915974
> Expect: 100-continue
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 100 continue
* We are completely uploaded and fine
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< connection: keep-alive
< content-length: 0
< content-type: text/html;charset=utf-8
< 
* Connection #0 to host localhost left intact

real    0m0,178s
user    0m0,020s
sys    0m0,090s

Same request, on httpbeast:

andrea ~ > time curl -X POST -H "content-type: octet/stream" --data-binary @sdserverino.mp4  http://localhost:8080 -v
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 127.0.0.1:8080...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> POST / HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.81.0
> Accept: */*
> content-type: octet/stream
> Content-Length: 157915974
> Expect: 100-continue
> 
* Done waiting for 100-continue
* We are completely uploaded and fine
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-Length: 10
< Server: HttpBeast
< Date: Tue, 23 Apr 2024 20:39:43 GMT
< 
* Connection #0 to host localhost left intact
HELLO POST
real    0m11,152s
user    0m0,054s
sys    0m0,116s```

@trikko
Copy link
Contributor

trikko commented Apr 23, 2024

don't even parse headers or request correctly.

Btw maybe worth to add such tests and requests into benchmark. To make it more "real testing", rather than absolutely synthetic and our of the real business cases.

Not the point anyway.

Agree.

But I don't understand why Docker could be the problem..

Please notice that we use regulary serverino with docker in production without any performance issue!

@waghanza
Copy link
Collaborator

So there is 3 concerns here :

  1. Why serverino hang on the setup here ?
  2. Are all servers implementation correct in here (parsing headers things) ?
  3. Add tests for point number 2

@trikko
Copy link
Contributor

trikko commented Apr 24, 2024

I have a lot of tests if you need them :)

@waghanza
Copy link
Collaborator

Be my guest @trikko. Maybe you could start a discussion on that.

Having more tests could reduce heterogeneity of implementations here

@trikko
Copy link
Contributor

trikko commented Apr 26, 2024

Workers starts after a long time on server side.

Maybe we can activate some verbose level

Could you please make a test? If they are slow to start on docker, try launch docker with an extra param --ulimit nofile=4096

Do you see any speedup?

@waghanza
Copy link
Collaborator

waghanza commented Apr 26, 2024

Workers starts instantely but still not reacheable

PS : Not understood, since the default of open files is 1073741816

@trikko
Copy link
Contributor

trikko commented Apr 26, 2024

Workers starts instantely but still not reacheable

PS : Not understood, since the default of open files is 1073741816

It's a bad default value. It's way too high, It degrades CPU performances. Now I set it to 4096 on Serverino startup if it's too high, if not set by user.

About reachability: from last release I set a custom name for processes, does it mess your config scripts?

@waghanza
Copy link
Collaborator

I can run it now, but server seems to crash at some point

PS : With number of open file to 4096

@trikko
Copy link
Contributor

trikko commented Apr 26, 2024

I can run it now, but server seems to crash at some point

PS : With number of open file to 4096

Pump up that number, it counts every fd

@waghanza
Copy link
Collaborator

I have use 10240 for next run

@trikko
Copy link
Contributor

trikko commented Apr 27, 2024

In the meanwhile I've added a workaround to serverino (that set 16384 as value) and send a pull request (already accepted) to dlang to fix the problem that is in the standard library.

@waghanza waghanza merged commit d5dfc73 into the-benchmarker:master Apr 29, 2024
2 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants