Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

call disconnect on protocol when reconnecting in simple connection #717

Merged
merged 1 commit into from
Nov 12, 2024
Merged

call disconnect on protocol when reconnecting in simple connection #717

merged 1 commit into from
Nov 12, 2024

Conversation

artemeff
Copy link
Contributor

postgrex 0.17.5
oban 2.18.3

we are using oban with postgres notifiers and in a few services we have a port leaks

image

blue line is fix hotload

the problem is that the ports are not closed on {:connect, :reconnect} handle, it just drops the protocol state and creates a new one

08:09:21.320006 <0.3785.0> Postgrex.SimpleConnection.handle_event(:info, {:tcp, #Port<0.84514854>,
 <<69, 0, 0, 0, 115, 83, 70, 65, 84, 65, 76, 0, 86, 70, 65, 84, 65, 76, 0, 67,
   53, 55, 80, 48, 53, 0, 77, 116, 101, 114, 109, 105, 110, 97, 116, 105, 110,
   103, 32, 99, 111, 110, 110, 101, 99, 116, 105, ...>>}, :no_state, %Postgrex.SimpleConnection{
  idle_interval: 5000,
  protocol: %Postgrex.Protocol{
    sock: {:gen_tcp, #Port<0.84514854>},
    connection_id: 3537365,
    connection_key: 904133435,
    peer: {{10, 129, 1, 100}, 5432},
    types: {Postgrex.DefaultTypes, #Reference<0.1812357926.8519733.135683>},
    null: nil,
    timeout: 15000,
    ping_timeout: 15000,
    parameters: #Reference<0.1812357926.1244921861.105622>,
    queries: nil,
    postgres: :idle,
    transactions: :naive,
    buffer: :active_once,
    disconnect_on_error_codes: [],
    scram: ...,
    disable_composite_types: false
  },
  auto_reconnect: true,
  reconnect_backoff: 500,
  state: {Oban.Notifiers.Postgres,
   %Oban.Notifiers.Postgres{
     conf: %Oban.Config{
       dispatch_cooldown: 5,
       engine: Oban.Engines.Basic,
       get_dynamic_repo: nil,
       insert_trigger: true,
       log: false,
       name: Oban,
       node: "[email protected]",
       notifier: {Oban.Notifiers.Postgres, []},
       peer: {Oban.Peers.Postgres, []},
       plugins: [{Oban.Plugins.Pruner, [max_age: 43200]}],
       prefix: "public",
       queues: [default: [limit: 10]],
       repo: Service.Repo,
       shutdown_grace_period: 15000,
       stage_interval: 1000,
       testing: :disabled
     },
     from: nil,
     key: nil,
     channels: %{
       "public.oban_insert" => [#PID<0.13379.92>],
       "public.oban_leader" => [#PID<0.3787.0>],
       "public.oban_signal" => [#PID<0.13379.92>, #PID<0.3789.0>],
       "public.oban_sonar" => [#PID<0.3788.0>]
     },
     connected?: true,
     listeners: %{
       #PID<0.3787.0> => {#Reference<0.1812357926.8388665.136456>,
        MapSet.new(["public.oban_leader"])},
       #PID<0.3788.0> => {#Reference<0.1812357926.8388663.136221>,
        MapSet.new(["public.oban_sonar"])},
       #PID<0.3789.0> => {#Reference<0.1812357926.8388663.136235>,
        MapSet.new(["public.oban_signal"])},
       #PID<0.13379.92> => {#Reference<0.1812357926.47972356.224570>,
        MapSet.new(["public.oban_insert", "public.oban_signal"])}
     }
   }}
})

08:09:21.321766 <0.3785.0> Postgrex.Protocol.handle_info({:tcp, #Port<0.84514854>,
 <<69, 0, 0, 0, 115, 83, 70, 65, 84, 65, 76, 0, 86, 70, 65, 84, 65, 76, 0, 67,
   53, 55, 80, 48, 53, 0, 77, 116, 101, 114, 109, 105, 110, 97, 116, 105, 110,
   103, 32, 99, 111, 110, 110, 101, 99, 116, 105, ...>>}, [notify: #Function<2.75911949/2 in Postgrex.SimpleConnection.handle_event/4>], %Postgrex.Protocol{
  sock: {:gen_tcp, #Port<0.84514854>},
  connection_id: 3537365,
  connection_key: 904133435,
  peer: {{10, 129, 1, 100}, 5432},
  types: {Postgrex.DefaultTypes, #Reference<0.1812357926.8519733.135683>},
  null: nil,
  timeout: 15000,
  ping_timeout: 15000,
  parameters: #Reference<0.1812357926.1244921861.105622>,
  queries: nil,
  postgres: :idle,
  transactions: :naive,
  buffer: :active_once,
  disconnect_on_error_codes: [],
  scram: ...,
  disable_composite_types: false
})

08:09:21.322877 <0.3785.0> Postgrex.Protocol.handle_info/3 --> {:disconnect,
 %Postgrex.Error{
   message: nil,
   postgres: %{
     code: nil,
     file: "postgres.c",
     line: "3381",
     message: "terminating connection due to idle-session timeout",
     pg_code: "57P05",
     routine: "ProcessInterrupts",
     severity: "FATAL",
     unknown: "FATAL"
   },
   connection_id: 3537365,
   query: nil
 },
 %Postgrex.Protocol{
   sock: {:gen_tcp, #Port<0.84514854>},
   connection_id: 3537365,
   connection_key: 904133435,
   peer: {{10, 129, 1, 100}, 5432},
   types: {Postgrex.DefaultTypes, #Reference<0.1812357926.8519733.135683>},
   null: nil,
   timeout: 15000,
   ping_timeout: 15000,
   parameters: #Reference<0.1812357926.1244921861.105622>,
   queries: nil,
   postgres: :idle,
   transactions: :naive,
   buffer: "",
   disconnect_on_error_codes: [],
   scram: ...,
   disable_composite_types: false
 }}

08:09:21.323738 <0.3785.0> Postgrex.SimpleConnection.handle_event/4 --> {:keep_state,
 %Postgrex.SimpleConnection{
   idle_interval: 5000,
   protocol: %Postgrex.Protocol{
     sock: {:gen_tcp, #Port<0.84514854>},
     connection_id: 3537365,
     connection_key: 904133435,
     peer: {{10, 129, 1, 100}, 5432},
     types: {Postgrex.DefaultTypes, #Reference<0.1812357926.8519733.135683>},
     null: nil,
     timeout: 15000,
     ping_timeout: 15000,
     parameters: #Reference<0.1812357926.1244921861.105622>,
     queries: nil,
     postgres: :idle,
     transactions: :naive,
     buffer: :active_once,
     disconnect_on_error_codes: [],
     scram: ...,
     disable_composite_types: false
   },
   auto_reconnect: true,
   reconnect_backoff: 500,
   state: {Oban.Notifiers.Postgres,
    %Oban.Notifiers.Postgres{
      conf: %Oban.Config{
        dispatch_cooldown: 5,
        engine: Oban.Engines.Basic,
        get_dynamic_repo: nil,
        insert_trigger: true,
        log: false,
        name: Oban,
        node: "[email protected]",
        notifier: {Oban.Notifiers.Postgres, []},
        peer: {Oban.Peers.Postgres, []},
        plugins: [{Oban.Plugins.Pruner, [max_age: 43200]}],
        prefix: "public",
        queues: [default: [limit: 10]],
        repo: Service.Repo,
        shutdown_grace_period: 15000,
        stage_interval: 1000,
        testing: :disabled
      },
      from: nil,
      key: nil,
      channels: %{
        "public.oban_insert" => [#PID<0.13379.92>],
        "public.oban_leader" => [#PID<0.3787.0>],
        "public.oban_signal" => [#PID<0.13379.92>, #PID<0.3789.0>],
        "public.oban_sonar" => [#PID<0.3788.0>]
      },
      connected?: false,
      listeners: %{
        #PID<0.3787.0> => {#Reference<0.1812357926.8388665.136456>,
         MapSet.new(["public.oban_leader"])},
        #PID<0.3788.0> => {#Reference<0.1812357926.8388663.136221>,
         MapSet.new(["public.oban_sonar"])},
        #PID<0.3789.0> => {#Reference<0.1812357926.8388663.136235>,
         MapSet.new(["public.oban_signal"])},
        #PID<0.13379.92> => {#Reference<0.1812357926.47972356.224570>,
         MapSet.new(["public.oban_insert", "public.oban_signal"])}
      }
    }}
 }, {:next_event, :internal, {:connect, :reconnect}}}

08:09:21.325981 <0.3785.0> Postgrex.SimpleConnection.handle_event(:internal, {:connect, :reconnect}, :no_state, %Postgrex.SimpleConnection{
  idle_interval: 5000,
  protocol: %Postgrex.Protocol{
    sock: {:gen_tcp, #Port<0.84514854>},
    connection_id: 3537365,
    connection_key: 904133435,
    peer: {{10, 129, 1, 100}, 5432},
    types: {Postgrex.DefaultTypes, #Reference<0.1812357926.8519733.135683>},
    null: nil,
    timeout: 15000,
    ping_timeout: 15000,
    parameters: #Reference<0.1812357926.1244921861.105622>,
    queries: nil,
    postgres: :idle,
    transactions: :naive,
    buffer: :active_once,
    disconnect_on_error_codes: [],
    scram: ...,
    disable_composite_types: false
  },
  auto_reconnect: true,
  reconnect_backoff: 500,
  state: {Oban.Notifiers.Postgres,
   %Oban.Notifiers.Postgres{
     conf: %Oban.Config{
       dispatch_cooldown: 5,
       engine: Oban.Engines.Basic,
       get_dynamic_repo: nil,
       insert_trigger: true,
       log: false,
       name: Oban,
       node: "[email protected]",
       notifier: {Oban.Notifiers.Postgres, []},
       peer: {Oban.Peers.Postgres, []},
       plugins: [{Oban.Plugins.Pruner, [max_age: 43200]}],
       prefix: "public",
       queues: [default: [limit: 10]],
       repo: Service.Repo,
       shutdown_grace_period: 15000,
       stage_interval: 1000,
       testing: :disabled
     },
     from: nil,
     key: nil,
     channels: %{
       "public.oban_insert" => [#PID<0.13379.92>],
       "public.oban_leader" => [#PID<0.3787.0>],
       "public.oban_signal" => [#PID<0.13379.92>, #PID<0.3789.0>],
       "public.oban_sonar" => [#PID<0.3788.0>]
     },
     connected?: false,
     listeners: %{
       #PID<0.3787.0> => {#Reference<0.1812357926.8388665.136456>,
        MapSet.new(["public.oban_leader"])},
       #PID<0.3788.0> => {#Reference<0.1812357926.8388663.136221>,
        MapSet.new(["public.oban_sonar"])},
       #PID<0.3789.0> => {#Reference<0.1812357926.8388663.136235>,
        MapSet.new(["public.oban_signal"])},
       #PID<0.13379.92> => {#Reference<0.1812357926.47972356.224570>,
        MapSet.new(["public.oban_insert", "public.oban_signal"])}
     }
   }}
})

@josevalim josevalim merged commit 71095dc into elixir-ecto:master Nov 12, 2024
9 checks passed
@josevalim
Copy link
Member

💚 💙 💜 💛 ❤️

@josevalim
Copy link
Member

I am shipping a new version now.

grzuy
grzuy reviewed Nov 28, 2024
View reviewed changes
lib/postgrex/simple_connection.ex
@@ -337,7 +337,12 @@ defmodule Postgrex.SimpleConnection do
@impl :gen_statem
def handle_event(type, content, statem_state, state)

def handle_event(:internal, {:connect, _}, @state, %{state: {mod, mod_state}} = state) do
def handle_event(:internal, {:connect, :reconnect}, @state, %{protocol: protocol} = state) do
Protocol.disconnect(:reconnect, protocol)
Copy link

@grzuy grzuy Nov 28, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi, thanks for this fix.

Could it be though that this needs to consider a case in which protocol is nil?

We got this error in production with the latest postgrex 0.19.3

image

Note cancel_request(nil) call.

Thanks!

Copy link

@grzuy grzuy Nov 28, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These are the logs from when this error happened...

image

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pushed to main.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks @josevalim 🙏

@JannikStreek JannikStreek mentioned this pull request Dec 8, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@grzuy grzuy grzuy left review comments

@josevalim josevalim josevalim left review comments

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
3 participants
@artemeff @josevalim @grzuy