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

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 r...
New
brecabral
Documentation While reading the Scoped Routes section, I noticed that the documentation currently refers to a problem without explainin...
New
nseaSeb
Hello, I know there is an approach for handling lists that allows for optimized traversal, but I can’t recall the specific method (somet...
New
achenet
Hello, I’m trying to build a basic Phoenix web-app, and I’d like to use Tailwind. However, when I launch mix phx.server, I get an error...
New
kpanic
Hi everyone, I am toying with the idea of building a “match maker” for giving personal help to people that wants to start coding. I sta...
New
velrest
So my question is quite simple and i have found no conclusive answer on forum, google or AI. Should we use :erlang.float for Integer to ...
New
asweet-confluent
I recently noticed that Elixir’s Logger defaults its primary log level to :debug when no :logger, :level application configuration is pre...
New

Other Trending Topics Top

GenericJam
Edit: 2026 May 15 - This post is archived. Mob is alive!! Main docs: mob v0.7.11 — Documentation A bit of explanation for the slightly c...
New
JesseHerrick
Hey, I’m Jesse and I’m the main contributor behind Dexter, a full-featured, lightning-fast Elixir LSP optimized for large codebases. It s...
New
mudasobwa
I am happy to introduce the very α version of the new programming language compiled to BEAM. Welcome Cure. It has literally three kille...
New
garrison
Hobbes is a low-level distributed database for the Elixir programming language. Hobbes provides a simple, safe, and scalable storage lay...
New
mhanberg
Hi everyone! The first release candidate for the Expert language server project is now available! We’ve published a press release detai...
New
budgie
A little off-topic, but I feel like people here have a good head on their shoulders. I used to be quite good at making software. Was luc...
New

We're in Beta

About us Mission Statement

Options

Thread Display Mode




Thread Preview

Skip Thread Previews