When and how does Postgres use "transactionid" locks

Question

I've ran into a need to figure this out on 9.6, but information on anything 9.6 or later would be appreciated.

I'm having an issue with my application being blocked on a database call because it's attempting to acquire an implicit transactionid lock on a another running transaction. What I don't understand is why.

I understand that every transaction, when it starts, acquires an ExclusiveLock on its own transaction ID (pg_locks). That's fine. That same page says that, "normally", only transactions that "change the state of the database" are assigned a permanent ID. I see the permanent ID in the locks table, so I assume that happened. However, the description is less clear, as the page neither specifies what does "normally" mean, nor what is considered "change of database state".

But then I can't find any information that specifies when would a statement attempt to acquire a SharedLock on some other transaction. The only statement from pg_locks is:

When a process finds it necessary to wait specifically for another transaction to end, it does so by attempting to acquire share lock on the other transaction's ID (either virtual or permanent ID depending on the situation)

Which is really vague. There is no way to request a transaction lock (at least I don't see them listed in Explicit Locking)

So I'm looking for the following answers:

1. When does Postgres decide to acquire (shared) transactionid lock on another transaction ID?
2. What exactly causes Postgres to assign a "permanent ID" to a transaction (that's less important for me to figure out how to fix my database use, but I was just generally confused by lack of hard information on this anywhere)
3. What is making the insert query acquire transactionid lock in this particular case (also less important, because if I had the reference, I could have determined that myself)

Now, for the particular reason my query is blocked in this case:

Relevant pg_locks content:

x=# select locktype,transactionid,virtualtransaction,pid,mode,granted
x-# from pg_locks where transactionid = '33682979' ;
   locktype    | transactionid | virtualtransaction |  pid   |     mode      | granted 
---------------+---------------+--------------------+--------+---------------+---------
 transactionid |      33682979 | 7/27909            | 476513 | ShareLock     | f
 transactionid |      33682979 | 5/387791           | 476509 | ExclusiveLock | t
(2 rows)

PID 476513 is stuck trying to insert:

x=# SELECT wait_event_type, state, query 
x-# FROM pg_stat_activity 
x-# WHERE pid = 476513;
 wait_event_type | state  |                              query                                                                                                                     
-----------------+--------+--------------------------------------------------------------------
 Lock            | active | INSERT INTO association (id, device, campaign) VALUES ($1, $2, $3)
(1 row)

I have full statement logging enabled, so I can also see what did PID 476509 do since declaring the last transaction. The only query that I can imagine has anything to do with it is the fact that it has deleted from association table.

$ grep '476509.*execute' tx-lock.txt
<2020-06-17 13:58:37.743 CEST 476509.5/387791> LOG:  execute S_13: BEGIN
<2020-06-17 13:58:37.743 CEST 476509.5/387791> LOG:  execute <unnamed>: SELECT t0.* FROM campaign t0 WHERE t0.id = $1 FOR UPDATE
<2020-06-17 13:58:37.744 CEST 476509.5/387791> LOG:  execute <unnamed>: SELECT t0.* FROM campaign t0 WHERE t0.id = $1 FOR UPDATE
<2020-06-17 13:58:37.752 CEST 476509.5/387791> LOG:  execute <unnamed>: SELECT t0.* FROM association t0 WHERE (t0.enabled = $1 AND $2 = t0.campaign AND t0.statusCreated <> $3) LIMIT $4
<2020-06-17 13:58:37.759 CEST 476509.5/387791> LOG:  execute <unnamed>: DELETE FROM association WHERE id IN (SELECT DISTINCT t0.id FROM association t0 WHERE (t0.campaign = $1))
<2020-06-17 13:58:37.796 CEST 476509.5/387791> LOG:  execute <unnamed>: UPDATE campaign SET statusCreated = $1 WHERE id = $2
<2020-06-17 13:58:37.796 CEST 476509.5/387791> LOG:  execute S_42: SELECT t0.id FROM lock t0 WHERE t0.id = $1
<2020-06-17 13:58:37.796 CEST 476509.5/387791> LOG:  execute S_31: select id from lock where id = $1 for update
<2020-06-17 13:58:37.798 CEST 476509.5/387791> LOG:  execute <unnamed>: SELECT t0.*, t1.*id FROM groups t0 INNER JOIN devices t1 ON t0.device_id = t1.id AND t0.device_tenancy = t1.tenancy LEFT OUTER JOIN group_defs t2 ON t0.DEVICEGROUP_ID = t2.id WHERE ((t0.group_id = $1...) AND t1.tenancy = $36) ORDER BY t0.id ASC, t1.id ASC LIMIT $37

(pardon some of the queries, they are created by a JPA, and not by me :) )

Unbar

Answer 1

That usually indicates that the transaction waits for a row lock that is held by the transaction it is waiting for.

Row locks are not stored in the shared memory locking table permanently, but on the table row itself in the xmax system column. The value stored there is the transaction number of the blocking transaction (usually).

Once a transaction has found out who holds the lock on that row, it starts waiting for that transaction to finish, which will release the exclusive lock it holds on its own transaction ID.

Depository

That doesn't explain lock on insert – Jasso

@Jasso It could if there are conflicting inserts. – Depository

I am in a similar situation. I have a function which is processing an insert into a table which has several triggers and other inserts into other tables. I am trying to multi-thread this process, but it is getting stuck in a lock when I try to. I am sure there is a conflicting insert/update somewhere... but so far I am having trouble getting any information about where. How can I drill down to get something like a stack dump of where the actual conflict is? – Mallory

@AlexiTheodore You have to dig through pg_locks and use pg_blocking_pids() to figure out who blocks whom and what locks are held. Then attach to the application threads involved with a debugger and figure out what transaction they are performing and what SQL statements they have issued. Once you understand how the lock happens and why, you can fix it. Hint: increase deadlock_timeout to have time for all that before the deadlock is resolved. – Depository

Thanks @LaurenzAlbe but I think you misunderstood my issue, which was that after doing exactly what you were saying (see the description), it was not providing any useful information because of nested functions. The locking was happening somewhere inside a function and I didn't know where. Oddly enough, the only way I could figure it out was to set log_lock_waits to a short figure and then watch the logs. This gave me meaningful diagnostics where I was unable to anywhere else. – Mallory