pg.ddx.io pgsql-bugs@postgresql.org mailing list archive help / color / mirror / Atom feed From: Marco Boeringa <marco@boeringa.demon.nl>
To: Andres Freund <andres@anarazel.de>
Cc: pgsql-bugs@lists.postgresql.org, Thom Brown <thom@linux.com>
Subject: Re: Potential "AIO / io workers" inter-worker locking issue in PG18?
Date: Wed, 8 Oct 2025 12:04:20 +0200
Message-ID: <4cc396f3-6508-4e25-a6da-efdd4f939946@boeringa.demon.nl> (raw )
In-Reply-To: <6ro55q35wiahf7mpsbnhyneatiqkz4qrjcfgtg6zo2bvtjwrxy@5fzxrbymhop3 >
References: <cc003455-1773-40b0-a488-281459942542@boeringa.demon.nl >
<c31b47d9-c5e4-4c2d-b1dc-22b07e86019e@boeringa.demon.nl >
<6ro55q35wiahf7mpsbnhyneatiqkz4qrjcfgtg6zo2bvtjwrxy@5fzxrbymhop3 >
> Could you show perf report --no-children? That would show us which individual
> functions, rather than call-stacks, take the longest.
Andres, I now captured a few more 'perf' sessions.
Run 1 is the original run I already showed you. For comparison, runs 2-4
are from a different backend captured during a new geoprocessing run,
but all refering to same PID. Run 5 is also from the same geoprocessing
run, but another backend PID, so another python thread launched from my
code.
Not much difference between all of these, especially the ordinary "perf
report", the "perf report --no children" show a little more
variation. "perf report --no children" runs are grouped together at the
bottom of the email.
Despite the minor differences, maybe seeing different captures of perf
is still of some use.
Marco
*** sudo perf -p <PID of one stuck postgres backend> -g -d 10 ***
*** sudo perf report -g ***
RUN 1:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10008250000
Children Self Command Shared Object Symbol
+ 100,00% 0,00% postgres postgres [.] _start
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_main@@GLIBC_2.34
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_call_main
+ 100,00% 0,00% postgres postgres [.] main
+ 100,00% 0,00% postgres postgres [.] PostmasterMain
+ 100,00% 0,00% postgres postgres [.] ServerLoop.isra.0
+ 100,00% 0,00% postgres postgres [.]
postmaster_child_launch
+ 100,00% 0,00% postgres postgres [.] 0x00005f3570fb9dbf
+ 100,00% 0,00% postgres postgres [.] PostgresMain
+ 100,00% 0,00% postgres postgres [.] exec_simple_query
+ 100,00% 0,63% postgres postgres [.] ExecNestLoop
+ 100,00% 0,00% postgres postgres [.] PortalRun
+ 100,00% 0,00% postgres postgres [.] PortalRunMulti
+ 100,00% 0,00% postgres postgres [.] ProcessQuery
+ 100,00% 0,00% postgres postgres [.] standard_ExecutorRun
+ 100,00% 0,00% postgres postgres [.] ExecModifyTable
+ 94,63% 1,47% postgres postgres [.] ExecScan
+ 78,76% 1,49% postgres postgres [.] IndexNext
+ 66,89% 1,96% postgres postgres [.] index_fetch_heap
+ 64,35% 3,61% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 21,92% 0,40% postgres postgres [.] ReadBufferExtended
+ 20,36% 1,19% postgres postgres [.] StartReadBuffer
+ 16,23% 5,79% postgres postgres [.] ExecInterpExpr
+ 15,00% 10,70% postgres postgres [.]
heap_hot_search_buffer
+ 12,81% 12,81% postgres postgres [.] LWLockAttemptLock
+ 10,31% 2,36% postgres postgres [.] index_getnext_tid
+ 9,69% 0,48% postgres postgres [.] slot_getsomeattrs_int
+ 9,27% 9,27% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 8,45% 1,85% postgres postgres [.] LWLockRelease
+ 7,91% 1,08% postgres postgres [.] btgettuple
+ 6,89% 1,12% postgres postgres [.] _bt_next
+ 6,77% 6,77% postgres postgres [.] LWLockReleaseInternal
+ 5,89% 5,89% postgres postgres [.]
hash_search_with_hash_value
+ 5,78% 0,10% postgres postgres [.] _bt_readnextpage
+ 4,48% 4,14% postgres postgres [.] PinBuffer
+ 4,41% 1,90% postgres postgres [.] _bt_readpage
+ 4,09% 3,00% postgres postgres [.] ReleaseAndReadBuffer
+ 2,99% 2,38% postgres postgres [.]
HeapTupleSatisfiesVisibility
+ 2,58% 0,82% postgres postgres [.]
ExecStoreBufferHeapTuple
+ 2,43% 2,43% postgres postgres [.] LWLockAcquire
+ 2,28% 1,47% postgres postgres [.] _bt_checkkeys
+ 1,74% 1,74% postgres postgres [.] heap_page_prune_opt
+ 1,67% 1,10% postgres postgres [.]
UnpinBufferNoOwner.lto_priv.0
+ 1,47% 1,47% postgres postgres [.] XidInMVCCSnapshot
+ 1,18% 1,18% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
+ 1,09% 1,09% postgres postgres [.] MemoryContextReset
RUN 2:
amples: 40K of event 'task-clock:ppp', Event count (approx.): 10020750000
Children Self Command Shared Object Symbol
+ 100,00% 0,00% postgres postgres [.] _start
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_main@@GLIBC_2.34
+ 100,00% 0,00% postgres libc.so.6 [.] __libc_start_call_main
+ 100,00% 0,00% postgres postgres [.] main
+ 100,00% 0,00% postgres postgres [.] PostmasterMain
+ 100,00% 0,00% postgres postgres [.] ServerLoop.isra.0
+ 100,00% 0,00% postgres postgres [.]
postmaster_child_launch
+ 100,00% 0,00% postgres postgres [.] 0x00005f3570fb9dbf
+ 100,00% 0,00% postgres postgres [.] PostgresMain
+ 100,00% 0,00% postgres postgres [.] exec_simple_query
+ 100,00% 0,34% postgres postgres [.] ExecNestLoop
+ 100,00% 0,00% postgres postgres [.] PortalRun
+ 100,00% 0,00% postgres postgres [.] PortalRunMulti
+ 100,00% 0,00% postgres postgres [.] ProcessQuery
+ 100,00% 0,00% postgres postgres [.] standard_ExecutorRun
+ 100,00% 0,00% postgres postgres [.] ExecModifyTable
+ 97,34% 1,13% postgres postgres [.] ExecScan
+ 88,55% 0,73% postgres postgres [.] IndexNext
+ 82,41% 1,05% postgres postgres [.] index_fetch_heap
+ 81,10% 1,78% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 25,70% 25,70% postgres postgres [.] LWLockAttemptLock
+ 16,67% 0,86% postgres postgres [.] LWLockRelease
+ 15,91% 15,91% postgres postgres [.] LWLockReleaseInternal
+ 15,27% 0,22% postgres postgres [.] ReadBufferExtended
+ 14,41% 1,73% postgres postgres [.] StartReadBuffer
+ 14,11% 13,01% postgres postgres [.] ReleaseAndReadBuffer
+ 8,60% 3,08% postgres postgres [.] ExecInterpExpr
+ 6,27% 3,90% postgres postgres [.] heap_hot_search_buffer
+ 5,36% 1,11% postgres postgres [.] index_getnext_tid
+ 5,20% 0,20% postgres postgres [.] slot_getsomeattrs_int
+ 5,05% 5,05% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 4,74% 4,59% postgres postgres [.] PinBuffer
+ 4,21% 0,54% postgres postgres [.] btgettuple
+ 3,75% 0,72% postgres postgres [.] _bt_next
+ 3,27% 3,27% postgres postgres [.]
hash_search_with_hash_value
+ 3,04% 0,03% postgres postgres [.] _bt_readnextpage
+ 3,00% 0,44% postgres postgres [.]
ExecStoreBufferHeapTuple
+ 2,43% 2,16% postgres postgres [.]
UnpinBufferNoOwner.lto_priv.0
+ 2,24% 1,01% postgres postgres [.] _bt_readpage
+ 1,62% 1,25% postgres postgres [.]
HeapTupleSatisfiesVisibility
+ 1,51% 1,51% postgres postgres [.] LWLockAcquire
+ 1,18% 1,18% postgres postgres [.] heap_page_prune_opt
+ 1,07% 0,72% postgres postgres [.] _bt_checkkeys
+ 0,85% 0,85% postgres postgres [.] XidInMVCCSnapshot
+ 0,82% 0,74% postgres postgres [.] ReleaseBuffer
+ 0,56% 0,56% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
0,41% 0,41% postgres postgres [.]
_bt_check_compare.lto_priv.0
RUN 3:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10010750000
Children Self Command Shared Object Symbol
+ 100,00% 0,00% postgres postgres [.] _start
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_main@@GLIBC_2.34
+ 100,00% 0,00% postgres libc.so.6 [.] __libc_start_call_main
+ 100,00% 0,00% postgres postgres [.] main
+ 100,00% 0,00% postgres postgres [.] PostmasterMain
+ 100,00% 0,00% postgres postgres [.] ServerLoop.isra.0
+ 100,00% 0,00% postgres postgres [.]
postmaster_child_launch
+ 100,00% 0,00% postgres postgres [.] 0x00005f3570fb9dbf
+ 100,00% 0,00% postgres postgres [.] PostgresMain
+ 100,00% 0,00% postgres postgres [.] exec_simple_query
+ 100,00% 0,34% postgres postgres [.] ExecNestLoop
+ 100,00% 0,00% postgres postgres [.] PortalRun
+ 100,00% 0,00% postgres postgres [.] PortalRunMulti
+ 100,00% 0,00% postgres postgres [.] ProcessQuery
+ 100,00% 0,00% postgres postgres [.] standard_ExecutorRun
+ 100,00% 0,00% postgres postgres [.] ExecModifyTable
+ 97,43% 1,10% postgres postgres [.] ExecScan
+ 88,96% 0,79% postgres postgres [.] IndexNext
+ 82,68% 1,03% postgres postgres [.] index_fetch_heap
+ 81,42% 1,89% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 25,54% 25,54% postgres postgres [.] LWLockAttemptLock
+ 17,38% 1,01% postgres postgres [.] LWLockRelease
+ 16,44% 16,44% postgres postgres [.] LWLockReleaseInternal
+ 15,39% 0,25% postgres postgres [.] ReadBufferExtended
+ 14,49% 1,69% postgres postgres [.] StartReadBuffer
+ 13,77% 12,72% postgres postgres [.] ReleaseAndReadBuffer
+ 8,28% 2,95% postgres postgres [.] ExecInterpExpr
+ 6,05% 3,75% postgres postgres [.] heap_hot_search_buffer
+ 5,39% 1,09% postgres postgres [.] index_getnext_tid
+ 5,05% 0,21% postgres postgres [.] slot_getsomeattrs_int
+ 4,88% 4,88% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 4,87% 4,69% postgres postgres [.] PinBuffer
+ 4,29% 0,61% postgres postgres [.] btgettuple
+ 3,74% 0,74% postgres postgres [.] _bt_next
+ 3,47% 3,47% postgres postgres [.]
hash_search_with_hash_value
+ 3,00% 0,05% postgres postgres [.] _bt_readnextpage
+ 2,99% 0,50% postgres postgres [.]
ExecStoreBufferHeapTuple
+ 2,27% 2,01% postgres postgres [.]
UnpinBufferNoOwner.lto_priv.0
+ 2,19% 0,99% postgres postgres [.] _bt_readpage
+ 1,52% 1,14% postgres postgres [.]
HeapTupleSatisfiesVisibility
+ 1,50% 1,50% postgres postgres [.] LWLockAcquire
+ 1,12% 1,12% postgres postgres [.] heap_page_prune_opt
+ 1,06% 0,72% postgres postgres [.] _bt_checkkeys
+ 0,87% 0,87% postgres postgres [.] XidInMVCCSnapshot
+ 0,87% 0,76% postgres postgres [.] ReleaseBuffer
+ 0,59% 0,59% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
0,41% 0,41% postgres postgres [.]
_bt_check_compare.lto_priv.0
RUN 4:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10010500000
Children Self Command Shared Object Symbol
+ 100,00% 0,00% postgres postgres [.] _start
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_main@@GLIBC_2.34
+ 100,00% 0,00% postgres libc.so.6 [.] __libc_start_call_main
+ 100,00% 0,00% postgres postgres [.] main
+ 100,00% 0,00% postgres postgres [.] PostmasterMain
+ 100,00% 0,00% postgres postgres [.] ServerLoop.isra.0
+ 100,00% 0,00% postgres postgres [.]
postmaster_child_launch
+ 100,00% 0,00% postgres postgres [.] 0x00005f3570fb9dbf
+ 100,00% 0,00% postgres postgres [.] PostgresMain
+ 100,00% 0,00% postgres postgres [.] exec_simple_query
+ 100,00% 0,32% postgres postgres [.] ExecNestLoop
+ 100,00% 0,00% postgres postgres [.] PortalRun
+ 100,00% 0,00% postgres postgres [.] PortalRunMulti
+ 100,00% 0,00% postgres postgres [.] ProcessQuery
+ 100,00% 0,00% postgres postgres [.] standard_ExecutorRun
+ 100,00% 0,00% postgres postgres [.] ExecModifyTable
+ 97,30% 1,16% postgres postgres [.] ExecScan
+ 88,81% 0,73% postgres postgres [.] IndexNext
+ 82,49% 0,99% postgres postgres [.] index_fetch_heap
+ 81,18% 2,01% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 25,65% 25,65% postgres postgres [.] LWLockAttemptLock
+ 16,65% 1,01% postgres postgres [.] LWLockRelease
+ 15,79% 0,26% postgres postgres [.] ReadBufferExtended
+ 15,76% 15,76% postgres postgres [.] LWLockReleaseInternal
+ 15,00% 1,65% postgres postgres [.] StartReadBuffer
+ 13,88% 12,75% postgres postgres [.] ReleaseAndReadBuffer
+ 8,41% 3,03% postgres postgres [.] ExecInterpExpr
+ 6,13% 3,82% postgres postgres [.] heap_hot_search_buffer
+ 5,46% 1,04% postgres postgres [.] index_getnext_tid
+ 5,02% 0,23% postgres postgres [.] slot_getsomeattrs_int
+ 4,94% 4,78% postgres postgres [.] PinBuffer
+ 4,83% 4,83% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 4,40% 0,58% postgres postgres [.] btgettuple
+ 3,87% 0,79% postgres postgres [.] _bt_next
+ 3,76% 3,76% postgres postgres [.]
hash_search_with_hash_value
+ 3,09% 0,05% postgres postgres [.] _bt_readnextpage
+ 2,88% 0,46% postgres postgres [.]
ExecStoreBufferHeapTuple
+ 2,44% 2,11% postgres postgres [.]
UnpinBufferNoOwner.lto_priv.0
+ 2,26% 1,01% postgres postgres [.] _bt_readpage
+ 1,53% 1,16% postgres postgres [.]
HeapTupleSatisfiesVisibility
+ 1,45% 1,45% postgres postgres [.] LWLockAcquire
+ 1,17% 1,17% postgres postgres [.] heap_page_prune_opt
+ 1,09% 0,72% postgres postgres [.] _bt_checkkeys
+ 0,82% 0,82% postgres postgres [.] XidInMVCCSnapshot
+ 0,80% 0,71% postgres postgres [.] ReleaseBuffer
+ 0,63% 0,63% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
0,44% 0,44% postgres postgres [.]
_bt_check_compare.lto_priv.0
RUN 5:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10003250000
Children Self Command Shared Object Symbol
+ 100,00% 0,00% postgres postgres [.] _start
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_main@@GLIBC_2.34
+ 100,00% 0,00% postgres libc.so.6 [.]
__libc_start_call_main
+ 100,00% 0,00% postgres postgres [.] main
+ 100,00% 0,00% postgres postgres [.] PostmasterMain
+ 100,00% 0,00% postgres postgres [.] ServerLoop.isra.0
+ 100,00% 0,00% postgres postgres [.]
postmaster_child_launch
+ 100,00% 0,00% postgres postgres [.] 0x00005f3570fb9dbf
+ 100,00% 0,00% postgres postgres [.] PostgresMain
+ 100,00% 0,00% postgres postgres [.] exec_simple_query
+ 100,00% 0,00% postgres postgres [.] PortalRun
+ 100,00% 0,00% postgres postgres [.] PortalRunMulti
+ 100,00% 0,00% postgres postgres [.] ProcessQuery
+ 100,00% 0,00% postgres postgres [.] standard_ExecutorRun
+ 100,00% 0,00% postgres postgres [.] ExecModifyTable
+ 100,00% 0,35% postgres postgres [.] ExecNestLoop
+ 97,20% 0,90% postgres postgres [.] ExecScan
+ 89,12% 0,85% postgres postgres [.] IndexNext
+ 82,86% 1,00% postgres postgres [.] index_fetch_heap
+ 81,60% 1,92% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 26,49% 26,48% postgres postgres [.] LWLockAttemptLock
+ 16,53% 0,81% postgres postgres [.] LWLockRelease
+ 15,81% 15,81% postgres postgres [.] LWLockReleaseInternal
+ 15,57% 0,22% postgres postgres [.] ReadBufferExtended
+ 14,68% 1,88% postgres postgres [.] StartReadBuffer
+ 14,10% 12,88% postgres postgres [.] ReleaseAndReadBuffer
+ 8,27% 2,97% postgres postgres [.] ExecInterpExpr
+ 5,87% 3,67% postgres postgres [.]
heap_hot_search_buffer
+ 5,38% 0,92% postgres postgres [.] index_getnext_tid
+ 5,01% 0,21% postgres postgres [.] slot_getsomeattrs_int
+ 4,85% 4,84% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 4,81% 4,64% postgres postgres [.] PinBuffer
+ 4,41% 0,53% postgres postgres [.] btgettuple
+ 3,96% 0,92% postgres postgres [.] _bt_next
+ 3,47% 3,47% postgres postgres [.]
hash_search_with_hash_value
+ 3,03% 0,03% postgres postgres [.] _bt_readnextpage
+ 2,77% 0,40% postgres postgres [.]
ExecStoreBufferHeapTuple
+ 2,41% 2,11% postgres postgres [.]
UnpinBufferNoOwner.lto_priv.0
+ 2,28% 0,97% postgres postgres [.] _bt_readpage
+ 1,46% 1,09% postgres postgres [.]
HeapTupleSatisfiesVisibility
+ 1,41% 1,41% postgres postgres [.] LWLockAcquire
+ 1,14% 0,71% postgres postgres [.] _bt_checkkeys
+ 1,12% 1,12% postgres postgres [.] heap_page_prune_opt
+ 0,83% 0,83% postgres postgres [.] XidInMVCCSnapshot
+ 0,81% 0,69% postgres postgres [.] ReleaseBuffer
+ 0,57% 0,57% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
0,48% 0,48% postgres postgres [.]
_bt_check_compare.lto_priv.0
*** sudo perf -p <PID of one stuck postgres backend> -g -d 10 ***
*** sudo perf report --no-children ***
RUN 1 - NO CHILDREN:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10008250000
Overhead Command Shared Object Symbol
+ 12,81% postgres postgres [.] LWLockAttemptLock
+ 10,70% postgres postgres [.] heap_hot_search_buffer
+ 9,27% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 6,77% postgres postgres [.] LWLockReleaseInternal
+ 5,89% postgres postgres [.] hash_search_with_hash_value
+ 5,79% postgres postgres [.] ExecInterpExpr
+ 4,14% postgres postgres [.] PinBuffer
+ 3,61% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 3,00% postgres postgres [.] ReleaseAndReadBuffer
+ 2,43% postgres postgres [.] LWLockAcquire
+ 2,38% postgres postgres [.] HeapTupleSatisfiesVisibility
+ 2,36% postgres postgres [.] index_getnext_tid
+ 1,96% postgres postgres [.] index_fetch_heap
+ 1,90% postgres postgres [.] _bt_readpage
+ 1,85% postgres postgres [.] LWLockRelease
+ 1,74% postgres postgres [.] heap_page_prune_opt
+ 1,49% postgres postgres [.] IndexNext
+ 1,47% postgres postgres [.] _bt_checkkeys
+ 1,47% postgres postgres [.] ExecScan
+ 1,47% postgres postgres [.] XidInMVCCSnapshot
+ 1,19% postgres postgres [.] StartReadBuffer
+ 1,18% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
+ 1,12% postgres postgres [.] _bt_next
+ 1,10% postgres postgres [.] UnpinBufferNoOwner.lto_priv.0
+ 1,09% postgres postgres [.] MemoryContextReset
+ 1,08% postgres postgres [.] btgettuple
+ 0,91% postgres postgres [.] _bt_check_compare.lto_priv.0
+ 0,82% postgres postgres [.] ExecEvalSysVar
+ 0,82% postgres postgres [.] ExecStoreBufferHeapTuple
+ 0,71% postgres postgres [.] hash_bytes
+ 0,65% postgres postgres [.] tts_virtual_clear.lto_priv.0
+ 0,63% postgres postgres [.] GlobalVisTestFor
+ 0,63% postgres postgres [.] ExecNestLoop
+ 0,55% postgres postgres [.] HeapTupleIsSurelyDead
+ 0,52% postgres postgres [.] ResourceOwnerForget
0,48% postgres postgres [.] slot_getsomeattrs_int
0,42% postgres postgres [.] PredicateLockTID
0,40% postgres postgres [.] ReadBufferExtended
0,37% postgres postgres [.] _bt_saveitem
0,31% postgres postgres [.] ExecIndexScan
0,30% postgres libc.so.6 [.] __memcmp_sse2
0,28% postgres postgres [.] _bt_setuppostingitems
0,26% postgres postgres [.] ReleaseBuffer
0,23% postgres postgres [.] ResourceOwnerEnlarge
0,23% postgres postgres [.]
HeapCheckForSerializableConflictOut
0,22% postgres postgres [.] IncrBufferRefCount
0,18% postgres postgres [.] pgstat_count_io_op
RUN 2 - NO CHILDREN:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10020750000
Overhead Command Shared Object Symbol
+ 25,70% postgres postgres [.] LWLockAttemptLock
+ 15,91% postgres postgres [.] LWLockReleaseInternal
+ 13,01% postgres postgres [.] ReleaseAndReadBuffer
+ 5,05% postgres postgres [.] tts_heap_getsomeattrs.lto_priv.0
+ 4,59% postgres postgres [.] PinBuffer
+ 3,90% postgres postgres [.] heap_hot_search_buffer
+ 3,27% postgres postgres [.] hash_search_with_hash_value
+ 3,08% postgres postgres [.] ExecInterpExpr
+ 2,16% postgres postgres [.] UnpinBufferNoOwner.lto_priv.0
+ 1,78% postgres postgres [.] heapam_index_fetch_tuple.lto_priv.0
+ 1,73% postgres postgres [.] StartReadBuffer
+ 1,51% postgres postgres [.] LWLockAcquire
+ 1,25% postgres postgres [.] HeapTupleSatisfiesVisibility
+ 1,18% postgres postgres [.] heap_page_prune_opt
+ 1,13% postgres postgres [.] ExecScan
+ 1,11% postgres postgres [.] index_getnext_tid
+ 1,05% postgres postgres [.] index_fetch_heap
+ 1,01% postgres postgres [.] _bt_readpage
+ 0,86% postgres postgres [.] LWLockRelease
+ 0,85% postgres postgres [.] XidInMVCCSnapshot
+ 0,74% postgres postgres [.] ReleaseBuffer
+ 0,73% postgres postgres [.] IndexNext
+ 0,72% postgres postgres [.] _bt_checkkeys
+ 0,72% postgres postgres [.] _bt_next
+ 0,56% postgres postgres [.] GetPrivateRefCountEntry.lto_priv.0
+ 0,54% postgres postgres [.] btgettuple
0,44% postgres postgres [.] ExecStoreBufferHeapTuple
0,41% postgres postgres [.] _bt_check_compare.lto_priv.0
0,41% postgres postgres [.] hash_bytes
0,39% postgres postgres [.] MemoryContextReset
0,34% postgres postgres [.] ExecEvalSysVar
0,34% postgres postgres [.] ExecNestLoop
0,32% postgres postgres [.] tts_virtual_clear.lto_priv.0
0,32% postgres postgres [.] ResourceOwnerForget
0,30% postgres postgres [.] GlobalVisTestFor
0,30% postgres postgres [.] HeapTupleIsSurelyDead
0,26% postgres postgres [.] PredicateLockTID
0,22% postgres postgres [.] ReadBufferExtended
0,20% postgres postgres [.] _bt_setuppostingitems
0,20% postgres postgres [.] ExecIndexScan
0,20% postgres postgres [.] slot_getsomeattrs_int
0,17% postgres libc.so.6 [.] __memcmp_sse2
0,16% postgres postgres [.] _bt_saveitem
0,13% postgres postgres [.] ResourceOwnerEnlarge
0,12% postgres postgres [.]
HeapCheckForSerializableConflictOut
0,10% postgres postgres [.] pgstat_count_io_op
0,08% postgres postgres [.] IncrBufferRefCount
RUN 3 - NO CHILDREN:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10010750000
Overhead Command Shared Object Symbol
+ 25,54% postgres postgres [.] LWLockAttemptLock
+ 16,44% postgres postgres [.] LWLockReleaseInternal
+ 12,72% postgres postgres [.] ReleaseAndReadBuffer
+ 4,88% postgres postgres [.] tts_heap_getsomeattrs.lto_priv.0
+ 4,69% postgres postgres [.] PinBuffer
+ 3,75% postgres postgres [.] heap_hot_search_buffer
+ 3,47% postgres postgres [.] hash_search_with_hash_value
+ 2,95% postgres postgres [.] ExecInterpExpr
+ 2,01% postgres postgres [.] UnpinBufferNoOwner.lto_priv.0
+ 1,89% postgres postgres [.] heapam_index_fetch_tuple.lto_priv.0
+ 1,69% postgres postgres [.] StartReadBuffer
+ 1,50% postgres postgres [.] LWLockAcquire
+ 1,14% postgres postgres [.] HeapTupleSatisfiesVisibility
+ 1,12% postgres postgres [.] heap_page_prune_opt
+ 1,10% postgres postgres [.] ExecScan
+ 1,09% postgres postgres [.] index_getnext_tid
+ 1,03% postgres postgres [.] index_fetch_heap
+ 1,01% postgres postgres [.] LWLockRelease
+ 0,99% postgres postgres [.] _bt_readpage
+ 0,87% postgres postgres [.] XidInMVCCSnapshot
+ 0,79% postgres postgres [.] IndexNext
+ 0,76% postgres postgres [.] ReleaseBuffer
+ 0,74% postgres postgres [.] _bt_next
+ 0,72% postgres postgres [.] _bt_checkkeys
+ 0,61% postgres postgres [.] btgettuple
+ 0,59% postgres postgres [.] GetPrivateRefCountEntry.lto_priv.0
0,50% postgres postgres [.] ExecStoreBufferHeapTuple
0,41% postgres postgres [.] _bt_check_compare.lto_priv.0
0,41% postgres postgres [.] hash_bytes
0,38% postgres postgres [.] MemoryContextReset
0,34% postgres postgres [.] ExecEvalSysVar
0,34% postgres postgres [.] HeapTupleIsSurelyDead
0,34% postgres postgres [.] ExecNestLoop
0,32% postgres postgres [.] ResourceOwnerForget
0,31% postgres postgres [.] GlobalVisTestFor
0,31% postgres postgres [.] tts_virtual_clear.lto_priv.0
0,25% postgres postgres [.] ReadBufferExtended
0,22% postgres postgres [.] PredicateLockTID
0,21% postgres postgres [.] slot_getsomeattrs_int
0,17% postgres postgres [.] ExecIndexScan
0,17% postgres postgres [.] _bt_saveitem
0,16% postgres postgres [.] _bt_setuppostingitems
0,14% postgres postgres [.]
HeapCheckForSerializableConflictOut
0,13% postgres libc.so.6 [.] __memcmp_sse2
0,12% postgres postgres [.] ResourceOwnerEnlarge
0,11% postgres postgres [.] IncrBufferRefCount
0,10% postgres postgres [.] pgstat_count_io_op
RUN 4 - NO CHILDREN:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10010500000
Overhead Command Shared Object Symbol
+ 25,65% postgres postgres [.] LWLockAttemptLock
+ 15,76% postgres postgres [.] LWLockReleaseInternal
+ 12,75% postgres postgres [.] ReleaseAndReadBuffer
+ 4,83% postgres postgres [.] tts_heap_getsomeattrs.lto_priv.0
+ 4,78% postgres postgres [.] PinBuffer
+ 3,82% postgres postgres [.] heap_hot_search_buffer
+ 3,76% postgres postgres [.] hash_search_with_hash_value
+ 3,03% postgres postgres [.] ExecInterpExpr
+ 2,11% postgres postgres [.] UnpinBufferNoOwner.lto_priv.0
+ 2,01% postgres postgres [.] heapam_index_fetch_tuple.lto_priv.0
+ 1,65% postgres postgres [.] StartReadBuffer
+ 1,45% postgres postgres [.] LWLockAcquire
+ 1,17% postgres postgres [.] heap_page_prune_opt
+ 1,16% postgres postgres [.] ExecScan
+ 1,16% postgres postgres [.] HeapTupleSatisfiesVisibility
+ 1,04% postgres postgres [.] index_getnext_tid
+ 1,01% postgres postgres [.] LWLockRelease
+ 1,01% postgres postgres [.] _bt_readpage
+ 0,99% postgres postgres [.] index_fetch_heap
+ 0,82% postgres postgres [.] XidInMVCCSnapshot
+ 0,79% postgres postgres [.] _bt_next
+ 0,73% postgres postgres [.] IndexNext
+ 0,72% postgres postgres [.] _bt_checkkeys
+ 0,71% postgres postgres [.] ReleaseBuffer
+ 0,63% postgres postgres [.] GetPrivateRefCountEntry.lto_priv.0
+ 0,58% postgres postgres [.] btgettuple
0,46% postgres postgres [.] ExecStoreBufferHeapTuple
0,44% postgres postgres [.] _bt_check_compare.lto_priv.0
0,37% postgres postgres [.] ExecEvalSysVar
0,36% postgres postgres [.] MemoryContextReset
0,34% postgres postgres [.] tts_virtual_clear.lto_priv.0
0,32% postgres postgres [.] ExecNestLoop
0,31% postgres postgres [.] GlobalVisTestFor
0,30% postgres postgres [.] HeapTupleIsSurelyDead
0,30% postgres postgres [.] hash_bytes
0,27% postgres postgres [.] PredicateLockTID
0,26% postgres postgres [.] ResourceOwnerForget
0,26% postgres postgres [.] ReadBufferExtended
0,23% postgres postgres [.] slot_getsomeattrs_int
0,17% postgres postgres [.] _bt_setuppostingitems
0,17% postgres libc.so.6 [.] __memcmp_sse2
0,15% postgres postgres [.] ExecIndexScan
0,14% postgres postgres [.] _bt_saveitem
0,12% postgres postgres [.] int8eq
0,12% postgres postgres [.]
ReservePrivateRefCountEntry.lto_priv.0
0,12% postgres postgres [.] ResourceOwnerEnlarge
0,11% postgres postgres [.]
HeapCheckForSerializableConflictOut
RUN 5 - NO CHILDREN:
Samples: 40K of event 'task-clock:ppp', Event count (approx.): 10003250000
Overhead Command Shared Object Symbol
+ 26,48% postgres postgres [.] LWLockAttemptLock
+ 15,81% postgres postgres [.] LWLockReleaseInternal
+ 12,88% postgres postgres [.] ReleaseAndReadBuffer
+ 4,84% postgres postgres [.]
tts_heap_getsomeattrs.lto_priv.0
+ 4,64% postgres postgres [.] PinBuffer
+ 3,67% postgres postgres [.] heap_hot_search_buffer
+ 3,47% postgres postgres [.] hash_search_with_hash_value
+ 2,97% postgres postgres [.] ExecInterpExpr
+ 2,11% postgres postgres [.] UnpinBufferNoOwner.lto_priv.0
+ 1,92% postgres postgres [.]
heapam_index_fetch_tuple.lto_priv.0
+ 1,88% postgres postgres [.] StartReadBuffer
+ 1,41% postgres postgres [.] LWLockAcquire
+ 1,12% postgres postgres [.] heap_page_prune_opt
+ 1,09% postgres postgres [.] HeapTupleSatisfiesVisibility
+ 1,00% postgres postgres [.] index_fetch_heap
+ 0,97% postgres postgres [.] _bt_readpage
+ 0,92% postgres postgres [.] _bt_next
+ 0,92% postgres postgres [.] index_getnext_tid
+ 0,90% postgres postgres [.] ExecScan
+ 0,85% postgres postgres [.] IndexNext
+ 0,83% postgres postgres [.] XidInMVCCSnapshot
+ 0,81% postgres postgres [.] LWLockRelease
+ 0,71% postgres postgres [.] _bt_checkkeys
+ 0,69% postgres postgres [.] ReleaseBuffer
+ 0,57% postgres postgres [.]
GetPrivateRefCountEntry.lto_priv.0
+ 0,53% postgres postgres [.] btgettuple
0,48% postgres postgres [.] _bt_check_compare.lto_priv.0
0,46% postgres postgres [.] MemoryContextReset
0,42% postgres postgres [.] hash_bytes
0,40% postgres postgres [.] ExecStoreBufferHeapTuple
0,36% postgres postgres [.] ResourceOwnerForget
0,35% postgres postgres [.] ExecNestLoop
0,33% postgres postgres [.] ExecEvalSysVar
0,32% postgres postgres [.] HeapTupleIsSurelyDead
0,27% postgres postgres [.] GlobalVisTestFor
0,26% postgres postgres [.] PredicateLockTID
0,22% postgres postgres [.] ReadBufferExtended
0,22% postgres postgres [.] tts_virtual_clear.lto_priv.0
0,21% postgres postgres [.] slot_getsomeattrs_int
0,19% postgres postgres [.] _bt_saveitem
0,19% postgres postgres [.] _bt_setuppostingitems
0,18% postgres postgres [.] ResourceOwnerEnlarge
0,17% postgres postgres [.] ExecIndexScan
0,14% postgres libc.so.6 [.] __memcmp_sse2
0,12% postgres postgres [.] pgstat_count_io_op
0,10% postgres postgres [.] int8eq
0,10% postgres postgres [.]
HeapCheckForSerializableConflictOut
view thread (56+ messages) latest in thread
Message-ID: <4cc396f3-6508-4e25-a6da-efdd4f939946@boeringa.demon.nl>
Permalink: ../4cc396f3-6508-4e25-a6da-efdd4f939946@boeringa.demon.nl/
Also on: postgresql.org/message-id/4cc396f3-6508-4e25-a6da-efdd4f939946@boeringa.demon.nl
copy link · copy postgr.es
reply Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-bugs@postgresql.org
Cc: marco@boeringa.demon.nl, andres@anarazel.de, thom@linux.com
Subject: Re: Potential "AIO / io workers" inter-worker locking issue in PG18?
In-Reply-To: <4cc396f3-6508-4e25-a6da-efdd4f939946@boeringa.demon.nl>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox