Re: Potential "AIO / io workers" inter-worker locking issue in PG18? - Mailing list pgsql-bugs
| From | Marco Boeringa |
|---|---|
| Subject | Re: Potential "AIO / io workers" inter-worker locking issue in PG18? |
| Date | |
| Msg-id | 9d2027e4-ff80-4da9-90d6-4a7af58a1d9e@boeringa.demon.nl Whole thread Raw |
| In response to | Re: Potential "AIO / io workers" inter-worker locking issue in PG18? (Andres Freund <andres@anarazel.de>) |
| Responses |
Re: Potential "AIO / io workers" inter-worker locking issue in PG18?
|
| List | pgsql-bugs |
Hi Andres, Thanks for all the help and suggestions so far! > Can you test this with postgis 3.6 on 17? If I find time... but looking through the release notes of PostGIS 3.6.0, I doubt the issue is in PostGIS, as there do not appear to be any changes to the specific PostGIS functions I am using. That doesn't exclude it though. > The fact that it runs without a problem in 17 means it's actually rather meaningful to look at the query plan. It could have changed. Separately, it might help us to narrow down what changes to look at that could potentially be causing problems. I would fully understand if this was an "ordinary" issue case with a simple self-contained query and with things going wrong each time in the same way. However, as said, besides the major issue of running the query separately from my geoprocessing workflow which involves many more steps - which would mean that any test outside of it would *not* be very much representative of what is going on inside my tool and geoprocessing workflow - there is the fact that things going wrong is a random anomaly. I cannot stress this enough: about 3-4 in 5 runs are OK, then a random follow up run *with exactly the same input data* turns out bad with the stall. Even if there was an easy way to run the query, I think the chance is highly likely the postgres query planner would come up with a decent plan, as in normal circumstances, there is no issue. > Making vacuum more aggressive won't really help much if you have longrunning queries/sessions, since vacuum can't clean up row versions that are still visibile to some of the transactions. My code batches the updates in sets of 2000 records at a time and then COMMITs, so the transactions themselves are limited in time and size, which should allow vacuum to do its job. > Could you "unfold" the callstacks for the top entries? And/or attach a perf report --no-children > somefile (when redirecting to a file perf will include much more detail than when using it interactively) See below: # Total Lost Samples: 0 # # Samples: 40K of event 'task-clock:ppp' # Event count (approx.): 10003250000 # # Overhead Command Shared Object Symbol # ........ ........ ................. ........................................... # 26.48% postgres postgres [.] LWLockAttemptLock | ---LWLockAttemptLock | |--23.15%--heapam_index_fetch_tuple.lto_priv.0 | index_fetch_heap | IndexNext | ExecScan | ExecNestLoop | ExecNestLoop | ExecModifyTable | standard_ExecutorRun | ProcessQuery | PortalRunMulti | PortalRun | exec_simple_query | PostgresMain | 0x5f3570fb9dbf | postmaster_child_launch | ServerLoop.isra.0 | PostmasterMain | main | __libc_start_call_main | __libc_start_main@@GLIBC_2.34 | _start | --3.30%--StartReadBuffer ReadBufferExtended | --3.25%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 15.81% postgres postgres [.] LWLockReleaseInternal | ---LWLockReleaseInternal | --15.71%--LWLockRelease | |--15.03%--heapam_index_fetch_tuple.lto_priv.0 | index_fetch_heap | IndexNext | ExecScan | ExecNestLoop | ExecNestLoop | ExecModifyTable | standard_ExecutorRun | ProcessQuery | PortalRunMulti | PortalRun | exec_simple_query | PostgresMain | 0x5f3570fb9dbf | postmaster_child_launch | ServerLoop.isra.0 | PostmasterMain | main | __libc_start_call_main | __libc_start_main@@GLIBC_2.34 | _start | --0.66%--StartReadBuffer ReadBufferExtended | --0.66%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 12.88% postgres postgres [.] ReleaseAndReadBuffer | ---ReleaseAndReadBuffer | --12.78%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 4.84% postgres postgres [.] tts_heap_getsomeattrs.lto_priv.0 | ---tts_heap_getsomeattrs.lto_priv.0 | --4.80%--slot_getsomeattrs_int ExecInterpExpr ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 4.64% postgres postgres [.] PinBuffer | ---PinBuffer | --4.64%--StartReadBuffer ReadBufferExtended | --4.57%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 3.67% postgres postgres [.] heap_hot_search_buffer | ---heap_hot_search_buffer | --3.61%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 3.47% postgres postgres [.] hash_search_with_hash_value | ---hash_search_with_hash_value | --3.45%--StartReadBuffer ReadBufferExtended | --3.35%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop | --3.34%--ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 2.97% postgres postgres [.] ExecInterpExpr | ---ExecInterpExpr | |--1.64%--ExecNestLoop | | | --1.60%--ExecNestLoop | ExecModifyTable | standard_ExecutorRun | ProcessQuery | PortalRunMulti | PortalRun | exec_simple_query | PostgresMain | 0x5f3570fb9dbf | postmaster_child_launch | ServerLoop.isra.0 | PostmasterMain | main | __libc_start_call_main | __libc_start_main@@GLIBC_2.34 | _start | --1.33%--ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 2.11% postgres postgres [.] UnpinBufferNoOwner.lto_priv.0 | ---UnpinBufferNoOwner.lto_priv.0 | |--1.24%--ExecStoreBufferHeapTuple | heapam_index_fetch_tuple.lto_priv.0 | index_fetch_heap | IndexNext | ExecScan | ExecNestLoop | ExecNestLoop | ExecModifyTable | standard_ExecutorRun | ProcessQuery | PortalRunMulti | PortalRun | exec_simple_query | PostgresMain | 0x5f3570fb9dbf | postmaster_child_launch | ServerLoop.isra.0 | PostmasterMain | main | __libc_start_call_main | __libc_start_main@@GLIBC_2.34 | _start | --0.81%--ReleaseAndReadBuffer heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 1.92% postgres postgres [.] heapam_index_fetch_tuple.lto_priv.0 | ---heapam_index_fetch_tuple.lto_priv.0 | --1.67%--index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 1.88% postgres postgres [.] StartReadBuffer | ---StartReadBuffer | --1.86%--ReadBufferExtended | --1.83%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 1.41% postgres postgres [.] LWLockAcquire | ---LWLockAcquire | --1.15%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 1.12% postgres postgres [.] heap_page_prune_opt | ---heap_page_prune_opt | --1.12%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 1.09% postgres postgres [.] HeapTupleSatisfiesVisibility | ---HeapTupleSatisfiesVisibility | --1.02%--heap_hot_search_buffer heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 1.00% postgres postgres [.] index_fetch_heap | ---index_fetch_heap | --0.83%--IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.97% postgres postgres [.] _bt_readpage | ---_bt_readpage | --0.97%--_bt_readnextpage _bt_next btgettuple index_getnext_tid IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.92% postgres postgres [.] _bt_next | ---_bt_next | --0.82%--btgettuple index_getnext_tid IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.92% postgres postgres [.] index_getnext_tid | ---index_getnext_tid | --0.82%--IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.90% postgres postgres [.] ExecScan | ---ExecScan ExecNestLoop | --0.83%--ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.85% postgres postgres [.] IndexNext | ---IndexNext | --0.80%--ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.83% postgres postgres [.] XidInMVCCSnapshot | ---XidInMVCCSnapshot 0.81% postgres postgres [.] LWLockRelease | ---LWLockRelease | --0.54%--heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.71% postgres postgres [.] _bt_checkkeys | ---_bt_checkkeys | --0.65%--_bt_readpage _bt_readnextpage _bt_next btgettuple index_getnext_tid IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.69% postgres postgres [.] ReleaseBuffer | ---ReleaseBuffer | --0.68%--ExecStoreBufferHeapTuple heapam_index_fetch_tuple.lto_priv.0 index_fetch_heap IndexNext ExecScan ExecNestLoop ExecNestLoop ExecModifyTable standard_ExecutorRun ProcessQuery PortalRunMulti PortalRun exec_simple_query PostgresMain 0x5f3570fb9dbf postmaster_child_launch ServerLoop.isra.0 PostmasterMain main __libc_start_call_main __libc_start_main@@GLIBC_2.34 _start 0.57% postgres postgres [.] GetPrivateRefCountEntry.lto_priv.0 | ---GetPrivateRefCountEntry.lto_priv.0 0.53% postgres postgres [.] btgettuple | ---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 0.10% postgres postgres [.] ReservePrivateRefCountEntry.lto_priv.0 0.09% postgres postgres [.] IncrBufferRefCount 0.06% postgres postgres [.] _bt_checkpage 0.03% postgres postgres [.] BufferGetLSNAtomic 0.03% postgres postgres [.] tag_hash 0.03% postgres postgres [.] LockBufHdr 0.03% postgres postgres [.] _bt_readnextpage 0.02% postgres postgres [.] tts_buffer_heap_getsomeattrs.lto_priv.0 0.02% postgres [kernel.kallsyms] [k] handle_softirqs 0.01% postgres postgres [.] _bt_steppage 0.01% postgres [kernel.kallsyms] [k] task_mm_cid_work 0.00% postgres [kernel.kallsyms] [k] _raw_spin_unlock_irq 0.00% postgres [kernel.kallsyms] [k] irqentry_exit_to_user_mode 0.00% postgres postgres [.] TransactionIdIsCurrentTransactionId 0.00% postgres postgres [.] index_rescan 0.00% postgres [kernel.kallsyms] [k] _raw_spin_unlock_irqrestore 0.00% postgres postgres [.] AllocSetAlloc 0.00% postgres postgres [.] PredicateLockPage 0.00% postgres postgres [.] _bt_set_startikey
pgsql-bugs by date: