Обсуждение: Commit with wait event on advisory lock!

Advisory locks are used by developers

<msalais@msym.fr> writes:
> How a COMMIT statement could be blocked by a lock whatever the kind of the lock could be. COMMIT releases locks. How
couldit be blocked by a lock?! 

There could be pre-commit actions (for example, firing deferred
triggers) that need to take locks the transaction didn't already
hold.  You've provided no details that would let anyone diagnose
the exact cause, though.

            regards, tom lane

Hi Tom,

Sorry,
- It is PG 14.4
- Replication is used (2 standby, one sync and the other potential) but no
application connection to replica.
- No deferrable constraints:
some_db=# select count(*) from pg_constraint where condeferrable ;
count
-------
     0
(1 row)

- No triggers:
some_db=# select count(*) from pg_trigger ;
count
-------
     0
(1 row)

I only capture statements executed within database some_db.

And finally, this is how I take snaps (this is launched by crontab every
hour). I also tried to capture 'idle in transaction' ...

do
$$
declare
  debut timestamptz := current_timestamp;
begin
  set synchronous_commit = local; -- I don't care about replication for my
table
  <<main>>
  loop
    insert into public.ms_slow_stmts(datname, pid, leader_pid, usename,
application_name, backend_start, xact_start, query_start, stmt_duration,
tx_idle_duration, ts_now, state, wait_event_type, wait_event, query_id,
query)
    select
      datname,
      pid,
      leader_pid,
      usename,
      application_name,
      backend_start,
      xact_start,
      query_start,
      case
        when state = 'idle in transaction' then state_change - query_start
        else clock_timestamp - query_start
      end stmt_duration,
      case
        when state = 'idle in transaction' then clock_timestamp -
state_change
        else interval '0s'
      end tx_idle_duration,
      clock_timestamp ts_now,
      state,
      wait_event_type,
      wait_event,
      query_id,
      query
    from pg_stat_activity
    where
      backend_type = 'client backend'
      and
      datname = 'some_db'
      and
      state != 'idle'
      and
      (
        case
          when state = 'idle in transaction' then state_change - query_start
-- last query execution time if in 'idle in transaction' state
          else clock_timestamp - query_start -- time from query start for
current query
        end >= interval'2s'
        or
        case
          when state = 'idle in transaction' then clock_timestamp -
state_change
          else interval'0s'
        end >= interval'1s' -- in state 'idle in transaction' for more than
1 s
      );
      commit;
    exit when clock_timestamp - debut >= interval'00:59:55';
    perform pg_sleep(1);
  end loop main;
end;
$$;

Best regards

---
Michel SALAIS

-----Message d'origine-----
De : Tom Lane <tgl@sss.pgh.pa.us>
Envoyé : mercredi 22 janvier 2025 01:49
À : msalais@msym.fr
Cc : 'Rajesh Kumar' <rajeshkumar.dba09@gmail.com>;
pgsql-admin@lists.postgresql.org
Objet : Re: Commit with wait event on advisory lock!

<msalais@msym.fr> writes:
> How a COMMIT statement could be blocked by a lock whatever the kind of the
lock could be. COMMIT releases locks. How could it be blocked by a lock?!

There could be pre-commit actions (for example, firing deferred
triggers) that need to take locks the transaction didn't already hold.
You've provided no details that would let anyone diagnose the exact cause,
though.

            regards, tom lane

<msalais@msym.fr> writes:
> - Replication is used (2 standby, one sync and the other potential) but no
> application connection to replica.

Maybe you have synchronous_commit set to enforce waiting for the
standby to receive/apply the transaction?  If so I'd look for
possible delays there.

            regards, tom lane

Hello Tom

I do have delays sometimes because of synchronous_commit (We use actually
the default value and synchronous_standby_names is not empty). I have
sometimes commit execution time more than 10 sec but the problem is more
general than commit/synchronization.

But my concern here is really to understand in which situations, a COMMIT
statement can wait on a lock especially that I have no triggers, and no
deferrable constraints...

What could it be? This can point something to look about...

By the way I also have commits which are waiting on ClientRead...

--
Michel SALAIS

-----Message d'origine-----
De : Tom Lane <tgl@sss.pgh.pa.us>
Envoyé : mercredi 22 janvier 2025 18:24
À : msalais@msym.fr
Cc : 'Rajesh Kumar' <rajeshkumar.dba09@gmail.com>;
pgsql-admin@lists.postgresql.org
Objet : Re: Commit with wait event on advisory lock!

<msalais@msym.fr> writes:
> - Replication is used (2 standby, one sync and the other potential)
> but no application connection to replica.

Maybe you have synchronous_commit set to enforce waiting for the standby to
receive/apply the transaction?  If so I'd look for possible delays there.

            regards, tom lane

<msalais@msym.fr> writes:
> But my concern here is really to understand in which situations, a COMMIT
> statement can wait on a lock especially that I have no triggers, and no
> deferrable constraints...

The core code does nothing with advisory locks.  If COMMIT is blocking
on one of those, it must be a consequence of user-defined code that
is running at pre-commit time.  You've given us nothing to go on about
what that could be.

> By the way I also have commits which are waiting on ClientRead...

That, on the other hand, is surely impossible.  I think maybe you
are misreading the stats display.  Typically I'd expect that such a
case indicates that the session is idle (awaiting a new command)
and the COMMIT is the last thing it did before that.

            regards, tom lane

Hello,

The session is marked ***active***. It is not in idle state and the query is
'commit' and the event is ***ClientRead***! There is no doubt...
This one and the wait on advisory lock by a commit statement let me think
about Oracle saying that it doesn't guarantee consistence for dynamic tables
data, and it could be the same thing here for pg_stat_activity. Could it be?
It could depend on protocol and when exactly this dynamic table is
updated...

Best regards

---
Michel SALAIS

-----Message d'origine-----
De : Tom Lane <tgl@sss.pgh.pa.us>
Envoyé : mercredi 22 janvier 2025 23:18
À : msalais@msym.fr
Cc : 'Rajesh Kumar' <rajeshkumar.dba09@gmail.com>;
pgsql-admin@lists.postgresql.org
Objet : Re: Commit with wait event on advisory lock!

<msalais@msym.fr> writes:
> But my concern here is really to understand in which situations, a
> COMMIT statement can wait on a lock especially that I have no
> triggers, and no deferrable constraints...

The core code does nothing with advisory locks.  If COMMIT is blocking on
one of those, it must be a consequence of user-defined code that is running
at pre-commit time.  You've given us nothing to go on about what that could
be.

> By the way I also have commits which are waiting on ClientRead...

That, on the other hand, is surely impossible.  I think maybe you are
misreading the stats display.  Typically I'd expect that such a case
indicates that the session is idle (awaiting a new command) and the COMMIT
is the last thing it did before that.

            regards, tom lane

Hi,
Just an example of my result today:
<code>
postgres=# select pid,  xact_start, query_start, ts_now, stmt_duration,
state, wait_event_type, wait_event, query from public.ms_slow_stmts where
query ilike 'commit' and wait_event_type in ('Client', 'Lock');
   pid   |          xact_start           |          query_start          |
ts_now             |  stmt_duration  | state  | wait_event_type | wait_event
| query
---------+-------------------------------+-------------------------------+--
-----------------------------+-----------------+--------+-----------------+-
-----------+--------
  529392 | 2025-01-21 05:55:19.427214+01 | 2025-01-21 05:55:19.429889+01 |
2025-01-21 05:55:21.569339+01 | 00:00:02.13945  | active | Client          |
ClientRead | COMMIT
2285947 | 2025-01-21 05:55:19.426945+01 | 2025-01-21 05:55:19.428651+01 |
2025-01-21 05:55:21.569342+01 | 00:00:02.140691 | active | Lock            |
advisory   | COMMIT
4106658 | 2025-01-22 13:04:29.551289+01 | 2025-01-22 13:04:29.726165+01 |
2025-01-22 13:04:33.191303+01 | 00:00:03.465138 | active | Client          |
ClientRead | COMMIT
4106652 | 2025-01-22 13:04:30.068406+01 | 2025-01-22 13:04:30.073688+01 |
2025-01-22 13:04:33.191322+01 | 00:00:03.117634 | active | Client          |
ClientRead | COMMIT
4106625 | 2025-01-22 13:04:30.064757+01 | 2025-01-22 13:04:30.070484+01 |
2025-01-22 13:04:33.191402+01 | 00:00:03.120918 | active | Client          |
ClientRead | COMMIT
  119472 | 2025-01-22 19:19:43.156342+01 | 2025-01-22 19:19:43.159275+01 |
2025-01-22 19:19:45.208617+01 | 00:00:02.049342 | active | Client          |
ClientRead | COMMIT
</code>

Michel SALAIS

-----Message d'origine-----
De : msalais@msym.fr <msalais@msym.fr>
Envoyé : jeudi 23 janvier 2025 19:36
À : 'Tom Lane' <tgl@sss.pgh.pa.us>
Cc : 'Rajesh Kumar' <rajeshkumar.dba09@gmail.com>;
pgsql-admin@lists.postgresql.org
Objet : RE: Commit with wait event on advisory lock!

Hello,

The session is marked ***active***. It is not in idle state and the query is
'commit' and the event is ***ClientRead***! There is no doubt...
This one and the wait on advisory lock by a commit statement let me think
about Oracle saying that it doesn't guarantee consistence for dynamic tables
data, and it could be the same thing here for pg_stat_activity. Could it be?
It could depend on protocol and when exactly this dynamic table is
updated...

Best regards

---
Michel SALAIS

-----Message d'origine-----
De : Tom Lane <tgl@sss.pgh.pa.us>
Envoyé : mercredi 22 janvier 2025 23:18
À : msalais@msym.fr
Cc : 'Rajesh Kumar' <rajeshkumar.dba09@gmail.com>;
pgsql-admin@lists.postgresql.org Objet : Re: Commit with wait event on
advisory lock!

<msalais@msym.fr> writes:
> But my concern here is really to understand in which situations, a
> COMMIT statement can wait on a lock especially that I have no
> triggers, and no deferrable constraints...

The core code does nothing with advisory locks.  If COMMIT is blocking on
one of those, it must be a consequence of user-defined code that is running
at pre-commit time.  You've given us nothing to go on about what that could
be.

> By the way I also have commits which are waiting on ClientRead...

That, on the other hand, is surely impossible.  I think maybe you are
misreading the stats display.  Typically I'd expect that such a case
indicates that the session is idle (awaiting a new command) and the COMMIT
is the last thing it did before that.

            regards, tom lane