Re: pg_stat_statements issue with parallel maintenance (Was Re: WALusage calculation patch)
От | Masahiko Sawada |
---|---|
Тема | Re: pg_stat_statements issue with parallel maintenance (Was Re: WALusage calculation patch) |
Дата | |
Msg-id | CA+fd4k75hAHm27qu_x=_5PPp4K+4mxOkPUGexeXtv+5TSwJn_w@mail.gmail.com обсуждение исходный текст |
Ответ на | Re: pg_stat_statements issue with parallel maintenance (Was Re: WALusage calculation patch) (Masahiko Sawada <masahiko.sawada@2ndquadrant.com>) |
Ответы |
Re: pg_stat_statements issue with parallel maintenance (Was Re: WALusage calculation patch)
(Amit Kapila <amit.kapila16@gmail.com>)
|
Список | pgsql-hackers |
On Tue, 7 Apr 2020 at 18:29, Masahiko Sawada <masahiko.sawada@2ndquadrant.com> wrote: > > On Tue, 7 Apr 2020 at 17:42, Amit Kapila <amit.kapila16@gmail.com> wrote: > > > > On Tue, Apr 7, 2020 at 1:30 PM Masahiko Sawada > > <masahiko.sawada@2ndquadrant.com> wrote: > > > > > > Buffer usage statistics seem correct. The small differences would be > > > catalog lookups Peter mentioned. > > > > > > > Agreed, but can you check which part of code does that lookup? I want > > to see if we can avoid that from buffer usage stats or at least write > > a comment about it, otherwise, we might have to face this question > > again and again. > > Okay, I'll check it. > I've checked the buffer usage differences when parallel btree index creation. TL;DR; During tuple sorting individual parallel workers read blocks of pg_amproc and pg_amproc_fam_proc_index to get the sort support function. The call flow is like: ParallelWorkerMain() _bt_parallel_scan_and_sort() tuplesort_begin_index_btree() PrepareSortSupportFromIndexRel() FinishSortSupportFunction() get_opfamily_proc() The details are as follows. I populated the test table by the following scripts: create table test (c int) with (autovacuum_enabled = off, parallel_workers = 8); insert into test select generate_series(1,10000000); and create index DDL is: create index test_idx on test (c); Before executing the test script, I've put code at the following 4 places which checks the buffer usage at that point, and calculated the difference between points: (a), (b) and (c). For example, (b) shows the number of blocks read or hit during executing scanning heap and building index. 1. Before executing CREATE INDEX command (at pgss_ProcessUtility()) (a) 2. Before parallel create index (at _bt_begin_parallel()) (b) 3. After parallel create index, after accumlating workers stats (at _bt_end_parallel()) (c) 4. After executing CREATE INDEX command (at pgss_ProcessUtility()) And here is the results: 2 workers: (a) hit: 107, read: 26 (b) hit: 12(=6+3+3), read: 44248(=15538+14453+14527) (c) hit: 13, read: 2 total hit: 132, read:44276 4 workers: (a) hit: 107, read: 26 (b) hit: 18(=6+3+3+3+3), read: 44248(=9368+8582+8544+9250+8504) (c) hit: 13, read: 2 total hit: 138, read:44276 The table 'test' has 44276 blocks. From the above results, the total number of reading blocks (44248 blocks) during parallel index creation is stable and equals to the number of blocks of the test table. And we can see that extra three blocks are read per workers. These three blocks are two for pg_amproc_fam_proc_index and one for pg_amproc. That is, individual parallel workers accesses these relations to get the sort support function. The full backtrace is: * thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP * frame #0: 0x00007fff779c561a libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010cc9f90d postgres`pg_usleep(microsec=20000000) at pgsleep.c:56:10 frame #2: 0x000000010ca5a668 postgres`ReadBuffer_common(smgr=0x00007fe872848f70, relpersistence='p', forkNum=MAIN_FORKNUM, blockNum=3, mode=RBM_NORMAL, strategy=0x0000000000000000, hit=0x00007ffee363071b) at bufmgr.c:685:3 frame #3: 0x000000010ca5a4b6 postgres`ReadBufferExtended(reln=0x000000010d58f790, forkNum=MAIN_FORKNUM, blockNum=3, mode=RBM_NORMAL, strategy=0x0000000000000000) at bufmgr.c:628:8 frame #4: 0x000000010ca5a397 postgres`ReadBuffer(reln=0x000000010d58f790, blockNum=3) at bufmgr.c:560:9 frame #5: 0x000000010c67187e postgres`_bt_getbuf(rel=0x000000010d58f790, blkno=3, access=1) at nbtpage.c:792:9 frame #6: 0x000000010c670507 postgres`_bt_getroot(rel=0x000000010d58f790, access=1) at nbtpage.c:294:13 frame #7: 0x000000010c679393 postgres`_bt_search(rel=0x000000010d58f790, key=0x00007ffee36312d0, bufP=0x00007ffee3631bec, access=1, snapshot=0x00007fe8728388e0) at nbtsearch.c:107:10 frame #8: 0x000000010c67b489 postgres`_bt_first(scan=0x00007fe86f814998, dir=ForwardScanDirection) at nbtsearch.c:1355:10 frame #9: 0x000000010c676869 postgres`btgettuple(scan=0x00007fe86f814998, dir=ForwardScanDirection) at nbtree.c:253:10 frame #10: 0x000000010c6656ad postgres`index_getnext_tid(scan=0x00007fe86f814998, direction=ForwardScanDirection) at indexam.c:530:10 frame #11: 0x000000010c66585b postgres`index_getnext_slot(scan=0x00007fe86f814998, direction=ForwardScanDirection, slot=0x00007fe86f814880) at indexam.c:622:10 frame #12: 0x000000010c663eac postgres`systable_getnext(sysscan=0x00007fe86f814828) at genam.c:454:7 frame #13: 0x000000010cc0be41 postgres`SearchCatCacheMiss(cache=0x00007fe872818e80, nkeys=4, hashValue=3052139574, hashIndex=6, v1=1976, v2=23, v3=23, v4=2) at catcache.c:1368:9 frame #14: 0x000000010cc0bced postgres`SearchCatCacheInternal(cache=0x00007fe872818e80, nkeys=4, v1=1976, v2=23, v3=23, v4=2) at catcache.c:1299:9 frame #15: 0x000000010cc0baa8 postgres`SearchCatCache4(cache=0x00007fe872818e80, v1=1976, v2=23, v3=23, v4=2) at catcache.c:1191:9 frame #16: 0x000000010cc27c82 postgres`SearchSysCache4(cacheId=5, key1=1976, key2=23, key3=23, key4=2) at syscache.c:1156:9 frame #17: 0x000000010cc105dd postgres`get_opfamily_proc(opfamily=1976, lefttype=23, righttype=23, procnum=2) at lsyscache.c:751:7 frame #18: 0x000000010cc72e1d postgres`FinishSortSupportFunction(opfamily=1976, opcintype=23, ssup=0x00007fe86f8147d0) at sortsupport.c:99:24 frame #19: 0x000000010cc73100 postgres`PrepareSortSupportFromIndexRel(indexRel=0x000000010d5ced48, strategy=1, ssup=0x00007fe86f8147d0) at sortsupport.c:176:2 frame #20: 0x000000010cc75463 postgres`tuplesort_begin_index_btree(heapRel=0x000000010d5cf808, indexRel=0x000000010d5ced48, enforceUnique=false, workMem=21845, coordinate=0x00007fe872839248, randomAccess=false) at tuplesort.c:1114:3 frame #21: 0x000000010c681ffc postgres`_bt_parallel_scan_and_sort(btspool=0x00007fe872839738, btspool2=0x0000000000000000, btshared=0x000000010d56c4c0, sharedsort=0x000000010d56c460, sharedsort2=0x0000000000000000, sortmem=21845, progress=false) at nbtsort.c:1941:23 frame #22: 0x000000010c681eb2 postgres`_bt_parallel_build_main(seg=0x00007fe87280a058, toc=0x000000010d56c000) at nbtsort.c:1889:2 frame #23: 0x000000010c6b7358 postgres`ParallelWorkerMain(main_arg=1169089032) at parallel.c:1471:2 frame #24: 0x000000010c9da86f postgres`StartBackgroundWorker at bgworker.c:813:2 frame #25: 0x000000010c9efbc0 postgres`do_start_bgworker(rw=0x00007fe86f419290) at postmaster.c:5852:4 frame #26: 0x000000010c9eff9f postgres`maybe_start_bgworkers at postmaster.c:6078:9 frame #27: 0x000000010c9eee99 postgres`sigusr1_handler(postgres_signal_arg=30) at postmaster.c:5247:3 frame #28: 0x00007fff77a74b5d libsystem_platform.dylib`_sigtramp + 29 frame #29: 0x00007fff779c561b libsystem_kernel.dylib`__select + 11 frame #30: 0x000000010c9ea48c postgres`ServerLoop at postmaster.c:1691:13 frame #31: 0x000000010c9e9e06 postgres`PostmasterMain(argc=5, argv=0x00007fe86f4036f0) at postmaster.c:1400:11 frame #32: 0x000000010c8ee399 postgres`main(argc=<unavailable>, argv=<unavailable>) at main.c:210:3 frame #33: 0x00007fff778893d5 libdyld.dylib`start + 1 Regards, -- Masahiko Sawada http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
В списке pgsql-hackers по дате отправления: