MIME-Version: 1.0
References: 
 <CAHgTRfdDkiX5bLRCYhrP18kFJjcvs1eHvL+jUtX1Ep-Y3=cFVg@mail.gmail.com>
 <66879d8bd44148f2ef1dcde1eff056e6c671306e.camel@cybertec.at>
In-Reply-To: <66879d8bd44148f2ef1dcde1eff056e6c671306e.camel@cybertec.at>
From: James Pang <jamespang886@gmail.com>
Date: Wed, 25 Jun 2025 17:10:55 +0800
Message-ID: 
 <CAHgTRffWqgV0635w-OYz3VKon=GcOiPfKB6PX3_a=mCJs-rcVA@mail.gmail.com>
Subject: Re: many sessions waiting DataFileRead and extend
To: Laurenz Albe <laurenz.albe@cybertec.at>
Cc: pgsql-performance@lists.postgresql.org
Content-Type: multipart/alternative; boundary="0000000000002045a9063861d334"
Archived-At: 
 <https://www.postgresql.org/message-id/CAHgTRffWqgV0635w-OYz3VKon%3DGcOiPfKB6PX3_a%3DmCJs-rcVA%40mail.gmail.com>
Precedence: bulk

--0000000000002045a9063861d334
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

   transparent_hugepage=3Dnever in our prod servers,  %iowait is low 0.x-1.=
x%
, read/write iops <2k, and read/write wait 0.x ms. we did not find other
abnormal logs from OS logs either.  Yes, we are discussing with our
application team to reduce concurrency.  more questions about DataFileRead
and extend wait_event.   when starting read data from physical datafiles ,
it report DataFileRead wait_event, until the data pages successfully loaded
into buffer cache, then end wait_event report from
pg_stat_activity,right?  if some contention in buffer cache, that will make
the session waiting there while in report DataFileRead, right?  another
thing is Operating system page cache, may sessions starting read data in
parallel may bring contention on OS pagecache, bgwriter and checkpointer is
flushing data, or OS background worker may flush dirty pages from OS page
cache too, bgwriter or checkpointer maybe contention on OS pagecache or PG
buffer cache? . no idea how to get the reason from online production
server.

Thanks,

James

Laurenz Albe <laurenz.albe@cybertec.at> =E6=96=BC 2025=E5=B9=B46=E6=9C=8825=
=E6=97=A5=E9=80=B1=E4=B8=89 =E4=B8=8B=E5=8D=881:59=E5=AF=AB=E9=81=93=EF=BC=
=9A

> On Wed, 2025-06-25 at 11:15 +0800, James Pang wrote:
> > pgv14, RHEL8, xfs , we suddenly see tens of sessions waiting on
> "DataFileRead" and
> > "extend", it last about 2 seconds(based on pg_stat_activity query) ,
> during the
> > waiting time, "%sys" cpu increased to 80% , but from "iostat" , no high
> iops and
> > io read/write latency increased either.
>
> Run "sar -P all 1" and see if "%iowait" is high.
>
> Check if you have transparent hugepages enabled:
>
>   cat /sys/kernel/mm/transparent_hugepage/enabled
>
> If they are enabled, disable them and see if it makes a difference.
>
> I am only guessing here.
>
> > many sessions were running same "DELETE FROM xxxx" in parallel waiting
> on "extend"
> > and "DataFileRead", there are triggers in this table "After delete" to
> insert/delete
> > other tables in the tigger.
>
> One thing that almost certainly would improve your situation is to run
> fewer
> concurrent statements, for example by using a reasonably sized connection
> pool.
>
> Yours,
> Laurenz Albe
>

--0000000000002045a9063861d334
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">=C2=A0 =C2=A0transparent_hugepage=3Dnever in our prod serv=
ers,=C2=A0 %iowait is low 0.x-1.x% , read/write iops &lt;2k, and read/write=
 wait 0.x ms. we did not find other abnormal logs from OS logs either.=C2=
=A0

Yes, we are discussing with our application team to reduce concurrency.=C2=
=A0 more questions about DataFileRead and extend wait_event.=C2=A0 =C2=A0wh=
en starting read=C2=A0data from physical datafiles , it report DataFileRead=
 wait_event, until the data pages successfully loaded into buffer cache, th=
en end wait_event report from pg_stat_activity,right?=C2=A0=C2=A0if some co=
ntention in buffer cache, that will make the session waiting=C2=A0there whi=
le=C2=A0in report DataFileRead,=C2=A0right?=C2=A0 another thing is Operatin=
g system page cache, may sessions starting read data in parallel may bring =
contention on OS pagecache,=C2=A0bgwriter and checkpointer is flushing data=
, or OS background worker may flush dirty pages from OS page cache too, bgw=
riter or checkpointer maybe contention on OS pagecache or PG buffer cache? =
. no idea how to get the reason from online production server.=C2=A0<div><b=
r></div><div>Thanks,</div><div><br></div><div>James=C2=A0</div></div><br><d=
iv class=3D"gmail_quote gmail_quote_container"><div dir=3D"ltr" class=3D"gm=
ail_attr">Laurenz Albe &lt;<a href=3D"mailto:laurenz.albe@cybertec.at">laur=
enz.albe@cybertec.at</a>&gt; =E6=96=BC 2025=E5=B9=B46=E6=9C=8825=E6=97=A5=
=E9=80=B1=E4=B8=89 =E4=B8=8B=E5=8D=881:59=E5=AF=AB=E9=81=93=EF=BC=9A<br></d=
iv><blockquote class=3D"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;bord=
er-left:1px solid rgb(204,204,204);padding-left:1ex">On Wed, 2025-06-25 at =
11:15 +0800, James Pang wrote:<br>
&gt; pgv14, RHEL8, xfs , we suddenly see tens of sessions waiting on &quot;=
DataFileRead&quot; and<br>
&gt; &quot;extend&quot;, it last about 2 seconds(based on pg_stat_activity =
query) , during the<br>
&gt; waiting time, &quot;%sys&quot; cpu increased to 80% , but from &quot;i=
ostat&quot; , no high iops and<br>
&gt; io read/write latency increased either.<br>
<br>
Run &quot;sar -P all 1&quot; and see if &quot;%iowait&quot; is high.<br>
<br>
Check if you have transparent hugepages enabled:<br>
<br>
=C2=A0 cat /sys/kernel/mm/transparent_hugepage/enabled<br>
<br>
If they are enabled, disable them and see if it makes a difference.<br>
<br>
I am only guessing here.<br>
<br>
&gt; many sessions were running same &quot;DELETE FROM xxxx&quot; in parall=
el waiting on &quot;extend&quot;<br>
&gt; and &quot;DataFileRead&quot;, there are triggers in this table &quot;A=
fter delete&quot; to insert/delete<br>
&gt; other tables in the tigger.=C2=A0<br>
<br>
One thing that almost certainly would improve your situation is to run fewe=
r<br>
concurrent statements, for example by using a reasonably sized connection p=
ool.<br>
<br>
Yours,<br>
Laurenz Albe<br>
</blockquote></div>

--0000000000002045a9063861d334--