Re: How to analyze of short but heavy intermittent slowdown on BIND on production database (or BIND vs log_lock_waits)

From: Maxim Boguk <maxim(dot)boguk(at)gmail(dot)com>
To: MichaelDBA <MichaelDBA(at)sqlexec(dot)com>
Cc: Justin Pryzby <pryzby(at)telsasoft(dot)com>, pgsql-performance(at)lists(dot)postgresql(dot)org
Subject: Re: How to analyze of short but heavy intermittent slowdown on BIND on production database (or BIND vs log_lock_waits)
Date: 2023-01-01 16:30:55
Message-ID: CAK-MWwRsAS3fPNA5o674hOVghiRGJYx23mEVBccwmjVHk6umbQ@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

On Sun, Jan 1, 2023 at 3:27 PM MichaelDBA <MichaelDBA(at)sqlexec(dot)com> wrote:

> Howdy,
>
> Few additional questions:
>
> 1. How many concurrent, active connections are running when these BIND
> problems occur? select count(*) from pg_stat_activity where state in
> ('active','idle in transaction')
> 2. Are the queries using gigantic IN (<big list>) values?
> 3. Perhaps unrelated, but is log_temp_files turned on, and if so, do
> you have a lot of logs related to that?
>
> Regards,
> Michael Vitale, just another PG DBA
>

1)usual load (e.g. no anomalies)
10-20 concurrent query runs (e.g. issues isn't related to the load spike or
similar anomalies)
additionally 5-10 short idle in transaction (usual amount too)
total around 300 active connections to the database (after local pgbouncer
in transaction mode)

2)no... long BIND for huge parameter lists is a known issue for me, in this
case there is nothing like that... just (every?) PARSE/BIND stuck for a
short period (including ones which don't require pg_statistic table
access)...
There are some funny samples from the latest spike:
2023-01-01 15:45:09.151 UTC 2421121 ******** from [local]
[vxid:109/20732521 txid:0] [BIND] LOG: duration: 338.830 ms bind
<unnamed>: ROLLBACK
2023-01-01 15:45:09.151 UTC 2365255 ******** from [local] [vxid:41/21277531
txid:2504447286] [PARSE] LOG: duration: 338.755 ms parse <unnamed>:
select nextval ('jobs_id_seq')
along with normal select/insert/update/delete operations stuck for a short
time too...

3)log_temp_files on for sure, I found no correlation with temp file usage,
as well as no correlation between latency spikes and logged autovacuum
actions.

PS: '[BIND] LOG: duration: 338.830 ms bind <unnamed>: ROLLBACK' on a
definitely not overloaded and perfectly healthy server - probably the most
curious log entry of 2022 year for me.

--
Maxim Boguk
Senior Postgresql DBA
https://dataegret.com/

Phone UA: +380 99 143 0000
Phone AU: +61 45 218 5678

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message MichaelDBA 2023-01-01 16:43:10 Re: How to analyze of short but heavy intermittent slowdown on BIND on production database (or BIND vs log_lock_waits)
Previous Message MichaelDBA 2023-01-01 13:27:34 Re: How to analyze of short but heavy intermittent slowdown on BIND on production database (or BIND vs log_lock_waits)