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

pmjoe
I have a relationship of love and hate with Elixir. Lots of things are just absolutely right, but there are some things that are kind of ...
New
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
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
mathew4509
I have a list say x = ["23gh", "56kh", "97mh"] I would like to pass each element to Val in each iteration. Say, in iteration 1 -------...
New
fayddelight
I tried installing elixir 1.11.2 erlang 23.3.4 via asdf in my zsh shell. Enabled the versions locally and globally. When I list them ...
New
Patoshizzle
After calling mix ecto.create I get this error: 17:00:32.162 [error] GenServer #PID&lt;0.412.0&gt; terminating ** (Postgrex.Error) FATAL...
New
beno
I will often find my self writing things similar to: case some_value do nil -&gt; something() "" -&gt; something() _ -&gt; someth...
New
Codball
Mix format works fine if run from the cmd. I’ve followed this to facilitate the implementation into VSC which involves downloading an ext...
New
siddhant3030
Hi, I have to write a raw query for one of my project. But till now I have used ecto queries and don’t have much experience writing raw ...
New

Other popular topics Top

shahryarjb
Hello, I get Persian date from my client and convert it to normal calendar like this: def jalali_string_to_miladi_english_number(persi...
New
gshaw
What is the idiomatic way of matching for not nil in Elixir? E.g., First way: defp halt_if_not_signed_in(conn, signed_in_account) when...
New
jerry
Good day to you all. I have been struggling to get a query involving like and ilike to work. Can anyone assist me on this, please? pro...
New
SoCreat
i’m a new one to elixir which editor can i use vs code? or atom? Thanks! :smiley:
New
vac
Hi, I'm quite new in Elixir and I'm trying to format a string to a PEM format. I have the certificate value like MIIDBTCCAe2...... and ...
New
qwerescape
Is there a way to get the call stack or stack trace at any point in the code? Not from exceptions, but an expression that returns how the...
New
vonH
When I run the Plug and I recompile I wind up having to use Ctrl C to quit iex and start again. Witht the help of rlwrap I can use the cu...
New
Qqwy
Original source of discussion: This topic on the Pragmatic Programmers' Functional Web Development with Elixir, OTP, and Phoenix forum. ...
New
AstonJ
by Lance Halvorsen Elixir and Phoenix are generating tremendous excitement as an unbeatable platform for building modern web application...
460 27162 124
New
Nvim
Elixir appears to be a superior language to Python. I don’t see any advantage of Python over Elixir. Are there any?
New

We're in Beta

About us Mission Statement