When I am restarting a backend application with
mix phx.serverthe following errors are emitted (3 of them):
2023-10-06T14:17:37.686454+02:00 error: Could not create schema migrations table. This error [...]
2023-10-06T14:17:37.687061+02:00 error: Could not create schema migrations table. [...]
2023-10-06T14:17:37.930492+02:00 error: GenServer #PID<0.2226.0> terminating, ** (Postgrex.Error) ERROR 40P01 (deadlock_detected) deadlock detected, [...]
2023-10-06T14:17:37.938410+02:00 error: GenServer #PID<0.2364.0> terminating, ** (Postgrex.Error) ERROR 40P01 (deadlock_detected) deadlock detected, [...] lib/phoenix_ecto/check_repo_status.ex:99: Phoenix.Ecto.CheckRepoStatus.migration...
2023-10-06T14:17:38.663907+02:00 error: Could not create schema migrations table. [...]
2023-10-06T14:17:38.761540+02:00 error: GenServer #PID<0.2308.0> terminating, ** (Postgrex.Error) ERROR 40P01 (deadlock_detected) deadlock detected, [...]```
Increasing the verbosity of the postresql server (to narrow down further what’s going on) makes these errors disappear. But I guess they are still there.
- Why there are 3 processes running at all? I have 3 tabs opened in the browser, pointing to different routes
- The DB has an event trigger added - which is excluding
- Got the feeling it has something to do with checking for the
2023-10-08 06:31:59.294 CEST  phoenix@p1 DETAIL: Process 116650 waits for AccessExclusiveLock on object 60892 of class 2620 of database 16389; blocked by process 116647.
Process 116647 waits for AccessExclusiveLock on relation 25408 of database 16389; blocked by process 116650.
Process 116650: CREATE TABLE IF NOT EXISTS "schema_migrations" ("version" bigint, "inserted_at" timestamp(0), PRIMARY KEY ("version"))
Process 116647: CREATE TABLE IF NOT EXISTS "schema_migrations" ("version" bigint, "inserted_at" timestamp(0), PRIMARY KEY ("version"))
Where and how to investigate further?
Any help appreciated
How do you start/stop/restart the app?
Starting the app with
mix phx.server and in case the application gets recompiled during a source code change I see this deadlock popping up in the log and in the open browser windows (which I have to manually reload)
I guess that the mentioned 3 open windows are reconnecting then and getting data almost simultaneously from the db.
I don’t know why the
CREATE TABLE IF NOT EXISTS schema_migrations command is even issued 3 times at all. Thought there would we something like a singleton to handle that check.
Not sure if there is any relation to:
Have you tried commenting out the
Phoenix.Ecto.CheckRepoStatus? Does it still happen then?
I give it a try and let you know.
Thank you for the guidance
Looks like commenting out
CheckRepoStatus solved the problem.
Are there any drawbacks if I keep it like this?
(Still asking myself why I’m the only one facing this deadlock but that’s for another day)
Can you check if it still trying to do the migrations with this commented out.
From that timestamp on I modified the
endpoint.ex file there are no such events logged.
Is it trying to run (any) migrations at all - or is it just checking for the existence of
schema.migrations ? I did not check the source code involved in this
I will have a look at the source if I find the time.
I don’t understand why it is trying to create the migration table at all
In any case. Thank you for the help. Appreciated it!
The migration table is a hard requirement when using a database. So by using the
create if not exists they can ensure it exists, without having to check for its existance.
And I guess that’s the reason for a deadlock at my end.
I don’t know enough about postgresql. But I take it that it does a lock if creating a table.
I will have a look the upcoming weekend and try to figure out what is going on
Yes, but unless you are starting more than 1 endpoint or more than once, you shouldn’t have that problem.
Looks like I have more than one endpoint running.
Don’t know why and what is going on at all.
Because I also see tripled messages from
live_reload in my console log:
[2023-10-20 14:50:20.812] [debug] Live reload: lib/backend_web/live/components/navbar.ex
[2023-10-20 14:50:20.813] [debug] Live reload: lib/backend_web/live/components/navbar.ex
[2023-10-20 14:50:20.847] [debug] Live reload: lib/backend_web/live/components/navbar.ex
I’d start with looking in application.ex, what is started there?