Telemetry not working with postgrex ([:db_connection, :connection_error] event)

Questions / Help
, ,
2

Well, this is embarassing, but I eventually got the telemetry event. It looks like I get it when I am trying to do a query on the database (an INSERT in this case) but not when I am idle and stop the database. I guess this is normal behavior since it is written “(…) whenever a connection checkout receives a %DBConnection.ConnectionError{} .” That means we have to need to checkout a connection from the pool and that only happens when we try to run a query.

Idle (no telemetry event):

11:02:20.448 [error] Postgrex.Protocol (#PID<0.242.0>) disconnected: ** (Postgrex.Error) FATAL 57P01 (admin_shutdown) terminating connection due to administrator command
11:02:20.449 [error] Postgrex.Protocol #PID<0.242.0> could not cancel backend: tcp connect: connection refused - :econnrefused
11:02:20.449 [info]  Disconnected from DB for pid: #PID<0.242.0>, state.pid: #PID<0.240.0>
11:02:20.454 [error] Postgrex.Protocol (#PID<0.242.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (xxx:5433): connection refused - :econnrefused

Trying to do an INSERT (transaction and query):

11:02:46.448 [error] Postgrex.Protocol (#PID<0.242.0>) disconnected: ** (Postgrex.Error) FATAL 57P01 (admin_shutdown) terminating connection due to administrator command
11:02:46.448 [error] Postgrex.Protocol #PID<0.242.0> could not cancel backend: tcp connect: connection refused - :econnrefused
11:02:46.453 [error] Postgrex.Protocol (#PID<0.242.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (xxx:5433): connection refused - :econnrefused
11:02:49.146 [error] Postgrex.Protocol (#PID<0.242.0>) failed to connect: ** (DBConnection.ConnectionError) tcp connect (xxx:5433): connection refused - :econnrefused
measurements: %{count: 1}
metadata: %{
  error: %DBConnection.ConnectionError{
    message: "connection not available and request was dropped from queue after 2045ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:\n\n  1. Ensuring your database is available and that you can connect to it\n  2. Tracking down slow queries and making sure they are running fast enough\n  3. Increasing the pool_size (albeit it increases resource consumption)\n  4. Allowing requests to wait longer by increasing :queue_target and :queue_interval\n\nSee DBConnection.start_link/2 for more information\n",
    reason: :queue_timeout,
    severity: :error
  },
  opts: []
}
catch transaction error: :error
catch transaction reason: %DBConnection.ConnectionError{
  message: "connection not available and request was dropped from queue after 2045ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:\n\n  1. Ensuring your database is available and that you can connect to it\n  2. Tracking down slow queries and making sure they are running fast enough\n  3. Increasing the pool_size (albeit it increases resource consumption)\n  4. Allowing requests to wait longer by increasing :queue_target and :queue_interval\n\nSee DBConnection.start_link/2 for more information\n",
  reason: :queue_timeout,
  severity: :error
}
1 Like