elixir-ecto / postgrex

PostgreSQL driver for Elixir
http://hexdocs.pm/postgrex/
1.11k stars 274 forks source link

GenServer terminating upon start #446

Closed jeroenbourgois closed 5 years ago

jeroenbourgois commented 5 years ago

Hi

I have a running Phoenix app connected to a Postgresql db, which is running fine on my local machine. However, after deploying, I get the following error (4 times):

13:56:10.221 [error] GenServer #PID<0.142.0> terminating
** (ArgumentError) unknown registry: Postgrex.TypeManager
    (elixir) lib/registry.ex:1125: Registry.key_info!/1
    (elixir) lib/registry.ex:529: Registry.lookup/2
    (postgrex) lib/postgrex/type_supervisor.ex:29: Postgrex.TypeSupervisor.locate/2
    (postgrex) lib/postgrex/protocol.ex:771: Postgrex.Protocol.bootstrap/3
    (postgrex) lib/postgrex/protocol.ex:576: Postgrex.Protocol.handshake/2
    (db_connection) lib/db_connection/connection.ex:66: DBConnection.Connection.connect/2
    (connection) lib/connection.ex:622: Connection.enter_connect/5
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Last message: nil

The main difference between my local and online setup is that the former has a postgres server running locally whereas the latter connects to a remote Postgres db. Does the online machine requires something installed before being able to connect to a remote machine?

For now, it is only a basic Debian machine, nothing db-related installed.

Thank you!

FYI:

Remote psql: PostgreSQL 10.6 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.3 20140911 (Red Hat 4.8.3-9), 64-bit Elixir 1.7.4 Erlang/OTP 21 [erts-10.2]

Output for mix deps:

* parse_trans 3.3.0 (Hex package) (rebar3)
  locked at 3.3.0 (parse_trans) 09765507
  ok
* gen_state_machine 2.0.5 (Hex package) (mix)
  locked at 2.0.5 (gen_state_machine) 9ac15ec6
  ok
* base64url 0.0.1 (Hex package) (rebar)
  locked at 0.0.1 (base64url) 36a90125
  ok
* mimerl 1.2.0 (Hex package) (rebar3)
  locked at 1.2.0 (mimerl) 67e2d3f5
  ok
* file_system 0.2.6 (Hex package) (mix)
  locked at 0.2.6 (file_system) fd4dc3af
  ok
* connection 1.0.4 (Hex package) (mix)
  locked at 1.0.4 (connection) a1cae722
  ok
* decorator 1.2.4 (Hex package) (mix)
  locked at 1.2.4 (decorator) 31dfff61
  ok
* nimble_parsec 0.5.0 (Hex package) (mix)
  locked at 0.5.0 (nimble_parsec) 90e2eca3
  ok
* makeup 0.8.0 (Hex package) (mix)
  locked at 0.8.0 (makeup) 9cf32aea
  ok
* metrics 1.0.1 (Hex package) (rebar3)
  locked at 1.0.1 (metrics) 25f094de
  ok
* unicode_util_compat 0.4.1 (Hex package) (rebar3)
  locked at 0.4.1 (unicode_util_compat) d869e4c6
  ok
* idna 6.0.0 (Hex package) (rebar3)
  locked at 6.0.0 (idna) 689c46cb
  ok
* gettext 0.16.1 (Hex package) (mix)
  locked at 0.16.1 (gettext) e2130b25
  ok
* logger_papertrail_backend 1.0.3 (Hex package) (mix)
  locked at 1.0.3 (logger_papertrail_backend) 54950db8
  ok
* gen_stage 0.14.1 (Hex package) (mix)
  locked at 0.14.1 (gen_stage) 9d46723f
  ok
* jose 1.9.0 (Hex package) (mix)
  locked at 1.9.0 (jose) 4167c5f6
  ok
* ranch 1.7.1 (Hex package) (rebar3)
  locked at 1.7.1 (ranch) 6b1fab51
  ok
* telemetry 0.3.0 (Hex package) (rebar3)
  locked at 0.3.0 (telemetry) 099a7f3c
  ok
* decimal 1.7.0 (Hex package) (mix)
  locked at 1.7.0 (decimal) 30d6b52c
  ok
* parallel_stream 1.0.6 (Hex package) (mix)
  locked at 1.0.6 (parallel_stream) b967be2b
  ok
* jason 1.1.2 (Hex package) (mix)
  locked at 1.1.2 (jason) b03dedea
  ok
* poison 3.1.0 (Hex package) (mix)
  locked at 3.1.0 (poison) d9eb6366
  ok
* json_web_token 0.2.10 (Hex package) (mix)
  locked at 0.2.10 (json_web_token) 61041d56
  ok
* ssl_verify_fun 1.1.4 (Hex package) (mix)
  locked at 1.1.4 (ssl_verify_fun) f0eafff8
  ok
* dialyxir 0.5.1 (Hex package) (mix)
  locked at 0.5.1 (dialyxir) b331b091
  ok
* exconstructor 1.1.0 (Hex package) (mix)
  locked at 1.1.0 (exconstructor) 272623a7
  ok
* gen_retry 1.2.0 (Hex package) (mix)
  locked at 1.2.0 (gen_retry) 6ac4411c
  ok
* combine 0.10.0 (Hex package) (mix)
  locked at 0.10.0 (combine) eff8224e
  ok
* csv 2.1.1 (Hex package) (mix)
  locked at 2.1.1 (csv) a4c1a7c3
  ok
* certifi 2.5.1 (Hex package) (rebar3)
  locked at 2.5.1 (certifi) 867ce347
  ok
* hackney 1.15.1 (Hex package) (rebar3)
  locked at 1.15.1 (hackney) 9f8f471c
  ok
* tzdata 0.5.19 (Hex package) (mix)
  locked at 0.5.19 (tzdata) 7962a399
  ok
* timex 3.5.0 (Hex package) (mix)
  locked at 3.5.0 (timex) b0a23167
  ok
* earmark 1.3.1 (Hex package) (mix)
  locked at 1.3.1 (earmark) 73812f44
  ok
* sweet_xml 0.6.6 (Hex package) (mix)
  locked at 0.6.6 (sweet_xml) fc3e91ec
  ok
* ex_aws 2.1.0 (Hex package) (mix)
  locked at 2.1.0 (ex_aws) b9265152
  ok
* ex_aws_s3 2.0.1 (Hex package) (mix)
  locked at 2.0.1 (ex_aws_s3) 9e09366e
  ok
* db_connection 2.0.5 (Hex package) (mix)
  locked at 2.0.5 (db_connection) ddb2ba67
  ok
* httpoison 1.5.0 (Hex package) (mix)
  locked at 1.5.0 (httpoison) 71ae9f30
  ok
* goth 0.8.2 (Hex package) (mix)
  locked at 0.8.2 (goth) edd1359f
  ok
* ecto 3.0.7 (Hex package) (mix)
  locked at 3.0.7 (ecto) 44dda84a
  ok
* crontab 1.1.5 (Hex package) (mix)
  locked at 1.1.5 (crontab) 2c943950
  ok
* makeup_elixir 0.13.0 (Hex package) (mix)
  locked at 0.13.0 (makeup_elixir) be7a4779
  ok
* ex_doc 0.19.3 (Hex package) (mix)
  locked at 0.19.3 (ex_doc) 3c7b0f02
  ok
* phoenix_pubsub 1.1.2 (Hex package) (mix)
  locked at 1.1.2 (phoenix_pubsub) 496c303b
  ok
* oauth2 0.9.4 (Hex package) (mix)
  locked at 0.9.4 (oauth2) 632e8e88
  ok
* cowlib 2.7.0 (Hex package) (rebar3)
  locked at 2.7.0 (cowlib) 3ef16e77
  ok
* cowboy 2.6.1 (Hex package) (rebar3)
  locked at 2.6.1 (cowboy) f2e06f75
  ok
* mime 1.3.1 (Hex package) (mix)
  locked at 1.3.1 (mime) 30ce04ab
  ok
* libring 1.4.0 (Hex package) (mix)
  locked at 1.4.0 (libring) 41246ba2
  ok
* swarm 3.4.0 (Hex package) (mix)
  locked at 3.4.0 (swarm) 64f8b300
  ok
* quantum 2.3.4 (Hex package) (mix)
  locked at 2.3.4 (quantum) 72a0e885
  ok
* postgrex 0.14.1 (Hex package) (mix)
  locked at 0.14.1 (postgrex) 63247d4a
  ok
* ecto_sql 3.0.5 (Hex package) (mix)
  locked at 3.0.5 (ecto_sql) 7e44172b
  ok
* artificery 0.4.1 (Hex package) (mix)
  locked at 0.4.1 (artificery) 90b1fced
  ok
* distillery 2.0.12 (Hex package) (mix)
  locked at 2.0.12 (distillery) 6e78fe04
  ok
* edeliver 1.6.0 (Hex package) (mix)
  locked at 1.6.0 (edeliver) 8bfdde1b
  ok
* plug_crypto 1.0.0 (Hex package) (mix)
  locked at 1.0.0 (plug_crypto) 18e49317
  ok
* plug 1.7.2 (Hex package) (mix)
  locked at 1.7.2 (plug) d7b7db7f
  ok
* bamboo 1.2.0 (Hex package) (mix)
  locked at 1.2.0 (bamboo) 8aebd24f
  ok
* plug_cowboy 2.0.1 (Hex package) (mix)
  locked at 2.0.1 (plug_cowboy) d798f8ee
  ok
* phoenix 1.4.1 (Hex package) (mix)
  locked at 1.4.1 (phoenix) 801f9d63
  ok
* guardian 1.2.1 (Hex package) (mix)
  locked at 1.2.1 (guardian) bdc8dd3d
  ok
* phoenix_live_reload 1.2.0 (Hex package) (mix)
  locked at 1.2.0 (phoenix_live_reload) 3bb31a9f
  ok
* phoenix_html 2.13.1 (Hex package) (mix)
  locked at 2.13.1 (phoenix_html) fa8f034b
  ok
* ueberauth 0.5.0 (Hex package) (mix)
  locked at 0.5.0 (ueberauth) 4570ec94
  ok
* ueberauth_google 0.8.0 (Hex package) (mix)
  locked at 0.8.0 (ueberauth_google) dc0e8417
  ok
* sentry 7.0.4 (Hex package) (mix)
  locked at 7.0.4 (sentry) a9a00b48
  ok
* appsignal 1.9.4 (Hex package) (mix)
  locked at 1.9.4 (appsignal) f4706fe8
  ok
* phoenix_ecto 4.0.0 (Hex package) (mix)
  locked at 4.0.0 (phoenix_ecto) c43117a1
  ok

My mix.exs:

defmodule MyApp.Mixfile do
  use Mix.Project

  def project do
    [
      app: :my_app,
      version: "2.0.0",
      elixir: "~> 1.4",
      elixirc_paths: elixirc_paths(Mix.env()),
      compilers: [:phoenix, :gettext] ++ Mix.compilers(),
      aliases: aliases(),
      start_permanent: Mix.env() == :prod,
      deps: deps(),
      dialyzer: [plt_add_deps: :transitive]
    ]
  end

  # Configuration for the OTP application.
  #
  # Type `mix help compile.app` for more information.
  def application do
    [
      mod: {MyApp.Application, []},
      extra_applications: [
        :logger,
        :runtime_tools,
        :appsignal,
        :ueberauth,
        :gen_retry,
        :ueberauth_google
      ]
    ]
  end

  # Specifies which paths to compile per environment.
  defp elixirc_paths(:test), do: ["lib", "test/support"]
  defp elixirc_paths(_), do: ["lib"]

  # Specifies your project dependencies.
  #
  # Type `mix help deps` for examples and options.
  defp deps do
    [
      {:bamboo, "~> 1.2.0"},
      {:plug_cowboy, "~> 2.0"},
      {:plug, "~> 1.7"},
      {:csv, "~> 2.1.1"},
      {:dialyxir, "~> 0.5", only: [:dev], runtime: false},
      {:distillery, "~> 2.0.4"},
      {:decimal, "~> 1.0"},
      {:edeliver, "~> 1.6"},
      {:ex_machina, "~> 2.2", only: :test},
      {:ex_aws, "~> 2.0"},
      {:ex_aws_s3, "~> 2.0"},
      {:ecto_sql, "~> 3.0"},
      {:jason, "~> 1.1"},
      {:gettext, "~> 0.16"},
      {:goth, "~> 0.8.0"},
      {:guardian, "~> 1.0"},
      {:hackney, "~> 1.12"},
      {:httpoison, "~> 1.4"},
      {:ex_doc, "~> 0.19", only: :dev, runtime: false},
      {:logger_papertrail_backend, "~> 1.0"},
      {:phoenix, "~> 1.4.0"},
      {:phoenix_ecto, "~> 4.0"},
      {:phoenix_html, "~> 2.10"},
      {:phoenix_live_reload, "~> 1.0", only: :dev},
      {:phoenix_pubsub, "~> 1.1"},
      {:ueberauth, "~> 0.3"},
      {:ueberauth_google, "~> 0.7"},
      {:quantum, "~> 2.3"},
      {:postgrex, ">= 0.0.0"},
      {:gen_retry, "~> 1.2.0"},
      {:sentry, "~> 7.0"},
      {:sweet_xml, "~> 0.6"},
      {:timex, "~> 3.5.0"},
      {:appsignal, "~> 1.9.4"}
    ]
  end

  defp aliases do
    [
      "ecto.setup": ["ecto.create", "ecto.migrate", "run priv/repo/seeds.exs"],
      "ecto.reset": ["ecto.drop", "ecto.setup"],
    ]
  end
end
josevalim commented 5 years ago

Can you please include your mix.exs, as well as the output of “mix deps”? Thanks. --

José Valim www.plataformatec.com.br Skype: jv.ptec Founder and Director of R&D

jeroenbourgois commented 5 years ago

@josevalim yes, of course! I updated the original ticket.

josevalim commented 5 years ago

So @jeroenbourgois, the only way this error can happen is if you have a bad extension. Maybe the remote server is configured in different ways than the local one?

Do you have anything else being logged? If not, you can try by adding :sasl to :extra_applications in your mix.exs and then adding this configuration to production:

config :logger, handle_sasl_reports: true

This should report much more data and hopefully link to the root clause.

jeroenbourgois commented 5 years ago

@josevalim the remote server is a Amazon RDS, but I do not know that much about it. I added sasl, thanks for the tip! It did provide a lot of output, amongst which I can see the Postgrex.TypeManager being started. However, sadly, the output ends with the same output as above.

The output in between is: Start Call: Registry.start_link(:unique, Postgrex.TypeManager)

We will try to find something on the Amazon RDS side. Can you provide information on what extension exactly should be enabled?

josevalim commented 5 years ago

Can you please put the full output in a gist? Thank you. --

José Valimwww.plataformatec.com.br http://www.plataformatec.com.br/Founder and Director of R&D

jeroenbourgois commented 5 years ago

@josevalim absolutely -> gist

josevalim commented 5 years ago

This is so weird. We can see the TypeManager is started and it never terminates but it still cannot be found. Have you deployed it to production before or is this the first deployment? If the latter, can you try connecting from your machine to the production DB to give things as a try?

jeroenbourgois commented 5 years ago

@josevalim weird indeed 😄 . From OSX, I can connect to them just fine. On the machine itself I tried telnet-ing the RDS which worked, but I don't know of a better way to check that since the staging server has no Postgres installed.

I just spinned up a brand new RDS instance on Amazon on another account, and at first I was unable to curl/telnet to it from the machine, so I saw another more clear Ecto error. Then, once I could connect again from curl, the old errors from above were back. This is so sad, the project is as good as finished, I put off testing on staging because I thought 'it is just the db setup, deploy, run migrations, done'. Not 😛

jeroenbourgois commented 5 years ago

@josevalim I just copied over my app to the remote machine and compiled it over there. Then, when done, I ran it using iex -S mix and it just worked... So there is something with the generated release that is causing the problems I guess. Still need to figure out what, because I don't want to run the app like that, we prefer to deploy with edeliver. But this might give someone a clue?

Also, and this might be important, I recently renamed the whole app from x to y, maybe that is causing some issues somewhere? But then, since I can run the app through iex, this does not seem to be the case.

jeroenbourgois commented 5 years ago

@josevalim solved! I kept on digging to try to find out what had fundamentaly changed in the app that could cause something like this that also had something related to releases.

My eye fell on this output (also in the gist above): 17:29:01.813 [info] Application mix started at :"my_app@127.0.0.1" Starting dependencies.. Starting repos.. Running migrations for my_app 17:29:02.308 [error] GenServer #PID<0.136.0> terminating

The 3 lines without thimestamp were not output by the Logger, but probably with IO.puts Also the to dots instead of three made me realise it had to be something not from distillery/mix/elixir itself.

Then I realised my coworker had finished a long overdue task we had about having a proper setup regarding release tasks with distillery, and the release hooks that are available. He did a good job on one project and then migrated that solution to our other existing projects. All of our projects use MySQL as a db, so the release task started :mariaex before running migrations.

All projects, except this one... So postgrex was not started before running the migrations and seeder, thus causing an error.

Still, the error was very ambiguous for me, I hope my explanation of the actual cause can maybe help to improve error logging in the future, because if the IO.puts calls would not have been there, there would be no indication it was related to that.

So happy it works now!

PS: is there any benefit and/or downside to leaving the sasl app in the setup? Does it slow down the app? If not, would it not be good practice to include it all the time? It is new to me.

josevalim commented 5 years ago

Glad to hear. Having sasl on is totally fine and even recommended. It should not slow anything down. --

José Valimwww.plataformatec.com.br http://www.plataformatec.com.br/Founder and Director of R&D

zemuldo commented 4 years ago

I was using RDS and I ended up with having a space at the end of my RDS URL. It's weird how the error was reported. Removing the space solved the issue.