katta

katta

I having some trouble figuring out if I have set myself too strict of standards for my production server. Currently I can handle 75% of requests in under 6ms, but my 90th percentile begins to show times that are closer to 75-100ms and the reason for these longer requests is something in the ecto library taking a while to return, because inside datadog I can see that the query_time field of the EctoLogEntry is what is taking 70 out of the 75ms of time. I wasn’t able to find a bunch of benchmarks from other peoples experiences online that use Ecto requests as part of the benchmark.

I would like to get all of my requests under 20ms, but I just don’t know if this is realistic or not. Could anybody she any light on what they would expect me to be able to achieve from a performance perspective as far as the latency times for request?

Showing Posts 1 to 10

brightball

brightball

Off the cuff I’d assume something is waiting for a database connection?

axelson

axelson

Scenic Core Team

Sounds interesting, what is your pool size set to?

katta

katta OP

We have our pool size set to 10 and we are running two pods inside a kubernetes cluster. So we see a total of 20 active connections to the postgres Db inside Aurora on our AWS dashboard. The way the ecto log entry is defined I would’ve thought the queue_time field of the EctoLogEntry would be the time it takes to check out a connection from the pool. The part that is taking longer is the query_time field of the log entry, but what is weird is on the DB itself we can see that every single query runs in under 1 ms because we are doing just simple selects on small tables and there is no reason for this latency. Do you think it could still be a connection problem if the queue_time field is under 1ms? Is there something about the queue_time and connections to the db that I’m not understanding properly?

Also, the latency only ever occurs randomly on the first Ecto call on any given network request. So if route A hits ecto 3 times, the only one with random slow latency is that first ecto call no matter what the query is. I’ve tried different routes with different first queries and they all randomly are slow around the 90th percentile.

josevalim

josevalim

Creator of Elixir

Since the slow down is on query_time, then it is definitely not a connection issue, as that would show on queue_time.

It is important to keep in mind that though that queue_time includes all the time we hold the database connection so if for some reason the current process is being scheduled out for another process to run, then the queue_time will have those spikes.

So in theory, I wouldn’t worry about queue_time if the response times are not seeing such variance. For example, imagine this code:

do_something
do_a_query
do_something_else

Sometimes the scheduler will swap on “do something”, sometimes inside the query and sometimes after the query. That’s why from time to time you see such a variance.

However, in practice, your variance is quite high, which may mean that the system is overloaded. The Erlang/VM is capable of handling overload well but this may be one of the symptoms. I would start measuring the run_queue and other values to see if that’s the case or not.

EDIT: Also please let us know your Ecto version and, if you have recently updated to Ecto 3, let us know if you saw this issue before or if it is something recent.

katta

katta OP

We were on Ecto 2.2 before and we just upgraded to 3.0 in hopes that it would fix our issues, but nothing changed. Also I pulled the metrics for our CPU over time and we never go above 5% utilization. However just because we don’t go above 5% doesn’t mean that we don’t already have processes running on all the cores in parallel and things aren’t getting context swtiched out right? or am I misunderstanding CPU load? I haven’t had a chance to dig into the run_queue of the system yet, but even if we find something in there what would I be able to do to prevent some sort of unwanted context switch? Is there somewhere in our project I should try to manually raise the priority level for the process in order to attempt to not get preempted while we go to the Db to make a query?

axelson

axelson

Scenic Core Team

Would it be possible to produce a reproducible example in a repo?

katta

katta OP

I can’t reproduce the random latency locally, but that might have to do with the fact that i have the server and db both on the same machine. Does anyone have any benchmarks or know of somewhere else where someone has done a good job documenting their latencies and response times in a production like environment?

amnu3387

amnu3387

It can even be your database itself - for instance if a certain query would produce 0 results it can behave strangely even when indexed on a reasonable column, I’ve seen queries that usually take ms’s timeout on that. Adding composite indexes for the relevant fields helped and brought them back to the ms’ range - not saying this is the case, but in mine I was sure it was Postgresql as I re-ran those in psql connected to the actual database, they took long, and explaining the query showed the planner thought it to be reasonably fast, but in practice it wasn’t what was happening.

katta

katta OP

I have already dug into the logs on our postgres instance and every single query has run in under 1ms. We are really just doing selects on small tables as of now because this is a new service. The extra random time occurs in between the database and the ecto process that needs to return the data. My only thought at this point is that when the ecto call is made the parent thread blocks while it waits for the result and then gets context switched out by another process because the scheduler is trying to be efficient and then it is just taking a while for the parent process to resume and read the data from the Ecto call. This is completely all speculation though. Even if this is the case it is not going to be trivial to fix. The main reason I’m trying to see if anyone else has any benchmarks is so I can determine if I should keep looking into this or if this is something other people have experienced.

Schultzer

Schultzer

I’ve been looking for the same thing, but benchmark on Ecto is hard to come by, but my work has revealed a lot of issues in Ecto when it comes to high concurrency:

These results are from an upcoming release laptop on battery, so real world should be even better:


➜  sql_bench git:(main) ✗ \_build/prod/rel/sql_bench/bin/sql_bench rpc "SQLBench.run_all()"

==========================================================================

Starting SQLBench Suites (Schedulers: 10)

==========================================================================



\### Performance Comparison: sql vs ecto



:mag: Target SQL: \`SELECT \* FROM information_schema.columns\`

| Concurrency | Impl | Total Req | OK Req | p50 | p95 | p99 | Max | Errors (p50 / p99) | Comparison |

|---|---|---|---|---|---|---|---|---|---|

| C = 1       | sql  | 35        | 35     | 53.5ms  | 56.4ms  | 65.8ms  | 128.0ms | 0                  | sql 1.1x faster, +4 OK                 |

| C = 1       | ecto | 31        | 31     | 59.4ms  | 71.5ms  | 71.5ms  | 94.8ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 10      | sql  | 240       | 240    | 80.5ms  | 99.7ms  | 109.7ms | 122.1ms | 0                  | sql 1.0x faster, +4 OK                 |

| C = 10      | ecto | 236       | 236    | 82.7ms  | 93.6ms  | 98.2ms  | 103.6ms | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 20      | sql  | 443       | 242    | 118.9ms | 135.3ms | 140.4ms | 144.2ms | 201 (50.8ms / 57.6ms) | sql 1.5x faster, +29 OK (fast-failing works) |

| C = 20      | ecto | 213       | 213    | 175.9ms | 205.7ms | 228.8ms | 238.7ms | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 50      | sql  | 1569      | 237    | 126.7ms | 140.1ms | 146.3ms | 159.6ms | 1332 (51.0ms / 60.2ms) | sql 3.3x faster, +26 OK (fast-failing works) |

| C = 50      | ecto | 211       | 211    | 419.2ms | 571.2ms | 615.1ms | 668.9ms | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 100     | sql  | 3517      | 236    | 118.9ms | 128.8ms | 130.6ms | 134.2ms | 3281 (51.0ms / 55.3ms) | sql 1.5x faster, +17 OK (fast-failing works) |

| C = 100     | ecto | 1582      | 219    | 178.4ms | 198.1ms | 201.5ms | 208.2ms | 1363 (108.7ms / 133.3ms) |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 500     | sql  | 19222     | 222    | 113.9ms | 121.3ms | 124.8ms | 126.4ms | 19000 (51.0ms / 52.1ms) | sql 9.8x faster, +38 OK (fast-failing works) |

| C = 500     | ecto | 184       | 184    | 1120.1ms | 1907.1ms | 1964.2ms | 1981.3ms | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|



\### Performance Comparison: sql vs ecto



:mag: Target SQL: \`BEGIN; COMMIT; -- Empty transaction\`

| Concurrency | Impl | Total Req | OK Req | p50 | p95 | p99 | Max | Errors (p50 / p99) | Comparison |

|---|---|---|---|---|---|---|---|---|---|

| C = 1       | sql  | 115816    | 115816 | 9us     | 37us    | 43us    | 49.2ms  | 0                  | sql 10.1x faster, +99.5k OK            |

| C = 1       | ecto | 16339     | 16339  | 91us    | 174us   | 640us   | 96.8ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 10      | sql  | 169713    | 169713 | 118us   | 195us   | 231us   | 926us   | 0                  | sql 2.0x faster, +85.7k OK             |

| C = 10      | ecto | 84036     | 84036  | 233us   | 319us   | 364us   | 1.6ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 20      | sql  | 173594    | 173594 | 232us   | 319us   | 356us   | 917us   | 0                  | sql 1.7x faster, +87.9k OK             |

| C = 20      | ecto | 85682     | 85682  | 396us   | 957us   | 1.2ms   | 2.5ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 50      | sql  | 175790    | 175790 | 567us   | 697us   | 756us   | 949us   | 0                  | sql 2.0x faster, +90.1k OK             |

| C = 50      | ecto | 85667     | 85667  | 1.2ms   | 1.8ms   | 2.0ms   | 3.3ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 100     | sql  | 174139    | 174139 | 1.1ms   | 1.4ms   | 1.4ms   | 1.6ms   | 0                  | sql 2.1x faster, +89.3k OK             |

| C = 100     | ecto | 84848     | 84848  | 2.4ms   | 3.0ms   | 3.2ms   | 4.7ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 500     | sql  | 169948    | 169948 | 5.9ms   | 6.3ms   | 6.5ms   | 6.8ms   | 0                  | sql 2.0x faster, +87.6k OK             |

| C = 500     | ecto | 82300     | 82300  | 12.1ms  | 13.2ms  | 13.6ms  | 14.4ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|



\### Performance Comparison: sql vs ecto



:mag: Target SQL: \`BEGIN; SELECT 1; COMMIT;\`

| Concurrency | Impl | Total Req | OK Req | p50 | p95 | p99 | Max | Errors (p50 / p99) | Comparison |

|---|---|---|---|---|---|---|---|---|---|

| C = 1       | sql  | 31672     | 31672  | 63us    | 79us    | 85us    | 249us   | 0                  | sql 3.0x faster, +23.0k OK             |

| C = 1       | ecto | 8710      | 8710   | 189us   | 337us   | 847us   | 5.5ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 10      | sql  | 76257     | 76257  | 259us   | 347us   | 405us   | 2.2ms   | 0                  | sql 1.7x faster, +30.8k OK             |

| C = 10      | ecto | 45450     | 45450  | 434us   | 545us   | 600us   | 2.5ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 20      | sql  | 76029     | 76029  | 522us   | 620us   | 673us   | 2.9ms   | 0                  | sql 1.6x faster, +30.6k OK             |

| C = 20      | ecto | 45384     | 45384  | 845us   | 1.5ms   | 1.7ms   | 4.1ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 50      | sql  | 76380     | 76380  | 1.3ms   | 1.4ms   | 1.5ms   | 2.8ms   | 0                  | sql 1.7x faster, +31.1k OK             |

| C = 50      | ecto | 45251     | 45251  | 2.2ms   | 2.8ms   | 3.0ms   | 5.6ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 100     | sql  | 75935     | 75935  | 2.6ms   | 2.8ms   | 2.9ms   | 3.7ms   | 0                  | sql 1.7x faster, +30.7k OK             |

| C = 100     | ecto | 45224     | 45224  | 4.4ms   | 5.1ms   | 5.3ms   | 7.4ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 500     | sql  | 75665     | 75665  | 13.2ms  | 13.8ms  | 14.0ms  | 14.4ms  | 0                  | sql 1.7x faster, +32.2k OK             |

| C = 500     | ecto | 43457     | 43457  | 22.9ms  | 24.4ms  | 24.8ms  | 26.0ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|



\### Performance Comparison: sql vs ecto



:mag: Target SQL: \`BEGIN; SAVEPOINT sp1; SELECT 1; RELEASE SAVEPOINT sp1; COMMIT;\`

| Concurrency | Impl | Total Req | OK Req | p50 | p95 | p99 | Max | Errors (p50 / p99) | Comparison |

|---|---|---|---|---|---|---|---|---|---|

| C = 1       | sql  | 27730     | 27730  | 72us    | 88us    | 99us    | 8.1ms   | 0                  | sql 2.7x faster, +18.8k OK             |

| C = 1       | ecto | 8897      | 8897   | 192us   | 338us   | 752us   | 22.1ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 10      | sql  | 65762     | 65762  | 299us   | 396us   | 472us   | 2.9ms   | 0                  | sql 1.4x faster, +19.9k OK             |

| C = 10      | ecto | 45891     | 45891  | 429us   | 538us   | 592us   | 4.4ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 20      | sql  | 66109     | 66109  | 602us   | 700us   | 749us   | 3.2ms   | 0                  | sql 1.4x faster, +20.5k OK             |

| C = 20      | ecto | 45609     | 45609  | 841us   | 1.5ms   | 1.7ms   | 5.7ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 50      | sql  | 66410     | 66410  | 1.5ms   | 1.7ms   | 1.8ms   | 11.6ms  | 0                  | sql 1.5x faster, +21.4k OK             |

| C = 50      | ecto | 45005     | 45005  | 2.2ms   | 2.9ms   | 3.1ms   | 6.4ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 100     | sql  | 67764     | 67764  | 2.9ms   | 3.2ms   | 3.3ms   | 8.6ms   | 0                  | sql 1.5x faster, +22.6k OK             |

| C = 100     | ecto | 45172     | 45172  | 4.4ms   | 5.1ms   | 5.3ms   | 8.9ms   | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 500     | sql  | 66520     | 66520  | 14.9ms  | 16.0ms  | 16.2ms  | 17.6ms  | 0                  | sql 1.5x faster, +23.1k OK             |

| C = 500     | ecto | 43434     | 43434  | 22.9ms  | 24.5ms  | 25.9ms  | 28.4ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|



\### Performance Comparison: sql vs ecto



:mag: Target SQL: \`DECLARE cursor... FETCH 100 FROM generate_series(1, 10000)\`

| Concurrency | Impl | Total Req | OK Req | p50 | p95 | p99 | Max | Errors (p50 / p99) | Comparison |

|---|---|---|---|---|---|---|---|---|---|

| C = 1       | sql  | 313       | 313    | 6.3ms   | 6.5ms   | 6.7ms   | 19.4ms  | 0                  | sql 2.3x faster, +183 OK               |

| C = 1       | ecto | 130       | 130    | 14.5ms  | 20.7ms  | 21.8ms  | 69.8ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 10      | sql  | 9561      | 1324   | 8.2ms   | 9.2ms   | 9.5ms   | 9.9ms   | 8237 (1.1ms / 1.8ms) | sql 2.9x faster, +498 OK (fast-failing works) |

| C = 10      | ecto | 826       | 826    | 23.9ms  | 25.4ms  | 28.2ms  | 40.3ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 20      | sql  | 9841      | 1331   | 10.3ms  | 11.3ms  | 11.8ms  | 13.2ms  | 8510 (3.1ms / 4.1ms) | sql 4.7x faster, +512 OK (fast-failing works) |

| C = 20      | ecto | 819       | 819    | 48.3ms  | 49.9ms  | 51.9ms  | 72.8ms  | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 50      | sql  | 9741      | 1319   | 16.5ms  | 17.8ms  | 18.5ms  | 20.7ms  | 8422 (9.3ms / 10.8ms) | sql 7.5x faster, +531 OK (fast-failing works) |

| C = 50      | ecto | 788       | 788    | 123.1ms | 128.6ms | 159.8ms | 176.7ms | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 100     | sql  | 9804      | 1300   | 26.7ms  | 28.7ms  | 30.8ms  | 37.1ms  | 8504 (19.3ms / 23.1ms) | sql 9.2x faster, +535 OK (fast-failing works) |

| C = 100     | ecto | 765       | 765    | 245.5ms | 270.2ms | 343.7ms | 368.0ms | 0                  |                                        |

|---|---|---|---|---|---|---|---|---|---|

| C = 500     | sql  | 19671     | 1246   | 57.8ms  | 59.1ms  | 60.0ms  | 60.9ms  | 18425 (50.7ms / 51.5ms) | sql 2.1x faster, +481 OK (fast-failing works) |

| C = 500     | ecto | 9368      | 765    | 122.4ms | 125.7ms | 127.4ms | 131.5ms | 8603 (103.3ms / 113.4ms) |                                        |

|---|---|---|---|---|---|---|---|---|---|



==========================================================================

All Benchmark Suites Completed.

==========================================================================

Where Next? Top

Trending in Questions Top

stjefim
Hello! Suppose you are building workflow (order / task / payment) processing system with the following requirements: Each workflow con...
New
water
I’m aware of 2 such projects, are there others? git: GitHub - team-alembic/realworld: A fullstack Phoenix LiveView application with back...
New
peck
Hi everyone. My team and I have been working on a fairly modest app based around video streaming and chat, but we’ve landed a customer t...
New
bradley
I really like the adapter patterns that ecto, nebulex, waffle, etc. use and would love find something similar for a key management servic...
New
unaware8150
Hello folks! So at work, we are seeing some situations where we have to define some “fixed” strings that are used across the codebase in...
New
Alvinkariuki
How Can I Optimise Compile Time Dependencies I have been building an elixir application for about 2 years now. Many modules and files ha...
New
leoschweizer
Hi, we run different LLM models across a cluster, with each node loading a configurable subset. Model-specific queues let nodes consume ...
New

Other Trending Topics Top

mudasobwa
I fully migrated to my own harness from Anthropic/Gemini and I think it’s time to share it. Welcome DSH, the DeepSeek Harness, fully writ...
New
KristerV
Hey. Is there anyone here who creates agents in their apps? Not talking about using agents, but creating them. I’m finding it pretty diff...
New
jimsynz
Beam Bots (or just BB for short) is a framework for building fault-tolerant robotics applications in Elixir using familiar OTP patterns. ...
New
juhalehtonen
There has been a thread to discuss the Stack Overflow Developer Survey on this forum every year since 2018, so here’s yet another one for...
New
webofbits
With AI doing more of the implementation work, I’ve been wondering how much coding I should deliberately keep doing myself. My main conc...
#ai
New
budgie
I love Elixir. It’s one of 2 programming languages I’ve ever fallen in love with. But I don’t use it anymore. Serverless was the promis...
New

We're in Beta

About us Mission Statement

Options

Thread Display Mode




Thread Preview

Skip Thread Previews