Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lBvGU-0007RX-6l for pgsql-hackers@arkaria.postgresql.org; Tue, 16 Feb 2021 07:59:22 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1lBvGR-000657-1x for pgsql-hackers@arkaria.postgresql.org; Tue, 16 Feb 2021 07:59:19 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lBvGQ-00064z-Pz for pgsql-hackers@lists.postgresql.org; Tue, 16 Feb 2021 07:59:18 +0000 Received: from oss.nttdata.com ([49.212.34.109]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lBvGM-0006ls-IJ for pgsql-hackers@postgresql.org; Tue, 16 Feb 2021 07:59:17 +0000 Received: from hnk.local (p2710230-ipbf1703funabasi.chiba.ocn.ne.jp [123.216.93.230]) by oss.nttdata.com (Postfix) with ESMTPSA id 22DA26280A; Tue, 16 Feb 2021 16:59:09 +0900 (JST) X-Virus-Status: Clean X-Virus-Scanned: clamav-milter 0.102.3 at oss.nttdata.com Subject: Re: adding wait_start column to pg_locks From: Fujii Masao To: torikoshia Cc: Ian Lawrence Barwick , Robert Haas , Justin Pryzby , pgsql-hackers References: <0fd375a53e306566cea7f451cc8cfcde@oss.nttdata.com> <7b1bb07a-73ec-1fcc-2f65-41101adf0080@oss.nttdata.com> <8002219d-b999-12fa-2327-49afe40e5fbb@oss.nttdata.com> <88c451c7-2729-4329-fbae-6ed7664adea1@oss.nttdata.com> <3db333a9-31f7-a225-8038-eeb835ba8f37@oss.nttdata.com> <990e5d4b-075f-101f-aec5-bb44f9b30550@oss.nttdata.com> <40dfaa75-1058-e811-1f7c-4cf7203a3068@oss.nttdata.com> <64102638-7fc3-1941-12f1-e139e3463c03@oss.nttdata.com> <067d5597e5de82fe47e5716991ab65c4@oss.nttdata.com> <337d5311-6113-15e0-bd85-90b47b55f5ae@oss.nttdata.com> <655f1a5b-4fa8-53ba-c3e2-8cee31587d37@oss.nttdata.com> Message-ID: <1df88660-6f08-cc6e-b7e2-f85296a2bdab@oss.nttdata.com> Date: Tue, 16 Feb 2021 16:59:08 +0900 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.14; rv:78.0) Gecko/20100101 Thunderbird/78.7.1 MIME-Version: 1.0 In-Reply-To: <655f1a5b-4fa8-53ba-c3e2-8cee31587d37@oss.nttdata.com> Content-Type: multipart/mixed; boundary="------------BF36ED1673A3B8CE5733A4E5" Content-Language: en-US List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk This is a multi-part message in MIME format. --------------BF36ED1673A3B8CE5733A4E5 Content-Type: text/plain; charset=utf-8; format=flowed Content-Transfer-Encoding: 8bit On 2021/02/15 15:17, Fujii Masao wrote: > > > On 2021/02/10 10:43, Fujii Masao wrote: >> >> >> On 2021/02/09 23:31, torikoshia wrote: >>> On 2021-02-09 22:54, Fujii Masao wrote: >>>> On 2021/02/09 19:11, Fujii Masao wrote: >>>>> >>>>> >>>>> On 2021/02/09 18:13, Fujii Masao wrote: >>>>>> >>>>>> >>>>>> On 2021/02/09 17:48, torikoshia wrote: >>>>>>> On 2021-02-05 18:49, Fujii Masao wrote: >>>>>>>> On 2021/02/05 0:03, torikoshia wrote: >>>>>>>>> On 2021-02-03 11:23, Fujii Masao wrote: >>>>>>>>>>> 64-bit fetches are not atomic on some platforms. So spinlock is necessary when updating "waitStart" without holding the partition lock? Also GetLockStatusData() needs spinlock when reading "waitStart"? >>>>>>>>>> >>>>>>>>>> Also it might be worth thinking to use 64-bit atomic operations like >>>>>>>>>> pg_atomic_read_u64(), for that. >>>>>>>>> >>>>>>>>> Thanks for your suggestion and advice! >>>>>>>>> >>>>>>>>> In the attached patch I used pg_atomic_read_u64() and pg_atomic_write_u64(). >>>>>>>>> >>>>>>>>> waitStart is TimestampTz i.e., int64, but it seems pg_atomic_read_xxx and pg_atomic_write_xxx only supports unsigned int, so I cast the type. >>>>>>>>> >>>>>>>>> I may be using these functions not correctly, so if something is wrong, I would appreciate any comments. >>>>>>>>> >>>>>>>>> >>>>>>>>> About the documentation, since your suggestion seems better than v6, I used it as is. >>>>>>>> >>>>>>>> Thanks for updating the patch! >>>>>>>> >>>>>>>> +    if (pg_atomic_read_u64(&MyProc->waitStart) == 0) >>>>>>>> +        pg_atomic_write_u64(&MyProc->waitStart, >>>>>>>> +                            pg_atomic_read_u64((pg_atomic_uint64 *) &now)); >>>>>>>> >>>>>>>> pg_atomic_read_u64() is really necessary? I think that >>>>>>>> "pg_atomic_write_u64(&MyProc->waitStart, now)" is enough. >>>>>>>> >>>>>>>> +        deadlockStart = get_timeout_start_time(DEADLOCK_TIMEOUT); >>>>>>>> +        pg_atomic_write_u64(&MyProc->waitStart, >>>>>>>> +                    pg_atomic_read_u64((pg_atomic_uint64 *) &deadlockStart)); >>>>>>>> >>>>>>>> Same as above. >>>>>>>> >>>>>>>> +        /* >>>>>>>> +         * Record waitStart reusing the deadlock timeout timer. >>>>>>>> +         * >>>>>>>> +         * It would be ideal this can be synchronously done with updating >>>>>>>> +         * lock information. Howerver, since it gives performance impacts >>>>>>>> +         * to hold partitionLock longer time, we do it here asynchronously. >>>>>>>> +         */ >>>>>>>> >>>>>>>> IMO it's better to comment why we reuse the deadlock timeout timer. >>>>>>>> >>>>>>>>      proc->waitStatus = waitStatus; >>>>>>>> +    pg_atomic_init_u64(&MyProc->waitStart, 0); >>>>>>>> >>>>>>>> pg_atomic_write_u64() should be used instead? Because waitStart can be >>>>>>>> accessed concurrently there. >>>>>>>> >>>>>>>> I updated the patch and addressed the above review comments. Patch attached. >>>>>>>> Barring any objection, I will commit this version. >>>>>>> >>>>>>> Thanks for modifying the patch! >>>>>>> I agree with your comments. >>>>>>> >>>>>>> BTW, I ran pgbench several times before and after applying >>>>>>> this patch. >>>>>>> >>>>>>> The environment is virtual machine(CentOS 8), so this is >>>>>>> just for reference, but there were no significant difference >>>>>>> in latency or tps(both are below 1%). >>>>>> >>>>>> Thanks for the test! I pushed the patch. >>>>> >>>>> But I reverted the patch because buildfarm members rorqual and >>>>> prion don't like the patch. I'm trying to investigate the cause >>>>> of this failures. >>>>> >>>>> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=rorqual&dt=2021-02-09%2009%3A20%3A10 >>>> >>>> -    relation     | locktype |        mode >>>> ------------------+----------+--------------------- >>>> - test_prepared_1 | relation | RowExclusiveLock >>>> - test_prepared_1 | relation | AccessExclusiveLock >>>> -(2 rows) >>>> - >>>> +ERROR:  invalid spinlock number: 0 >>>> >>>> "rorqual" reported that the above error happened in the server built with >>>> --disable-atomics --disable-spinlocks when reading pg_locks after >>>> the transaction was prepared. The cause of this issue is that "waitStart" >>>> atomic variable in the dummy proc created at the end of prepare transaction >>>> was not initialized. I updated the patch so that pg_atomic_init_u64() is >>>> called for the "waitStart" in the dummy proc for prepared transaction. >>>> Patch attached. I confirmed that the patched server built with >>>> --disable-atomics --disable-spinlocks passed all the regression tests. >>> >>> Thanks for fixing the bug, I also tested v9.patch configured with >>> --disable-atomics --disable-spinlocks on my environment and confirmed >>> that all tests have passed. >> >> Thanks for the test! >> >> I found another bug in the patch. InitProcess() initializes "waitStart", >> but previously InitAuxiliaryProcess() did not. This could cause "invalid >> spinlock number" error when reading pg_locks in the standby server. >> I fixed that. Attached is the updated version of the patch. > > I pushed this version. Thanks! While reading the patch again, I found two minor things. 1. As discussed in another thread [1], the atomic variable "waitStart" should be initialized at the postmaster startup rather than the startup of each child process. I changed "waitStart" so that it's initialized in InitProcGlobal() and also reset to 0 by using pg_atomic_write_u64() in InitProcess() and InitAuxiliaryProcess(). 2. Thanks to the above change, InitProcGlobal() initializes "waitStart" even in PGPROC entries for prepare transactions. But those entries are zeroed in MarkAsPreparingGuts(), so "waitStart" needs to be initialized again. Currently TwoPhaseGetDummyProc() initializes "waitStart" in the PGPROC entry for prepare transaction. But it's better to do that in MarkAsPreparingGuts() instead because that function initializes other PGPROC variables. So I moved that initialization code from TwoPhaseGetDummyProc() to MarkAsPreparingGuts(). Patch attached. Thought? [1] https://postgr.es/m/7ef8708c-5b6b-edd3-2cf2-7783f1c7c175@oss.nttdata.com Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION --------------BF36ED1673A3B8CE5733A4E5 Content-Type: text/plain; charset=UTF-8; x-mac-type="0"; x-mac-creator="0"; name="bugfix_pg_locks_waitstart.patch" Content-Transfer-Encoding: base64 Content-Disposition: attachment; filename="bugfix_pg_locks_waitstart.patch" ZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL2FjY2Vzcy90cmFuc2FtL3R3b3BoYXNlLmMgYi9z cmMvYmFja2VuZC9hY2Nlc3MvdHJhbnNhbS90d29waGFzZS5jCmluZGV4IDcwZDIyNTc3Y2Uu LmM5YjEzMDYyYjAgMTAwNjQ0Ci0tLSBhL3NyYy9iYWNrZW5kL2FjY2Vzcy90cmFuc2FtL3R3 b3BoYXNlLmMKKysrIGIvc3JjL2JhY2tlbmQvYWNjZXNzL3RyYW5zYW0vdHdvcGhhc2UuYwpA QCAtNDc1LDYgKzQ3NSw3IEBAIE1hcmtBc1ByZXBhcmluZ0d1dHMoR2xvYmFsVHJhbnNhY3Rp b24gZ3hhY3QsIFRyYW5zYWN0aW9uSWQgeGlkLCBjb25zdCBjaGFyICpnaWQsCiAJcHJvYy0+ bHdXYWl0TW9kZSA9IDA7CiAJcHJvYy0+d2FpdExvY2sgPSBOVUxMOwogCXByb2MtPndhaXRQ cm9jTG9jayA9IE5VTEw7CisJcGdfYXRvbWljX2luaXRfdTY0KCZwcm9jLT53YWl0U3RhcnQs IDApOwogCWZvciAoaSA9IDA7IGkgPCBOVU1fTE9DS19QQVJUSVRJT05TOyBpKyspCiAJCVNI TVF1ZXVlSW5pdCgmKHByb2MtPm15UHJvY0xvY2tzW2ldKSk7CiAJLyogc3VieGlkIGRhdGEg bXVzdCBiZSBmaWxsZWQgbGF0ZXIgYnkgR1hhY3RMb2FkU3VieGFjdERhdGEgKi8KQEAgLTg3 MywxNSArODc0LDggQEAgUEdQUk9DICoKIFR3b1BoYXNlR2V0RHVtbXlQcm9jKFRyYW5zYWN0 aW9uSWQgeGlkLCBib29sIGxvY2tfaGVsZCkKIHsKIAlHbG9iYWxUcmFuc2FjdGlvbiBneGFj dCA9IFR3b1BoYXNlR2V0R1hhY3QoeGlkLCBsb2NrX2hlbGQpOwotCVBHUFJPQwkgICAqZHVt bXkgPSAmUHJvY0dsb2JhbC0+YWxsUHJvY3NbZ3hhY3QtPnBncHJvY25vXTsKIAotCS8qCi0J ICogSW5pdGlhbGl6ZSBhdG9taWMgdmFyaWFibGUgaW4gZHVtbXkgcHJvYyBzbyB0aGF0IEdl dExvY2tTdGF0dXNEYXRhKCkKLQkgKiBjYW4gcmVhZCBpdCBsYXRlci4KLQkgKi8KLQlwZ19h dG9taWNfaW5pdF91NjQoJmR1bW15LT53YWl0U3RhcnQsIDApOwotCi0JcmV0dXJuIGR1bW15 OworCXJldHVybiAmUHJvY0dsb2JhbC0+YWxsUHJvY3NbZ3hhY3QtPnBncHJvY25vXTsKIH0K IAogLyoqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioq KioqKioqKioqKioqKioqKioqKioqKi8KZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL3N0b3Jh Z2UvbG1nci9wcm9jLmMgYi9zcmMvYmFja2VuZC9zdG9yYWdlL2xtZ3IvcHJvYy5jCmluZGV4 IDA4ODQ5MDlhMjIuLjhlN2QyMTQ1NmEgMTAwNjQ0Ci0tLSBhL3NyYy9iYWNrZW5kL3N0b3Jh Z2UvbG1nci9wcm9jLmMKKysrIGIvc3JjL2JhY2tlbmQvc3RvcmFnZS9sbWdyL3Byb2MuYwpA QCAtMjgxLDYgKzI4MSw3IEBAIEluaXRQcm9jR2xvYmFsKHZvaWQpCiAJCSAqLwogCQlwZ19h dG9taWNfaW5pdF91MzIoJihwcm9jc1tpXS5wcm9jQXJyYXlHcm91cE5leHQpLCBJTlZBTElE X1BHUFJPQ05PKTsKIAkJcGdfYXRvbWljX2luaXRfdTMyKCYocHJvY3NbaV0uY2xvZ0dyb3Vw TmV4dCksIElOVkFMSURfUEdQUk9DTk8pOworCQlwZ19hdG9taWNfaW5pdF91NjQoJihwcm9j c1tpXS53YWl0U3RhcnQpLCAwKTsKIAl9CiAKIAkvKgpAQCAtNDAyLDcgKzQwMyw3IEBAIElu aXRQcm9jZXNzKHZvaWQpCiAJTXlQcm9jLT5sd1dhaXRNb2RlID0gMDsKIAlNeVByb2MtPndh aXRMb2NrID0gTlVMTDsKIAlNeVByb2MtPndhaXRQcm9jTG9jayA9IE5VTEw7Ci0JcGdfYXRv bWljX2luaXRfdTY0KCZNeVByb2MtPndhaXRTdGFydCwgMCk7CisJcGdfYXRvbWljX3dyaXRl X3U2NCgmTXlQcm9jLT53YWl0U3RhcnQsIDApOwogI2lmZGVmIFVTRV9BU1NFUlRfQ0hFQ0tJ TkcKIAl7CiAJCWludAkJCWk7CkBAIC01ODEsNyArNTgyLDcgQEAgSW5pdEF1eGlsaWFyeVBy b2Nlc3Modm9pZCkKIAlNeVByb2MtPmx3V2FpdE1vZGUgPSAwOwogCU15UHJvYy0+d2FpdExv Y2sgPSBOVUxMOwogCU15UHJvYy0+d2FpdFByb2NMb2NrID0gTlVMTDsKLQlwZ19hdG9taWNf aW5pdF91NjQoJk15UHJvYy0+d2FpdFN0YXJ0LCAwKTsKKwlwZ19hdG9taWNfd3JpdGVfdTY0 KCZNeVByb2MtPndhaXRTdGFydCwgMCk7CiAjaWZkZWYgVVNFX0FTU0VSVF9DSEVDS0lORwog CXsKIAkJaW50CQkJaTsK --------------BF36ED1673A3B8CE5733A4E5--