Gateway service throttling issue

[vvasilevbosch]

I have an issue with the gateway service, while doing some testing. My setup is 1 instance of each service, all having 5Gb of memory.

I run a warmup phase, reading a total of 10,000 things via the gateway, which get cached.
I send 1310 search commands(?filter=eq(thingId,'${id}')) per second via the gateway for 5 minutes and the whole time taken for a single request is ~10s according to 'HTTP Command Processing Time (2xx)' grafana panel. What I notice in the logs is that things-search service receives the command from the gateway service after ~10s. Also in grafana 'signal processing times' panel is seen that the signals are processed in less than 20ms.

When sending 1300 requests/s the total time is <20ms, so it seems I hit some limit, because 10 requests/s makes a huge difference in total processing time. GC dashboard shows no spikes in memory or GC time for gateway. I tried playing with ActiveProcessorCount, a value of 8 is what I found best performance with, the node that the service runs on has 8 cpus. After the problem occurs, as can be seen on '# of messages in mailbox' panel, 'org.eclipse.ditto.gateway.service.proxy.actors.GatewayProxyActor' actor mailbox increases to ~4k and keeps that number during the remaining time of the test.

Another thing is that a lot of the requests I send get timed out, with error of:
"error":"read: connection reset by peer","error_code":1220, from k6 docs: https://k6.io/docs/testing-guides/running-large-tests/#read-connection-reset-by-peer

Also I get this error, which is related to the previous one:
"error":"dial: i/o timeout","error_code":1211, from k6 docs: https://k6.io/docs/testing-guides/running-large-tests/#dial-tcp-52-18-24-222-80-i-o-timeout

In total, http_req_failed: 13.80%, 53016 out of 330985, because of these two errors.

What I tried is different values for these http akka server properties, from https://doc.akka.io/docs/akka-http/current/configuration.html:
akka.http.server.pipelining-limit - default 1, tried 128, 512, 1024, made no difference in the results
akka.http.server.max-connections - default 1024, tried with 4096, no difference
akka.http.server.backlog - default 100, tried 200, 1000, no difference

checking the file descriptor limits on the gateway pod with 'ulimit -a' returns the following:
time(seconds) unlimited
file(blocks) unlimited
data(kbytes) unlimited
stack(kbytes) 10240
coredump(blocks) unlimited
memory(kbytes) unlimited
locked memory(kbytes) unlimited
process unlimited
nofiles 1048576
vmemory(kbytes) unlimited
locks unlimited
rtprio 0

Doing the same with 2 gateway instances shows the same results, but with 2 times more requests/s. I feel like I am maybe missing some akka configuration.
Attached screenshots from test runs and log for a single request, that took >10s.
screenshots.zip
logs.csv

[thjaeckle]

Hi @vvasilevbosch
I took a quick look - and wanted to ask:

• What do you expect to reach for numbers with only "single instance per service"?
• You are doing ~1.000 search requests via HTTP per second with a "single instance per service" setup?
  • That is an impressive number in my opinion without any horizontal scaling applied .. Resoning:
    • Search is one of the "most expensive" operations to do
    • HTTP serving is intended to be scaled horizontally (e.g. also because of max open ports topics, connection pools, etc.)

You wrote:

Doing the same with 2 gateway instances shows the same results, but with 2 times more requests/s. I feel like I am maybe missing some akka configuration.

• That sounds like an awesome finding regarding ability of Ditto to scale horizontally
  • Ideally you would e.g. determine that a single gateway can serve ~1.300 HTTP requests per second and 2 gateways can serve ~2.600 requests per second
  • If that is the case and you e.g. even verify with 4 gateways that ~5.200 HTTP requests per second can be served you "proofed" Ditto to scale horizontally

After the problem occurs, as can be seen on '# of messages in mailbox' panel, 'org.eclipse.ditto.gateway.service.proxy.actors.GatewayProxyActor' actor mailbox increases to ~4k and keeps that number during the remaining time of the test.

To me this sounds like an expected behavior to find some kind of "max throughput" for a single actor being able to handle.
1.300 msgs per second means that the actor takes ~0,77 milliseconds per message to process (forwarding into the Ditto cluster).
Sounds reasonable to me.

There is an Akka setting of outbound-lanes (defaulting to 1 - Ditto can overwrite it with environment variable REMOTE_OUTBOUND_LANES) which could improve the number per instance.
This however has the side-effect that order of messages will no longer be guaranteed.

So to be honest I don't actually see a real "problem" ;)

[vvasilevbosch]

What do you expect to reach for numbers with only "single instance per service"?

I just try to see what is the maximum amount of requests handled by this setup, but it feels 1000 is a small number, considering the search takes <20ms, according to metrics and logs, shouldn't gateway service just wrap and dispatch the commands to the other services?

Search is one of the "most expensive" operations to do

Yes, but on the metrics and logs can be seen that the search is actually very fast <20ms

Doing the same with 2 gateway instances shows the same results, but with 2 times more requests/s. I feel like I am maybe missing some akka configuration.

Regarding this, I mislead you, I must have tested something else, retrying to achieve this, I needed 5 gateways to handle ~2600 requests/s and handling 1310 requests/s with 2 gateways. The maximum requests/s for 2 gateways is ~1400. Overall I feel like it is not scaling well horizontally.

[thjaeckle]

Regarding this, I mislead you, I must have tested something else, retrying to achieve this, I needed 5 gateways to handle ~2600 requests/s and handling 1310 requests/s with 2 gateways. The maximum requests/s for 2 gateways is ~1400. Overall I feel like it is not scaling well horizontally.

Ok, this is a completely different statement.
Are both of these 2 gateway instances then handling the same "load" (as of CPU load)?
And do you have an nginx in front of the gateway? If yes, how much scaled and what does its CPU/worker metrics say?

And how much "things" and "things-search" instances are involved?

I think it does not make sense to provide load metrics for "single instance" setup at all, as this is a non-realistic setup because of missing high availability.

Did you do the same test with GET /things/<thingId>?
That should be the fastest request and only involves querying a single service, "things".

[vvasilevbosch]

Are both of these 2 gateway instances then handling the same "load" (as of CPU load)?

Yes, checking with kubectl top, they seem to be handling the same cpu load

And do you have an nginx in front of the gateway? If yes, how much scaled and what does its CPU/worker metrics say?

No nginx, only ClusterIP service

And how much "things" and "things-search" instances are involved?

I used only single instance of both, scaling to 2 or more doesn't increase the amount of handled requests for 1 or 2 gateways.

I think it does not make sense to provide load metrics for "single instance" setup at all, as this is a non-realistic setup because of missing high availability.

Yes, I agree, just wanted to know what to expect when scaling.

Did you do the same test with GET /things/?
That should be the fastest request and only involves querying a single service, "things".

Yes, using GET by thingId has better performance and seems to scale well, f.e. with 1 gateway and 1 things I was able to reach ~2000 requests/s. Scaling to 2 gateways - ~3800, scaling things to 2 instances - ~4000. 3 gateways, 1 things - ~5000, 3 gateways, 2 things - ~5500

One more thing I noticed today is that the worker nodes are not very stable. Sometimes I can't even reach 500 searches/s with the same setup I reached 1000. And also today, I managed to get ~2300 searches with 2 gateways, so it seems it scales alright. I still don't understand why is the sudden spike in processing time, from milliseconds to 10 seconds in the matter of 10-50 more searches/s, with signal processing time panel showing <20ms prcoessing for query thing

[thjaeckle]

I still don't understand why is the sudden spike in processing time, from milliseconds to 10 seconds in the matter of 10-50 more searches/s

Do you use a hosted MondoDB atlas and check its metrics as well?
Could also be that read tickets are going down at a certain level for a booked service plan of Atlas.

Either way..
Using that many searches per second is probably not the best test case.
From my experience search requests are at least 100 times more seldom than eg updates.

[vvasilevbosch]

I use Atlas MongoDB, metrics show ~20ms max operation execution times, and ~30% max cpu usage. The least amount of available read tickets is 125