Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1uUcQE-005x0l-S5 for pgsql-performance@arkaria.postgresql.org; Thu, 26 Jun 2025 02:33:07 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1uUcQC-006uEi-It for pgsql-performance@arkaria.postgresql.org; Thu, 26 Jun 2025 02:33:05 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1uUcQC-006uEX-5x for pgsql-performance@lists.postgresql.org; Thu, 26 Jun 2025 02:33:04 +0000 Received: from mail-yw1-x1130.google.com ([2607:f8b0:4864:20::1130]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.96) (envelope-from ) id 1uUcQA-0048lH-2b for pgsql-performance@lists.postgresql.org; Thu, 26 Jun 2025 02:33:04 +0000 Received: by mail-yw1-x1130.google.com with SMTP id 00721157ae682-7086dcab64bso5267807b3.1 for ; Wed, 25 Jun 2025 19:33:02 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1750905181; x=1751509981; darn=lists.postgresql.org; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:from:to:cc:subject:date:message-id:reply-to; bh=NIl/W4wx3El6GxdrmrHvBDEjgjnnAStHfUk1++O39fU=; b=UuFU+J1VXx6Xs8VjMIdgiZR8ykyzynqob0t5y9e1tSTxiV8VQV7HwHEleb6K3nxKP0 olkzzwHZxfEKxKFYlbsVmqYOslPvotLYqybMArOentlIy9HLkenQj2mk6eNgKspUVKm1 7Fi/z1IeG0rD3+G8ipkq7MpcV4v2I6sC5NtCpVXUwHrE6rVEpubt/scUbbrNwQeuwT0p eAFRnZ9O38v+vTN3PuBkvHbEsHTVxxmGdznN9EfNHnNE52sxir0UccDVmZQnN4/KhNc2 nsDQrWdrro5QaSZXPWYw7P4T2VZ5qqyjEs/S9fXD8U6hvlnqcCbFNMdJwIaJPXumhPHr AnDg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1750905181; x=1751509981; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=NIl/W4wx3El6GxdrmrHvBDEjgjnnAStHfUk1++O39fU=; b=CYJtdSQcGAACm/vgsME9MY+JKIfv2qoLzfbWWtL/FND+TTAdqOFzErxrUu4YUOHlJK v0fuZiW4ve4vUWnjFAZhET740QOwfQJEwLNg+IOrS1fXRWNzILa1TJuZTTJppVAjiihP LrGHGy5V9p2oI+jUVWw6ZXFV8+p2g4X/L8m4ufmSzwyXn0TrUlVA8nvombsueUvQDPdM TB/AUngg6369ip+hA0QC5mIGliR/u4TjGTN3FN+d+bl9gJnUlCkcZf83jG6aU6Ho5tcE PkrUHjcDTcVXOOvnR4HV17wib4GjSf1Mn21A8hrBXXEoLkkG1Dc0Q6UPWE8s8LsFCwMC DhAA== X-Forwarded-Encrypted: i=1; AJvYcCXvUE8BEuFslpxAuhBpW/Qd7nns4wsoq7gWnHYVg1v5iYifK4L85kWuqPllfzgrQEVp47yHTItc45p29fM0PCI8qg==@lists.postgresql.org X-Gm-Message-State: AOJu0Yw5VstDDWq+juj6do0kQLM59g5zxHOXCOOk547mo5RoNsDy2w3T wINUcABYVV4zp4Y7n1RFOIE6JAOsl4jeT8yXUDnbcGSGah+PoHsq4S5aiNQ6DaRe/x2N/39gLoA RyPj8Iw2sR+rdaRaCdbd23iCGB/w5NKiXZofc X-Gm-Gg: ASbGncuWLkTIAwu2ba7hy5JecTxlxHQmRtX7662zwL0Qw3SC4VuvxpOoLFFLcUwVxyj How1XePbWPD4vj0CFhCySQqz/Y+XS/dSfU70Tg2yaknhW6PTUn+dYhG/XZ3dvNh58fOcM+uwPhM VYAIk3hOb4SWuhJhfvcGtF/+ERVGFkrKioDmOO2xLU2ZQ= X-Google-Smtp-Source: AGHT+IHXdpZfDmvfJGn+5dvswQkIrDTHuDFVSbPXCRjaAizp0I2VVFOYw16FlVU42lQO+6mv5einnRtQiQRP2Yw0iqs= X-Received: by 2002:a05:690c:fd3:b0:711:af14:3981 with SMTP id 00721157ae682-71406de1bfbmr82365517b3.31.1750905180871; Wed, 25 Jun 2025 19:33:00 -0700 (PDT) MIME-Version: 1.0 References: <66879d8bd44148f2ef1dcde1eff056e6c671306e.camel@cybertec.at> In-Reply-To: From: James Pang Date: Thu, 26 Jun 2025 10:32:50 +0800 X-Gm-Features: Ac12FXyjHAJ0UZowCUeDrSa0zj-8wr4bBAoHd0MIyNmMHs9gvPWmBTdsNEPHmdM Message-ID: Subject: Re: many sessions waiting DataFileRead and extend To: Frits Hoogland Cc: Laurenz Albe , pgsql-performance@lists.postgresql.org Content-Type: multipart/alternative; boundary="00000000000057625a0638706103" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --00000000000057625a0638706103 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable thans for you suggestions, we have iowait from sar command too, copy here, checking with infra team not found abnormal IO activities either. 02:00:01 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle 02:00:03 PM all 15.92 0.00 43.02 0.65 0.76 2.56 0.00 0.00 0.00 37.09 02:00:03 PM 0 17.59 0.00 46.73 1.01 0.50 0.50 0.00 0.00 0.00 33.67 02:00:03 PM 1 9.50 0.00 61.50 0.50 0.50 1.00 0.00 0.00 0.00 27.00 02:00:03 PM 2 20.71 0.00 44.44 1.01 0.51 0.51 0.00 0.00 0.00 32.83 02:00:03 PM 3 14.00 0.00 51.50 2.00 1.00 1.00 0.00 0.00 0.00 30.50 02:00:03 PM 4 6.57 0.00 52.53 0.51 0.51 3.54 0.00 0.00 0.00 36.36 02:00:03 PM 5 10.20 0.00 49.49 1.02 1.53 0.00 0.00 0.00 0.00 37.76 02:00:03 PM 6 27.64 0.00 41.21 0.50 0.50 0.50 0.00 0.00 0.00 29.65 02:00:03 PM 7 9.05 0.00 50.75 0.50 1.01 0.50 0.00 0.00 0.00 38.19 02:00:03 PM 8 12.18 0.00 49.75 0.51 0.51 0.51 0.00 0.00 0.00 36.55 02:00:03 PM 9 13.00 0.00 9.50 0.50 1.50 15.50 0.00 0.00 0.00 60.00 02:00:03 PM 10 15.58 0.00 46.23 0.00 0.50 0.50 0.00 0.00 0.00 37.19 02:00:03 PM 11 20.71 0.00 10.10 0.00 1.01 14.14 0.00 0.00 0.00 54.04 02:00:03 PM 12 21.00 0.00 37.00 0.50 1.00 1.00 0.00 0.00 0.00 39.50 02:00:03 PM 13 13.57 0.00 45.73 1.01 1.01 1.01 0.00 0.00 0.00 37.69 02:00:03 PM 14 18.18 0.00 39.39 1.01 0.51 0.51 0.00 0.00 0.00 40.40 02:00:03 PM 15 14.00 0.00 49.50 0.50 0.50 3.50 0.00 0.00 0.00 32.00 02:00:03 PM 16 19.39 0.00 39.80 1.02 1.53 0.51 0.00 0.00 0.00 37.76 02:00:03 PM 17 16.75 0.00 45.18 1.52 1.02 2.54 0.00 0.00 0.00 32.99 02:00:03 PM 18 12.63 0.00 50.00 0.00 1.01 0.00 0.00 0.00 0.00 36.36 02:00:03 PM 19 5.56 0.00 82.32 0.00 0.00 0.00 0.00 0.00 0.00 12.12 02:00:03 PM 20 15.08 0.00 48.24 0.50 0.50 3.52 0.00 0.00 0.00 32.16 02:00:03 PM 21 17.68 0.00 9.09 0.51 1.52 13.64 0.00 0.00 0.00 57.58 02:00:03 PM 22 13.13 0.00 43.94 0.51 0.51 0.51 0.00 0.00 0.00 41.41 02:00:03 PM 23 14.07 0.00 42.71 0.50 0.50 0.50 0.00 0.00 0.00 41.71 02:00:03 PM 24 13.13 0.00 41.92 1.01 0.51 0.51 0.00 0.00 0.00 42.93 02:00:03 PM 25 16.58 0.00 47.74 0.50 1.01 0.50 0.00 0.00 0.00 33.67 02:00:03 PM 26 16.58 0.00 46.73 0.50 1.01 0.50 0.00 0.00 0.00 34.67 02:00:03 PM 27 45.50 0.00 54.50 0.00 0.00 0.00 0.00 0.00 0.00 0.00 02:00:03 PM 28 6.06 0.00 32.32 0.00 0.51 13.13 0.00 0.00 0.00 47.98 02:00:03 PM 29 13.93 0.00 44.78 1.00 1.00 0.50 0.00 0.00 0.00 38.81 02:00:03 PM 30 11.56 0.00 57.79 0.00 0.50 1.01 0.00 0.00 0.00 29.15 02:00:03 PM 31 33.85 0.00 9.23 0.51 1.54 0.51 0.00 0.00 0.00 54.36 02:00:03 PM 32 30.15 0.00 41.71 0.50 0.50 1.51 0.00 0.00 0.00 25.63 Thanks, James Frits Hoogland =E6=96=BC 2025=E5=B9=B46=E6=9C=88= 25=E6=97=A5=E9=80=B1=E4=B8=89 =E4=B8=8B=E5=8D=8810:27=E5=AF=AB=E9=81=93=EF= =BC=9A > > > > On 25 Jun 2025, at 07:59, Laurenz Albe wrote= : > > > > 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 hig= h > iops and > >> io read/write latency increased either. > > > > Run "sar -P all 1" and see if "%iowait" is high. > I would (strongly) advise against the use of iowait as an indicator. It i= s > a kernel approximation of time spent in IO from which cannot be use used = in > any sensible way other than possibly you're doing IO. > First of all, iowait is not a kernel state, and therefore it's taken from > idle. This means that if there is no, or too little, idle time, iowait th= at > should be there is gone. > Second, the calculation to transfer idle time to iowait is done for > synchronous IO calls only. Which currently is not a problem for postgres > because it uses exactly that, but in the future it might. > Very roughly put, what the kernel does is keep a counter of tasks > currently in certain system IO calls, and then try to express that using > iowait. The time in IO wait can't be used calculate any IO facts. > > In that sense, it puts it in the same area as the load figure: indicative= , > but mostly useless because it doesn't give you any facts about what it is > expressing. > > > > 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. > Absolutely. Anything that is using signficant amounts of memory and is no= t > created to take advantage of transparent hugepages will probably experien= ce > more downsides from THP than it helps. > > > >> 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. > This is true if the limits of the IO device, or anything towards to IO > device or devices are hit. > And in general, high "%sys", alias lots of time spent in kernel mode alia= s > system time indicates lots of time spent in system calls, which is what t= he > read and write calls in postgres are. > Therefore these figures suggest blocking for IO, for which Laurenz' advis= e > to lower the amount of concurrent sessions doing IO in general makes sens= e. > A more nuanced analysis: if IO requests get queued, these will wait in 'D= ' > state in linux, which by definition is off cpu, and thus do not spent cpu > (system/kernel) time. > > What sounds suspicious is that you indicate you indicate there is you see > no signficant change in the amount of IO in iostat. > > In order to understand this, you will have to first carefully find the > actual IO physical IO devices that you are using for postgres IO. > In current linux this can be tricky, depending on how the hardware or > virtual machine looks like, and how the disks are arranged in linux. > What you need to determine is which actual disk devices are used, and wha= t > their limits are. > Limits for any disk are IOPS (operations per second) and MBPS (megabytes > per second -> bandwdith). > > There is an additional thing to realize, which makes this really tricky: > postgres for common IO uses buffered IO. > Buffered IO means any read or write will use the linux buffercache, and > read or writes can be served from the buffercache if possible. > > So in your case, if you managed to make the database perform identical > read or write requests, this could result in a difference of amounts of > read and write IOs served from the cache, which can make an enormous > amounts of difference for how fast these requests are served. If somehow > you managed to make the operating system choose to use the physical IO > path, you will see significant amounts time spent on that, which will hav= e > IO related wait events. > > Not a simple answer, but this is how it works. > > So I would suggest checking the difference between the situation of when > it's doing the same which is considered well performing versus badly > performing. > > > > > > Yours, > > Laurenz Albe > > > > > > --00000000000057625a0638706103 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
thans for you suggestions, we have iowait from sar command= too, copy here, checking with infra team not found abnormal IO activities = either.=C2=A0=C2=A0
02:00:01 PM =C2=A0CPU =C2=A0 =C2=A0%usr =C2=A0 %nic= e =C2=A0 =C2=A0%sys %iowait =C2=A0 =C2=A0%irq =C2=A0 %soft =C2=A0%steal =C2= =A0%guest =C2=A0%gnice =C2=A0 %idle
02:00:03 PM =C2=A0all=C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A015.92 =C2=A0 =C2=A00.00 =C2=A0 43.02 =C2=A0 =C2=A00.65 = =C2=A0 =C2=A00.76 =C2=A0 =C2=A02.56 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 37.09
02:00:03 PM =C2=A0 =C2=A00=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A017.59 =C2=A0 =C2=A00.00 =C2=A0 46.73 =C2=A0 =C2=A01.01 =C2= =A0 =C2=A00.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0= =C2=A00.00 =C2=A0 33.67
02:00:03 PM =C2=A0 =C2=A01=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 9.50=C2=A0 =C2=A0 =C2=A00.00 =C2=A0 61.50 =C2=A0 =C2=A00.50 = =C2=A0 =C2=A00.50 =C2=A0 =C2=A01.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 27.00
02:00:03 PM =C2=A0 =C2=A02=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 20.71 =C2=A0 =C2=A00.00 =C2=A0 44.44 =C2=A0 =C2=A01.01 = =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 32.83
02:00:03 PM =C2=A0 =C2=A03=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A014.00 =C2=A0 =C2=A00.00 =C2=A0 51.50 =C2=A0 =C2=A02.00 =C2= =A0 =C2=A01.00 =C2=A0 =C2=A01.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0= =C2=A00.00 =C2=A0 30.50
02:00:03 PM =C2=A0 =C2=A04=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 6.57=C2=A0 =C2=A0 =C2=A00.00 =C2=A0 52.53 =C2=A0 =C2=A00.51 = =C2=A0 =C2=A00.51 =C2=A0 =C2=A03.54 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 36.36
02:00:03 PM =C2=A0 =C2=A05=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 10.20 =C2=A0 =C2=A00.00 =C2=A0 49.49 =C2=A0 =C2=A01.02 = =C2=A0 =C2=A01.53 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 37.76
02:00:03 PM =C2=A0 =C2=A06=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 27.64 =C2=A0 =C2=A00.00 =C2=A0 41.21 =C2=A0 =C2=A00.50 = =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 29.65
02:00:03 PM =C2=A0 =C2=A07=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 9.05 =C2=A0 =C2=A00.00 =C2=A0 50.75 =C2=A0 =C2=A00.50 =C2= =A0 =C2=A01.01 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0= =C2=A00.00 =C2=A0 38.19
02:00:03 PM =C2=A0 =C2=A08=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 12.18 =C2=A0 =C2=A00.00 =C2=A0 49.75 =C2=A0 =C2=A00.51 =C2=A0= =C2=A00.51 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 = =C2=A00.00 =C2=A0 36.55
02:00:03 PM =C2=A0 =C2=A09=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 13.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A09.50 =C2=A0 =C2=A00.50 = =C2=A0 =C2=A01.50 =C2=A0 15.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 = =C2=A00.00 =C2=A0 60.00
02:00:03 PM =C2=A0 10=C2=A0 =C2=A0 =C2=A0 =C2=A0= =C2=A015.58 =C2=A0 =C2=A00.00 =C2=A0 46.23 =C2=A0 =C2=A00.00 =C2=A0 =C2=A0= 0.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.0= 0 =C2=A0 37.19
02:00:03 PM =C2=A0 11=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 2= 0.71 =C2=A0 =C2=A00.00 =C2=A0 10.10 =C2=A0 =C2=A00.00 =C2=A0 =C2=A01.01 =C2= =A0 14.14 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 54.0= 4
02:00:03 PM =C2=A0 12=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A021.00 =C2=A0 = =C2=A00.00 =C2=A0 37.00 =C2=A0 =C2=A00.50 =C2=A0 =C2=A01.00 =C2=A0 =C2=A01.= 00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 39.50
02= :00:03 PM =C2=A0 13=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A013.57 =C2=A0 =C2=A00.0= 0 =C2=A0 45.73 =C2=A0 =C2=A01.01 =C2=A0 =C2=A01.01 =C2=A0 =C2=A01.01 =C2=A0= =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 37.69
02:00:03 PM= =C2=A0 14 =C2=A0 18.18 =C2=A0 =C2=A00.00 =C2=A0 39.39 =C2=A0 =C2=A01.01 = =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 40.40
02:00:03 PM =C2=A0 15 =C2=A0 14.00 =C2=A0 = =C2=A00.00 =C2=A0 49.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A03.= 50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 32.00
02= :00:03 PM =C2=A0 16 =C2=A0 19.39 =C2=A0 =C2=A00.00 =C2=A0 39.80 =C2=A0 =C2= =A01.02 =C2=A0 =C2=A01.53 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.00 =C2=A0 =C2=A0= 0.00 =C2=A0 =C2=A00.00 =C2=A0 37.76
02:00:03 PM =C2=A0 17 =C2=A0 16.75 = =C2=A0 =C2=A00.00 =C2=A0 45.18 =C2=A0 =C2=A01.52 =C2=A0 =C2=A01.02 =C2=A0 = =C2=A02.54 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 32.= 99
02:00:03 PM =C2=A0 18 =C2=A0 12.63 =C2=A0 =C2=A00.00 =C2=A0 50.00 =C2= =A0 =C2=A00.00 =C2=A0 =C2=A01.01 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0= =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 36.36
02:00:03 PM =C2=A0 19 =C2=A0 = =C2=A05.56 =C2=A0 =C2=A00.00 =C2=A0 82.32 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.= 00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 = =C2=A0 12.12
02:00:03 PM =C2=A0 20 =C2=A0 15.08 =C2=A0 =C2=A00.00 =C2=A0= 48.24 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A03.52 =C2=A0 =C2=A00= .00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 32.16
02:00:03 PM =C2=A0 = 21 =C2=A0 17.68 =C2=A0 =C2=A00.00 =C2=A0 =C2=A09.09 =C2=A0 =C2=A00.51 =C2= =A0 =C2=A01.52 =C2=A0 13.64 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2= =A00.00 =C2=A0 57.58
02:00:03 PM =C2=A0 22 =C2=A0 13.13 =C2=A0 =C2=A00.0= 0 =C2=A0 43.94 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.51 =C2=A0= =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 41.41
02:00:03 PM= =C2=A0 23 =C2=A0 14.07 =C2=A0 =C2=A00.00 =C2=A0 42.71 =C2=A0 =C2=A00.50 = =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2= =A0 =C2=A00.00 =C2=A0 41.71
02:00:03 PM =C2=A0 24 =C2=A0 13.13 =C2=A0 = =C2=A00.00 =C2=A0 41.92 =C2=A0 =C2=A01.01 =C2=A0 =C2=A00.51 =C2=A0 =C2=A00.= 51 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 42.93
02= :00:03 PM =C2=A0 25 =C2=A0 16.58 =C2=A0 =C2=A00.00 =C2=A0 47.74 =C2=A0 =C2= =A00.50 =C2=A0 =C2=A01.01 =C2=A0 =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A0= 0.00 =C2=A0 =C2=A00.00 =C2=A0 33.67
02:00:03 PM =C2=A0 26 =C2=A0 16.58 = =C2=A0 =C2=A00.00 =C2=A0 46.73 =C2=A0 =C2=A00.50 =C2=A0 =C2=A01.01 =C2=A0 = =C2=A00.50 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 34.= 67
02:00:03 PM =C2=A0 27 =C2=A0 45.50 =C2=A0 =C2=A00.00 =C2=A0 54.50 =C2= =A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0= =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00
02:00:03 PM =C2=A0 28 = =C2=A0 =C2=A06.06 =C2=A0 =C2=A00.00 =C2=A0 32.32 =C2=A0 =C2=A00.00 =C2=A0 = =C2=A00.51 =C2=A0 13.13 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.= 00 =C2=A0 47.98
02:00:03 PM =C2=A0 29 =C2=A0 13.93 =C2=A0 =C2=A00.00 =C2= =A0 44.78 =C2=A0 =C2=A01.00 =C2=A0 =C2=A01.00 =C2=A0 =C2=A00.50 =C2=A0 =C2= =A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 38.81
02:00:03 PM =C2= =A0 30 =C2=A0 11.56 =C2=A0 =C2=A00.00 =C2=A0 57.79 =C2=A0 =C2=A00.00 =C2=A0= =C2=A00.50 =C2=A0 =C2=A01.01 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 = =C2=A00.00 =C2=A0 29.15
02:00:03 PM =C2=A0 31 =C2=A0 33.85 =C2=A0 =C2=A0= 0.00 =C2=A0 =C2=A09.23 =C2=A0 =C2=A00.51 =C2=A0 =C2=A01.54 =C2=A0 =C2=A00.5= 1 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 =C2=A00.00 =C2=A0 54.36
02:= 00:03 PM =C2=A0 32 =C2=A0 30.15 =C2=A0 =C2=A00.00 =C2=A0 41.71 =C2=A0 =C2= =A00.50 =C2=A0 =C2=A00.50 =C2=A0 =C2=A01.51 =C2=A0 =C2=A00.00 =C2=A0 =C2=A0= 0.00 =C2=A0 =C2=A00.00 =C2=A0 25.63

Thanks,

James=C2=A0

Frits Hooglan= d <frits.hoogland@gmail.com<= /a>> =E6=96=BC 2025=E5=B9=B46=E6=9C=8825=E6=97=A5=E9=80=B1=E4=B8=89 =E4= =B8=8B=E5=8D=8810:27=E5=AF=AB=E9=81=93=EF=BC=9A


> On 25 Jun 2025, at 07:59, Laurenz Albe <laurenz.albe@cybertec.at> wrote:<= br> >
> On Wed, 2025-06-25 at 11:15 +0800, James Pang wrote:
>> pgv14, RHEL8, xfs , we suddenly see tens of sessions waiting on &q= uot;DataFileRead" and
>> "extend", it last about 2 seconds(based on pg_stat_activ= ity query) , during the
>> waiting time, "%sys" cpu increased to 80% , but from &qu= ot;iostat" , no high iops and
>> io read/write latency increased either.
>
> Run "sar -P all 1" and see if "%iowait" is high. I would (strongly) advise against the use of iowait as an indicator. It is = a kernel approximation of time spent in IO from which cannot be use used in= any sensible way other than possibly you're doing IO.
First of all, iowait is not a kernel state, and therefore it's taken fr= om idle. This means that if there is no, or too little, idle time, iowait t= hat should be there is gone.
Second, the calculation to transfer idle time to iowait is done for synchro= nous IO calls only. Which currently is not a problem for postgres because i= t uses exactly that, but in the future it might.
Very roughly put, what the kernel does is keep a counter of tasks currently= in certain system IO calls, and then try to express that using iowait. The= time in IO wait can't be used calculate any IO facts.

In that sense, it puts it in the same area as the load figure: indicative, = but mostly useless because it doesn't give you any facts about what it = is expressing.
>
> Check if you have transparent hugepages enabled:
>
>=C2=A0 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.
Absolutely. Anything that is using signficant amounts of memory and is not = created to take advantage of transparent hugepages will probably experience= more downsides from THP than it helps.
>
>> many sessions were running same "DELETE FROM xxxx" in pa= rallel waiting on "extend"
>> and "DataFileRead", there are triggers in this table &qu= ot;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 connect= ion pool.
This is true if the limits of the IO device, or anything towards to IO devi= ce or devices are hit.
And in general, high "%sys", alias lots of time spent in kernel m= ode alias system time indicates lots of time spent in system calls, which i= s what the read and write calls in postgres are.
Therefore these figures suggest blocking for IO, for which Laurenz' adv= ise to lower the amount of concurrent sessions doing IO in general makes se= nse.
A more nuanced analysis: if IO requests get queued, these will wait in '= ;D' state in linux, which by definition is off cpu, and thus do not spe= nt cpu (system/kernel) time.

What sounds suspicious is that you indicate you indicate there is you see n= o signficant change in the amount of IO in iostat.

In order to understand this, you will have to first carefully find the actu= al IO physical IO devices that you are using for postgres IO.
In current linux this can be tricky, depending on how the hardware or virtu= al machine looks like, and how the disks are arranged in linux.
What you need to determine is which actual disk devices are used, and what = their limits are.
Limits for any disk are IOPS (operations per second) and MBPS (megabytes pe= r second -> bandwdith).

There is an additional thing to realize, which makes this really tricky: po= stgres for common IO uses buffered IO.
Buffered IO means any read or write will use the linux buffercache, and rea= d or writes can be served from the buffercache if possible.

So in your case, if you managed to make the database perform identical read= or write requests, this could result in a difference of amounts of read an= d write IOs served from the cache, which can make an enormous amounts of di= fference for how fast these requests are served. If somehow you managed to = make the operating system choose to use the physical IO path, you will see = significant amounts time spent on that, which will have IO related wait eve= nts.

Not a simple answer, but this is how it works.

So I would suggest checking the difference between the situation of when it= 's doing the same which is considered well performing versus badly perf= orming.


>
> Yours,
> Laurenz Albe
>
>

--00000000000057625a0638706103--