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 1uUR6K-003FRd-F2 for pgsql-performance@arkaria.postgresql.org; Wed, 25 Jun 2025 14:27:48 +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 1uUR6I-0045e2-8X for pgsql-performance@arkaria.postgresql.org; Wed, 25 Jun 2025 14:27:46 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1uUR6H-0045dh-QD for pgsql-performance@lists.postgresql.org; Wed, 25 Jun 2025 14:27:46 +0000 Received: from mail-ej1-x634.google.com ([2a00:1450:4864:20::634]) by makus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.96) (envelope-from ) id 1uUR6G-003w68-2K for pgsql-performance@lists.postgresql.org; Wed, 25 Jun 2025 14:27:45 +0000 Received: by mail-ej1-x634.google.com with SMTP id a640c23a62f3a-ad8a6c202ffso1225954166b.3 for ; Wed, 25 Jun 2025 07:27:44 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1750861661; x=1751466461; darn=lists.postgresql.org; h=to:references:message-id:content-transfer-encoding:cc:date :in-reply-to:from:subject:mime-version:from:to:cc:subject:date :message-id:reply-to; bh=MZiHlq7GToHeCMd08gxz8eI+0dn8Ogzu3QvCrcYlbLI=; b=N6j0tPz5SywVt9JXCK6llS7M/y7U2ILUz4H4wzXBkDr9yJsuHOCNfJT5KO6aw5+t9C pTBaO+5BdFheGWfnhQgtAV1kG5z6OjV+VbbIL+Q7cTyZ7oFkFDiaZsMxSDXMsIGz60bR Z4aLQuKZDjzxk2hNO5WUfZQGOlUkYtOFXoxLRkEngqmJ/Qrqq5KywPBCqx0aOiGYoq7L XmZ+RTBC4D1K49bd+hoDzQ7ctmK4gzvL7JDZShKeloc4WADKX4BKLm7JsXH8KleuLQP0 tEhh/PNJ5veK8PE8hRtSpD0jb/5x6VqKKRSFCu/ux88JSAePZOCEd9NpUPIUkW5o6GoU 66gw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1750861661; x=1751466461; h=to:references:message-id:content-transfer-encoding:cc:date :in-reply-to:from:subject:mime-version:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=MZiHlq7GToHeCMd08gxz8eI+0dn8Ogzu3QvCrcYlbLI=; b=reazUIs3YPEL6TqDLxSmeq3p47YCG9ays5txEdGIiEPGrhZw7jgUjBH5pyJkjoEwLo aJnMYBPxSvtJt3Bl9F9diKONKrjTM5Fb8f3ni+k8Jx3nW55dtKcCXLfTJLzub8+wTz+z Bd17HaOmOwBh4Kwo7kDJB8FPrZMIT2E0WxxGFmxE13Y3/Olzfgs3oEi7aanL37wsHpj0 1LfpYcIVF6M6EuGnJ/DaIkqMQBkYJBFMIRFkn7VUnpqmTPjqM02+PTodGZoITgKppccn x0joJOBO6DC5aivrslJsgV4XzW8rFRtWNO671iZsOAptfcIVcmilSNOKbsyiE66X1CxG G9kg== X-Gm-Message-State: AOJu0YyQ70l7KULKZ6SQ3jtLZ1MLiwBDIe9KGpAe0TbycjArZuN7nSva KrKJqLVzIKr1L3LAbdaoRyuCwB+uAqn72eAWOhsPYAtoqh5U/RjaNH42 X-Gm-Gg: ASbGncuUbjqxsHIPVOJGVFw+fx1A+sTgHj1B/0rz2fNqOFzuA4RMHF3jZa9pl129PJA rOjtLjs0GLZwFJYNkcsJhpEiqbswG3gIz2VzIYDDalblJEQqxmG7HIJJkcNN+3BPNfadMZyXmS/ ZcFXSBklOUrECwbtY4xNcrkfxyfQv7BmfxUNdw0IG20lQxO2C4B4K9TQulkuOZlQmzwuqCxMty9 30cPp24Dg5VvLCCLFnVPHuwO2N4EMxFZ7rRsIpTXfqE3pmLjQIuPu86Eal9Ex75efNAeiJ2Z2Ov bM8hBjlC5Ma6NTttvJ9BHsKKrtlojQte6kZwwiiOmf4k/fyFcbGKIxBweiKICh11azHjYqlVDSd Oxflm4wLkl0M1+YNOOGKM513QA5RSzp35TRj5rlWXtOqE1Wk9dbeXWTP9zYR1XS2tlqv6fyb63R l4HVfNBJh48H64tQkJhEXBXA== X-Google-Smtp-Source: AGHT+IHnEbUiuT6sMxpnxRBNRPG09HPOSDWcqLowEae2iyVp8+vIT+7Ho0qplhM1cbvcLC5AKeMjRA== X-Received: by 2002:a17:907:9805:b0:ad8:e477:970c with SMTP id a640c23a62f3a-ae0bebec056mr336210166b.23.1750861660907; Wed, 25 Jun 2025 07:27:40 -0700 (PDT) Received: from smtpclient.apple (2001-1c04-0681-7700-c8e5-498e-3967-d25c.cable.dynamic.v6.ziggo.nl. [2001:1c04:681:7700:c8e5:498e:3967:d25c]) by smtp.gmail.com with ESMTPSA id a640c23a62f3a-ae0a1f704ecsm367993066b.97.2025.06.25.07.27.40 (version=TLS1_2 cipher=ECDHE-ECDSA-AES128-GCM-SHA256 bits=128/128); Wed, 25 Jun 2025 07:27:40 -0700 (PDT) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3826.600.51.1.1\)) Subject: Re: many sessions waiting DataFileRead and extend From: Frits Hoogland In-Reply-To: <66879d8bd44148f2ef1dcde1eff056e6c671306e.camel@cybertec.at> Date: Wed, 25 Jun 2025 16:27:29 +0200 Cc: pgsql-performance@lists.postgresql.org Content-Transfer-Encoding: quoted-printable Message-Id: References: <66879d8bd44148f2ef1dcde1eff056e6c671306e.camel@cybertec.at> To: Laurenz Albe , James Pang X-Mailer: Apple Mail (2.3826.600.51.1.1) List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk > On 25 Jun 2025, at 07:59, Laurenz Albe = wrote: >=20 > 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. >=20 > 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 = from idle. This means that if there is no, or too little, idle time, = iowait that 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. >=20 > Check if you have transparent hugepages enabled: >=20 > cat /sys/kernel/mm/transparent_hugepage/enabled >=20 > If they are enabled, disable them and see if it makes a difference. >=20 > 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. >=20 >> 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.=20 >=20 > 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 = alias system time indicates lots of time spent in system calls, which is = what the read and write calls in postgres are. Therefore these figures suggest blocking for IO, for which Laurenz' = advise to lower the amount of concurrent sessions doing IO in general = makes sense. 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 = what their limits are.=20 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 = have 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. >=20 > Yours, > Laurenz Albe >=20 >=20