Re: Potential "AIO / io workers" inter-worker locking issue in PG18? - Mailing list 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