Re: BUG #19006: Assert(BufferIsPinned) in BufferGetBlockNumber() is triggered for forwarded buffer - Mailing list pgsql-bugs

From Xuneng Zhou
Subject Re: BUG #19006: Assert(BufferIsPinned) in BufferGetBlockNumber() is triggered for forwarded buffer
Date
Msg-id CABPTF7W6gBEh27hU0GVMM8g=GhEhD+nw_oQGS3Lae_h_n03ejA@mail.gmail.com
Whole thread Raw
In response to Re: BUG #19006: Assert(BufferIsPinned) in BufferGetBlockNumber() is triggered for forwarded buffer  (Thomas Munro <thomas.munro@gmail.com>)
List pgsql-bugs
Hi,

These are the results of a cold-cache(not strictly) bench:

Cold-cache readstream microbench (20M rows, shared_buffers=128MB). Use
a somewhat unrealistic setting to amplify the potential impact.

Patch: Make StartReadBuffers() carry npinned in/out

Workload: single-session COUNT(*) on large_table
• Seq scan: SET enable_{indexscan,indexonlyscan,bitmapscan}=off;
SELECT count(*) FROM large_table;
• Bitmap scan: 16 wide tiles over id (contiguous ranges)

Machine: AMD, 16G mem,  8 cores

Config (per run):
shared_buffers=128MB, io_combine_limit=8, track_io_timing=on, jit=off,
effective_io_concurrency=32. Table is clustered by id. N≈20M rows
(int, text(100)).


1) Query runtimes (EXPLAIN ANALYZE)

Sequential scan — 5 reps each
• BASE: mean 2937 ms, median 2963 ms, p95 3254 ms
(per-run: 2719, 2692, 3254, 3061, 2963 ms)
• PATCHED: mean 2692 ms, median 2697 ms, p95 2770 ms
(per-run: 2720, 2770, 2697, 2611, 2662 ms)
PATCHED faster: mean –8.4%, p95 –14.8% vs BASE.

Bitmap scan — 5 reps each
• BASE: mean 86.6 ms, median 89.6 ms, p95 94.1 ms
• PATCHED: mean 88.9 ms, median 88.2 ms, p95 98.7 ms


2) perf stat (60s pgbench drive of the same SQL)

Sequential scan

metric BASE PATCHED
task-clock (ms) 10,862.53 8,896.26 –18.1%
cycles 16.27e9 13.05e9 –19.8%
instructions 39.78e9 33.34e9 –16.2%
IPC 2.44 2.56 +4.5%
branches 8.62e9 7.33e9 –14.9%
branch-misses 32.74e6 24.47e6 –25.2%

Bitmap scan

metric BASE PATCHED
task-clock (ms) 8,528.28 8,542.37 +0.2%
cycles 16.84e9 16.80e9 –0.3%
instructions 51.16e9 51.43e9 +0.5%
IPC 3.04 3.06 +0.8%
branch-misses 11.86e6 11.05e6 –6.9%


3) bpftrace micro-latency on the readstream path

(averages in µs; also showing call counts and total time seen in probes)

Sequential scan (60s)
function BASE avg (µs) PATCHED avg (µs) BASE calls PATCHED calls BASE
sum (s) PATCHED sum (s)
StartReadBuffers 8 8 712,927 727,083 6.14 6.23
read_stream_start_pending_read 3 3 2,042,992 2,083,866 7.52 7.61
read_stream_next_buffer 6 6 5,528,071 5,636,554 35.40 35.36

Bitmap scan (60s)
function BASE avg (µs) PATCHED avg (µs) BASE calls PATCHED calls BASE
sum (s) PATCHED sum (s)
StartReadBuffers 4 4 2,697,243 2,677,563 11.28 11.26
read_stream_start_pending_read 5 5 2,696,591 2,676,940 14.72 14.60
read_stream_next_buffer 10 10 2,697,105 2,677,477 28.74 28.67

Indistinguishable between BASE and PATCHED

Best,
Xuneng

Attachment

pgsql-bugs by date:

Previous
From: Richard Guo
Date:
Subject: Re: BUG #19007: Planner fails to choose partial index with spurious 'not null'
Next
From: Masahiko Sawada
Date:
Subject: Re: TRAP: failed Assert("outerPlan != NULL") in postgres_fdw.c