Re: hash_search_with_hash_value is high in "perf top" on a replica
Dmitry Koterov <dmitry.koterov@gmail.com>
From: Dmitry Koterov <dmitry.koterov@gmail.com>
To: Andres Freund <andres@anarazel.de>
Cc: "pgsql-hackers@postgresql.org" <pgsql-hackers@postgresql.org>
Date: 2025-02-01T11:46:33Z
Lists: pgsql-hackers
Commits
Same data as JSON:
GET /api/v1/messages/:b64id/commits
the thread's linked commits as JSON, with link sources.
API reference →
-
doc: Fix pg_buffercache_evict() title
- 59d6c0395619 18.0 cited
-
Fix several hash functions that were taking chintzy shortcuts instead of
- 1f559b7d3aa4 8.3.0 cited
> It'd be interesting to see what the paths towards hash_search_with_hash_value are. One of the popular paths is on the screenshot. They are all more or less the same when recovery_prefetch=on (and when it's off, the replica behaves worse, more replication lag). That COPY command - it's the initial sync stage after CREATE SUBSCRIPTION basically (with streaming=off, default). Large table (hundreds of gigabytes). [image: image.png] It's also interesting, how gradually the disk writes and IOPS grow on the replica during that large table COPY (dark blue line on the screenshot below). And in the end, when "EXPLAIN SELECT 1 FROM mytable" showed ~100% of the rows (i.e. almost everything is copied), it got stuck or ~5 minutes with a spike on both reads and writes (the dark blue charts are all about the replica). I.e. that COPY load, it is not spread uniformly: in the end, it causes more load (I also saw that on the "startup recovering" process CPU metrics). [image: CleanShot 2025-02-01 at 03.42.16@2x.png] On Fri, Jan 31, 2025 at 6:43 AM Andres Freund <andres@anarazel.de> wrote: > Hi, > > On 2025-01-31 03:30:35 -0800, Dmitry Koterov wrote: > > Debugging some replication lag on a replica when the master node > > experiences heavy writes. > > > > PG "startup recovering" eats up a lot of CPU (like 65 %user and 30 %sys), > > which is a little surprising (what is it doing with all those CPU cycles? > > it looked like WAL replay should be more IO bound than CPU bound?). > > > > Running "perf top -p <pid>", it shows this: > > > > Samples: 1M of event 'cycles:P', 4000 Hz, Event count (approx.): > > 18178814660 lost: 0/0 drop: 0/0 > > Overhead Shared Object Symbol > > 16.63% postgres [.] hash_search_with_hash_value > > It'd be interesting to see what the paths towards > hash_search_with_hash_value > are. > > You said it's a COPY workloads, which surprises me a bit, because that > should > normally be a bit less sensitive to it. Perhaps you have triggers or such > that > prevent use of the multi-insert path? > > > > > 5.38% postgres [.] __aarch64_ldset4_sync > > 4.42% postgres [.] __aarch64_cas4_acq_rel > > These two suggest that it might be worth compiling with an -march CPU that > provides native atomics (everything above armv8.1-a, I think). > > > > Maybe it's a red herring though, but it looks pretty suspicious. > > It's unfortunately not too surprising - our buffer mapping table is a > pretty > big bottleneck. Both because a hash table is just not a good fit for the > buffer mapping table due to the lack of locality and because dynahash is > really poor hash table implementation. > > > > Greetings, > > Andres Freund >