Amber: Far too many database connections while stress testing

[katafrakt]

Description

I found a really weird behaviour while I was stress testing my application in production mode, however it is reproducible in development mode. I'm using Crecto to connect to PostgreSQL and my database initializer looks basically as it was generated by amber:

require "pg"
require "crecto"
Query = Crecto::Repo::Query

module Repo
  extend Crecto::Repo

  config do |c|
    c.adapter = Crecto::Adapters::Postgres
    c.uri = Amber.settings.database_url
  end
end

My database url is set with max_pool_size=5 and I'm using two processes in production mode. I tested the app with a following command:

siege -c 200 -r 50 http://localhost:8080/MRiU45 --no-follow

What happened was that my database started to spit out a lot of FATAL: sorry, too many clients already. This was weird, because max_connections was set to 100 and nothing else was using the database. I quickly started to suspect that something does not respect max pool size, but I checked crystal-pg, crecto and crystal-db and couldn't find the bug. After that as a test I reduced max_pool_size and added a puts to Crecto's get_connection method:

def get_connection
  @crecto_db ||= begin  
    puts "connecting"
    DB.open(database_url).as(DB::Database)
  end
end

By simply counting the lines I discovered that two processes with max_pool_size=1 can generate around 90 connections in my case.

The reason turned out to be lazy connecting in Crecto. The code above executes DB.open but while it's still running, another request tries to access the database and tries to open the connection too. This can happen many times before the first connection is actually made and assigned to the instance variable but in the meantime, max connection count is reached and requests start to fail.

Steps to Reproduce

1. Initialize new project with crecto and PostgreSQL
2. Set database url to include max_pool_size with some reasonably low value (5)
3. Start the server in production mode with at least 2 processes
4. Siege the server with siege -c 200 -r 50 http://localhost:8080/some_fast_endpoint_using_database

Expected behavior:

No information about max clients number being exceeded.

Actual behavior:

A lot of FATAL: sorry, too many clients already from the database and some requests failing.

Reproduces how often:

100% on fast enough endpoint.

Versions

Amber master, Crystal 0.24.2, but it does not really matter probably.

Suggested solution

I fixed that with adding Repo.raw_exec("SELECT 1") to the end of my initializer. This waits to connect to database before stating that server is ready. It fixes 100% of problems for me in any setup. Of course, it also make server boot time a little slower.

Ideally, Crecto could have some connect! method because it's better API that doing SELECT 1. Internally, it could just initialize the connection (by get_connection).

Anyway, I think something should be added to default database initializer of Amber for Crecto, for others to avoid those problems. When some consensus is reached, I can prepare a pull request.

[faustinoaq]

Hi @katafrakt Thank you for report this issue?

@fridgerator Is this just related to Amber+Crecto or Crecto in General?

[fridgerator]

I'm not sure, I'll have to play around w/ it when I get time

[fridgerator]

The same thing should probably be tested w/ Granite.

[eliasjpr]

This might be a better issue for https://github.com/will/crystal-pg. WDYT?

[eliasjpr]

Also for reference https://crystal-lang.org/docs/database/connection_pool.html

[katafrakt]

@eliasjpr I think this is too low-level. From what I was able to debug, connection pools work fine, it's just that Crecto initializes many of them. So maybe I'll try to reproduce it in Amber-independent environment and will take the discussion to Crecto bugtracker.

[marksiemers]

@katafrakt - Can this issue be closed here?

[katafrakt]

@marksiemers Since we agreed that this is not really Amber issue, I think it can be closed now. If some new information comes up we can always reopen it.