From: | Marco Boeringa <marco(at)boeringa(dot)demon(dot)nl> |
---|---|
To: | Andres Freund <andres(at)anarazel(dot)de> |
Cc: | pgsql-bugs(at)lists(dot)postgresql(dot)org, Thom Brown <thom(at)linux(dot)com> |
Subject: | Re: Potential "AIO / io workers" inter-worker locking issue in PG18? |
Date: | 2025-10-08 10:04:20 |
Message-ID: | 4cc396f3-6508-4e25-a6da-efdd4f939946@boeringa.demon.nl |
Views: | Whole Thread | Raw Message | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-bugs |
> 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
From | Date | Subject | |
---|---|---|---|
Next Message | Premal Patel | 2025-10-08 11:17:03 | Re: BUG #19076: Generic query plan is extremely slow |
Previous Message | David Rowley | 2025-10-08 09:13:54 | Re: BUG #19076: Generic query plan is extremely slow |