maxguzenski

maxguzenski

App in production crashing with DBConnection.ConnectionError

Hello.
I don’t know what the best place is, hoping to find any help with the problem I’ve been facing in production for about 3 days.

I have a niche social network that, on average, has 4 thousand users online, and makes around 30 thousand requests per second to the server. The application runs smoothly with an average per request of just 0.02s and memory of around 10GB. But something happens when the site reaches 5.5k users online, everything drops very quickly (less than 10s), the application goes from 10gb to 60gb in a few seconds, the Elixir Logger starts dropping logs, the server loses all connections with the database and starts trying to reestablish new connections, but they all timeout… so the app becomes irresponsible until docker is restarted (returning to normal speed and staying like that for about 20 minutes).

Error that appears in the log thousands of times:


DBConnection.ConnectionError

tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)

My infrastructure:

The application runs on Docker (generated by Phoenix 1.7), deploys with AWS ECS on a c6i.x24large (96vcpu/189gb) and Aurora r6.x4large database (16cpu/128gb)

The database uses around 35% of CPU, and remains that way even when the application crashes. The application uses only 10% CPU and 10GB of RAM.

ps.: All online users connect via websocket, in addition to the normal request.

Elixir 1.15.7
Phoenix 1.7.10 with all deps updated
React front-end

Things I’ve tried

  • db connection pool: from 100 to 2400
  • Direct connection to Aurora and throught RDS proxy as well
  • I have tested with an instance with 50 gigabits of network performance
  • soft/hard “ulimit” from default value to 130k
  • queue_interval/target from 50ms to 2s

Because of websocket, I haven’t been able to test scaling horizontally yet.

Some screenshots

App on “normal” mode:

When app is not responding (See how memory increased):

Avarage request time, you can see it stop to responding very fast:

Aurora database shows that app is not reading the query result:

So what I need is some direction, it’s strange that it happens right after passing the 5500 users mark online, before that the app doesn’t present any problems or slowdowns.

I also don’t know if scaling horizontally would solve it, but there is no metric (memory/cpu) that indicates that the problem is close to occurring so that it can be scaled.

I would bet on some network limit, port exhaustion or process limit reached. But I don’t find anything in the logs other than the database connection error.

Most Liked

josevalim

josevalim

Creator of Elixir

I would start by adding more metrics around the application. Having such a large connection number is likely going to lead to worse performance, as they won’t ever be effectively used and the runtime now has to spend more time managing them.

If you suspect this is related to the database, you should log the metrics emitted by Ecto, such as query time, checkout time, idle time and so on.

I would also log the memory metrics from the VM and, most important, the Erlang VM run queues, which tells you how much CPU/IO work it has to do. You can get those by running Phoenix LiveDashboard on the repo, but ideally you want to push these to an external tool too.

felix-starman

felix-starman

Are you by chance using Bandit? I was experiencing a similar symptom, although w/ no resource issues that I noticed, just sudden timeouts that felt like port exhaustion.

If so, there’s a PR @mtrudel put out for thousand_island (Refine acceptor behaviour on abnormal conditions by mtrudel · Pull Request #103 · mtrudel/thousand_island · GitHub) that resolves an issue where the kernel might kill a connection, but the process responsible for it was not restarting since it looked “normal” to it. I was similarly seeing it occur during peaks, but it was mostly just coincidence since that’s when the most activity and aborted connections were occurring. I also saw large numbers of DB timeouts right after, but it was a red herring.

dch

dch

lots of great points already here, but not much on OS level.

questions

  • any info on what is the bottleneck? storage? network? kernel?
  • is there a load balancer in between you and the users?
  • are there any errors reported in kernel logs at this time?
  • any other sysctl or other tunables set for ulimit, max open files, …
  • are you running into any tcp ephemeral port exhaustion? this is surprisingly common when running behind load balancers, you should monitor total ports, and what state they are in, at runtime, both in kernel and of elixir app.

I would initially check the networking side first, before looking at storage. A reasonable hypothesis is this:

  • you are running out of free tcp sockets for inbound connections and/or queued connections in the kernel, and they’re not being recycled fast enough by OS
  • this could cause both the DB pool to be unable to spawn new connections, and same for phoenix on accepting new user connections
  • user requests start piling up in process mailboxes, causing memory to balloon
  • everything rapidly turns to custard

TLDR

You need to check/fix all of ulimits as seen by beam.smp process, kernel backlog & accept queues, phoenix acceptors, backlogs, and max requests.

  • check cat /proc/<pid>/limits for elixir beam.smp pid to ensure ulimits are ok (fix in systemctl unit file or ulimit if not a systemd service)
  • check ss -s to see how many “active” connections there are at runtime
  • save full output of ss -tan somewhere for review later
  • check sysctl net.ipv4.ip_local_port_range and increase it sysctl -w net.ipv4.ip_local_port_range="4096 65535" to give more headroom
  • check ss -lnt to see how many active connections phoenix is handling atm
  • adjust phoenix to handle more active connections if required (use gen_tcp backlog 1024 as a reasonable number)

Longer

NB many caveats and handwavey innacuracies, to keep it simple.

Incoming network connections arrive in the kernel, and are queued in several places.

  • first kernel queue is backlog queue, until tcp handshake is completed (syn, then syn-ack reply, final ack from client)
  • next kernel queue is the accept queue, waiting for your listening app to accept the next connection. The kernel will buffer 1.5x the maximum configured connections on behalf of your app. This default is either 128 or 4096 depending on OS. Note that 1.5 * 4096 is 6144 which is awfully close to 5500. Could be coincidence of course!
  • final queue is gen_tcp acceptors in phoenix app, if there are no free ones (busy with existing requests), then we “push back” and requests start piling up in the buffer, then the accept queue itself overflows, and the backlog queue, until new requests for both receive and send get rejected.

If you are using the default port range, you’ll have around 28000 available sockets behind a NAT. If each user request creates 2 tcp requests in, and a further temporary 1 or 2 out to DB or elsewhere, then 5500 active users brings you pretty close to maxing that out. Also another coincidence possibly!

You may see this info in AWS LB metrics, or in whatever grafana or similar server metrics you collect too.

Probably something like this:

### whats the configured ephemeral port range
# sysctl net.ipv4.ip_local_port_range
### how many sockets are open atm? one of these commands should work for you
### they all give slightly different info
# netstat -nat
# ss -lnt
# ss -tan | awk '{print $4}' | cut -d':' -f2 | sort | uniq -c | sort -n

I wrote a bit about this in the past so start with that. Some details on tcp networking in general:

background

finding appropriate tunables / settings

can’t I just query how many ephemeral ports are left?

No. That complexity can wait for another day.

maxguzenski

maxguzenski

@posilva @dch

We believe we have fixed the problem. Monday will be the real test (as it is the day of the week with the most hits).

Problem summary:

Under high demand (more than 40k requests/minute), the app completely freeze from one moment to the next, which was resolved with a complete docker container restart. RAM usage grew exponentially in a few seconds and the logs stopped being reported (Logger dropped the logs, but what could be seen in the logs a few seconds before they stopped was a large number of connection errors with the database. )

Even requests without access to the database gave a timeout. Which prevented me from seeing any telemetry generated by the application. (and I wasn’t using any external services to collect beam data)

The application runs in Docker on a c6i.4xlarge (only 1 instance) connecting to AWS Aurora (r6.4xlarge).

I immediately scaled the application to a c6.12xlarge and the database as well, hoping to have time to investigate the problem. But the problem remained the same.

Initially what helped was increasing the db connection pool (ecto) from 200 to 2000, but even then the application needed to be restarted every 30 minutes.

It wasn’t an OS-level problem.

Solution:
A good database engineer improved some aurora queries and configurations, this didn’t solve the problem at all but it improved the time the application was responsive.

A RateLimit was implemented to prevent abuse of requests from some users. This helped the application to run much longer (+/- 1 hour).

But what really resolved it was reversing absinthe (graphql) from version 1.7.5 to 1.6.8, which had already been well tested in the past. Version 1.7 had already been used for a couple months, but I believe that something happens with asinthe, when it is under intense use, that does not happen in version 1.6.x.

Now let’s wait for Monday, and if the issue really solved, I will do performance tests with absinthe (or stay with version 1.6.8).

Thank you very much to everyone who helped!

mpope

mpope

When I am faced with these kinds of high-load issues I rely on recon and remote nodes. I’d suggest trying to come up with a load test that simulates this error (maybe 1/4 of the max users on 1/4 of the CPUs?), then connect to your Phoneix app using a remote node and poke around. Check scheduler usage across your CPUs, check processes with high memory / reductions, etc.

Ofcourse this can be done through automated metrics gathering by sweeping the system periodically and measuring / logging the most ‘heavy’ processes, but sometimes the proactive approach is easier to work with. You can see process state, what the current stacktrace is, etc.

Checking out Microstate Accounting and Lock Profiling can also help if nothing really stands out with scheduler usage or processes. Also try giving Erlang in Anger a read.

Where Next?

Popular in Questions Top

JDanielMartinez
Hi! May someone helps me, please! I have two apps into an umbrella project: the first one is Database, which manages queries, and the se...
New
lessless
I believe there are people here who are dealing with CSV files import on the daily basis, and since Excel is a really popular tool there ...
New
itssasanka
Hi all, Trying to get some more clarity over utc_datetime and naive_datetime for Ecto: https://hexdocs.pm/ecto/Ecto.Schema.html#module-...
New
logicmason
Hi there, I'm working through my first release with elixir/phoenix. I've built a release with distillery and found that it crashes when I...
New
gonzofish
I’m currently trying to understand how to join three tables using Ecto. All the examples I’ve seen use 2, so maybe I’m just missing somet...
New
belgoros
I’m not a pro in using Regex and can’t figure out why the following behaviour happens, especially if we take into account the difference ...
New
skosch
To my knowledge, put_in, Map.update etc. all have the one limitation of not automatically creating intermediate keys when needed (for exa...
New
lucidguppy
I have a super simple question about elixir - how would I take a file like this foo bar baz and output a new file that enumerates th...
New
jc00ke
Expanding on this topic: https://forum.elixirforum.net/t/map-typespec-question/19217 Let’s say I have a map with required and optional k...
New
idi527
I’ve been re-reading swift book again and noticed that multiline strings there don’t have a trailing line break, unlike in elixir iex(2)...
New

Other popular topics Top

Qqwy
Update: How to use the Blogs &amp; Podcasts section You can post links to your blog posts or podcasts either in one of the Official Blog...
3268 119930 1237
New
yurko
Here are few pieces of (common) Linux knowledge that we use for reasonably small one server apps. We use Ubuntu but this should work for ...
New
senggen
Erlang/OTP 25 [erts-13.2.2] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] 15:22:35.803 [error] gen_event {lager_file_backend...
New
JorisKok
I have a server on AWS, and was running a load test using artillery. When looking at the Phoenix dashboard I see the Ports going to 100% ...
New
Harrisonl
We have an ECS cluster with 4 services, where each task joins a single cluster, via discovery ECS discovery service. Currently when I de...
New
myronmarston
The Elixir Typespec docs show the following syntax for keyword lists in typespecs: # ... | [key: type] # keyword lis...
New
chensan
I have a User schema with a :from_id field set to type :string: defmodule TweetBot.Repo.Migrations.CreateUsers do use Ecto.Migration ...
New
9mm
I am constructing a JSON object (map) and I need to conditionally set a field. I’m trying to write proper elixir-way code… and I’m at a l...
New
skosch
To my knowledge, put_in, Map.update etc. all have the one limitation of not automatically creating intermediate keys when needed (for exa...
New
lanycrost
Hi everyone! I need implement if…else if…else condition from my elixir code, and anymore of this control flow structures not work proper...
New

We're in Beta

About us Mission Statement