ReplicationConnection.start_link with sync_connect: true might block forever

[edgurgel]

Elixir version

1.17.3

Database and Version

PostgreSQL 17.4

Postgrex Version

0.19.3

Current behavior

Hi team,

We think that Postgrex.ReplicationConnection.start_link with sync_connect: true is getting stuck sometimes.
Sadly I'm not entirely sure how to reproduce this issue.

Here is the current_stacktrace of a DynamicSupervisor we are using to start Postgrex.ReplicationConnection. The line 124 below is this one:

https://github.com/supabase/realtime/blob/b128eb09ea6e891c59f8a5d6481af484122d5115/lib/realtime/tenants/replication_connection.ex#L124 (case Postgrex.ReplicationConnection.start_link(__MODULE__, attrs, connection_opts) do)

iex> Process.info(pid, :current_stacktrace)
{:current_stacktrace,
 [
   {:proc_lib, :sync_start, 2, [file: ~c"proc_lib.erl", line: 434]},
   {Realtime.Tenants.ReplicationConnection, :start_link, 1,
    [file: ~c"lib/realtime/tenants/replication_connection.ex", line: 124]},
   {DynamicSupervisor, :start_child, 3,
    [file: ~c"lib/dynamic_supervisor.ex", line: 795]},
   {DynamicSupervisor, :handle_start_child, 2,
    [file: ~c"lib/dynamic_supervisor.ex", line: 781]},
   {:gen_server, :try_handle_call, 4, [file: ~c"gen_server.erl", line: 2381]},
   {:gen_server, :handle_msg, 6, [file: ~c"gen_server.erl", line: 2410]},
   {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
 ]}

This supervisor was stuck waiting for many many hours.

I can see that Postgrex.ReplicationConnection calls the module init but our init is very lightweight:

https://github.com/supabase/realtime/blob/v2.36.17/lib/realtime/tenants/replication_connection.ex#L133-L147

But there is also the handle_connect etc which can also add up until it finally succeeds connecting?

Expected behavior

The expected behaviour is to respect the timeout set to establish the connection.

While I don't know how the connection was not set-up it would be good to be able to set the gen_statem init timeout regardless if this is an issue with Postgrex connection/handshake setup or not. Having the option to pass a gen_statem timeout would be great and even better if the default value was not :infinity as it will have ultimately a max amount of time that it will be waiting to start.

This would also protect people from having their Module.init/1 taking a long time and blocking the process from starting which is out of Postgrex.ReplicationConnection's control.

Hope this makes sense.

Thanks in advance!

I'm happy to send a PR with this change with some guidance on how we would like to expose this. If we go this route would we want a generic way to send gen_statem start_link options or simply the :timeout (:init_timeout) option?

[josevalim]

We do two things on connect:

1. We establsh a connection
2. We execute the handle_connect callback

The first one has a timeout, so I am suspecting that it is actually blocking on your handle_connect. Perhaps you could change your implementation so it sends a message to itself on handle_connect and then you emit the query on a handle_info callback that receives said message? This would allow us to verify the one that is blocking.

You actually need to be careful with sync connections under a DynamicSupervisor because they will block the DynamicSupervisor. If you realy need them to be blocking, consider putting them under a PartitionSupervisor with a large partition size to account this blocking on external resources.

[edgurgel]

Perhaps you could change your implementation so it sends a message to itself on handle_connect and then you emit the query on a handle_info callback that receives said message? This would allow us to verify the one that is blocking.

Would this mean that the connection setup won't be "synchronous" then? Given that handle_connect will return {:noreply, instead of {:query (if I understood correctly)? https://github.com/elixir-ecto/postgrex/blob/v0.20.0/lib/postgrex/replication_connection.ex#L562-L563

We might look at the option to move to sync_connect: false anyway and this might show up more easily as we can inspect the process current_stacktrace if the process is not progressing.

You actually need to be careful with sync connections under a DynamicSupervisor because they will block the DynamicSupervisor. If you realy need them to be blocking, consider putting them under a PartitionSupervisor with a large partition size to account this blocking on external resources.

Oh. Yup we are doing this 👍 . We just noticed because one of these partitions was blocked for hours.

In the meanwhile, we have a GenServer with an init timeout in front of the ReplicationConnection process to ensure that we don't block indefinitely.

If you don't think this is a bug happy to close the issue.

Obrigado!

[josevalim]

There may be a bug but I am suspecting it is in the handle_connect query, which is why I suggested moving it to handle_info, since we do have timeouts for connects at the moment (but not for the query afaik).

[edgurgel]

It turns out that we have some decent logging in place. And for every case we found so far it seems to hang while trying to do:

query =
      "CREATE_REPLICATION_SLOT #{replication_slot_name} TEMPORARY LOGICAL #{output_plugin} NOEXPORT_SNAPSHOT"

    {:query, query, %{state | step: :check_publication}}

output_plugin is pgoutput

On postgres logs we see stuff like :

starting logical decoding for slot ...

And then nothing related to that slot for minutes/hours and sometimes it never creates the slot

We found cases where it never seems to succeed and some cases where it can take 15 minutes or much more.

I'm not entirely sure why it can be blocked for so long but reading about replication on postgres if there are too many transactions and specially long transactions it might impact replication in general to progress and start.

So maybe a way to say specify a timeout for a query or a more general for all queries could be useful here? {:query, query, timeout: ..., state}

WDYT?

[josevalim]

Yes, supporting timeouts for those would be welcome! Feel free submit a PR :)

[edgurgel]

Sweet! Will work on it soon 👍