Date: Tue, 30 Aug 2022 11:16:22 +0200
From: hubert depesz lubaczewski <depesz@depesz.com>
Sender: depesz@depesz.com
To: Alvaro Herrera <alvherre@alvh.no-ip.org>
Cc: PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>
Subject: Re: pg_restore deadlocks with itself
Message-ID: <20220830091622.GA29531@depesz.com>
Reply-To: depesz@depesz.com
References: <20220825124411.GA8257@depesz.com>
 <20220830090634.patldggt4zddwgu5@alvherre.pgsql>
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Disposition: inline
In-Reply-To: <20220830090634.patldggt4zddwgu5@alvherre.pgsql>
User-Agent: Mutt/1.10.1 (2018-07-13)
Archived-At: 
 <https://www.postgresql.org/message-id/20220830091622.GA29531%40depesz.com>
Precedence: bulk

On Tue, Aug 30, 2022 at 11:06:34AM +0200, Alvaro Herrera wrote:
> On 2022-Aug-25, hubert depesz lubaczewski wrote:
> 
> > Specifically, command to run it is:
> > sudo -u postgres pg_restore -j 64 -d database -L /tmp/schema-post-data.nopkey.list /tmp/schema-post-data.dump
> 
> > 2022-08-24 20:01:04.466 UTC,"postgres","database",3343477,"[local]",630624ad.330475,42,"ALTER TABLE waiting",2022-08-24 13:16:29 UTC,21/1932,0,LOG,00000,"process 3343477 detected deadlock while waiting for ShareRowExclusiveLock on relation 742617610 of database 16641 after 1000.647 ms","Process holding the lock: 3587718. Wait queue: .",,,,,"ALTER TABLE ONLY some_schema.table_a_o
> >     ADD CONSTRAINT table_a_o_q_id_fk FOREIGN KEY (q_id) REFERENCES some_schema.table_q(id);
> > ",,,"pg_restore","client backend",,3355460102417501954
> > 
> > 
> > 2022-08-24 20:01:50.291 UTC,"postgres","database",3343477,"[local]",630624ad.330475,46,"ALTER TABLE waiting",2022-08-24 13:16:29 UTC,21/1933,0,LOG,00000,"process 3343477 detected deadlock while waiting for ShareRowExclusiveLock on relation 742617610 of database 16641 after 1000.030 ms","Process holding the lock: 3587718. Wait queue: .",,,,,"ALTER TABLE ONLY some_schema.table_a
> >     ADD CONSTRAINT fk_rails_46718e626a FOREIGN KEY (migrate_from_id) REFERENCES some_schema.table_q(id);
> > ",,,"pg_restore","client backend",,-2548896815899838768
> > 
> > Now, I know I can fix the situation by adding missing fkeys myself, but
> > I don't think pg_restore should be putting itself in deadlock.
> 
> You're right, it shouldn't.  Parallel restore shouldn't run DDL commands
> in parallel that would deadlock, but I suppose there must be holes in
> that.
> 
> What was process 3587718 doing at the time?  Some DDL in
> some_schema.table_q, I suspect, right?  Are any of these tables
> partitioned?

So, more info from logs:

2022-08-24 20:01:04.466 UTC,"postgres","database",3343477,"[local]",630624ad.330475,43,"ALTER TABLE",2022-08-24 13:16:29 UTC,21/1932,0,ERROR,40P01,"deadlock detected","Process 3343477 waits for ShareRowExclusiveLock on relation 742617610 of database 16641; blocked by process 3587718.
Process 3587718 waits for RowExclusiveLock on relation 742615338 of database 16641; blocked by process 3343477.
Process 3343477: ALTER TABLE ONLY some_schema.table_ao
    ADD CONSTRAINT table_ao_q_id_fk FOREIGN KEY (q_id) REFERENCES some_schema.table_q(id);


Process 3587718: <command string not enabled>","See server log for query details.",,,,"ALTER TABLE ONLY some_schema.table_ao
    ADD CONSTRAINT table_ao_q_id_fk FOREIGN KEY (q_id) REFERENCES some_schema.table_q(id);


",,,"pg_restore","client backend",,3355460102417501954

Which is weird, as it seems that they both were trying to do the same fkey?!

Neither table_ao nor table_q are partitioned, and used restore-list contained this fkey only once.

Best regards,

depesz