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 1pFPbj-0001eS-8W for pgsql-hackers@arkaria.postgresql.org; Wed, 11 Jan 2023 01:08:47 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1pFPbh-0000Ka-RF for pgsql-hackers@arkaria.postgresql.org; Wed, 11 Jan 2023 01:08:45 +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 1pFPbh-0000KQ-Fd for pgsql-hackers@lists.postgresql.org; Wed, 11 Jan 2023 01:08:45 +0000 Received: from mail-pj1-x1033.google.com ([2607:f8b0:4864:20::1033]) by magus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1pFPbe-0006GG-Nm for pgsql-hackers@postgresql.org; Wed, 11 Jan 2023 01:08:45 +0000 Received: by mail-pj1-x1033.google.com with SMTP id v23so14247201pju.3 for ; Tue, 10 Jan 2023 17:08:42 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=content-disposition:mime-version:message-id:subject:to:from:date :from:to:cc:subject:date:message-id:reply-to; bh=xKEYrBl6jKIq2G6oFVE2qYwvyG5DlOwBdPmP0/v8Mi8=; b=FnT1XOiZaVkr6kIioRynR5VGvx+uw+QbKLxlo1piaddKwz/kEoQqQOcGUx2qVJFdPM 3+8yJJRnTfiF7KYV04yC5pBIQep6iomKUAslYe4CJYb5ov4/gZhiwVYTg/zUTTJ9jDqs mS9FGQqT6Lp0R0lFi/Pktt8wBT/IbdTZr3tOLKPF9kH81AlZBDBfoVrEJcm04MY544D3 B6neRMLfW6TI9BQUVizj7AaM9F0D/lDmnBX8N757WGwR/rVj/zwZR1JOOGGTan8Up5ks zmti4GIIppylOGOvKEt5R69xMWTJDG6ioNkS0yeE/MjuJN3OGygkaWUdHlRAs+H5DCLQ HtPw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=content-disposition:mime-version:message-id:subject:to:from:date :x-gm-message-state:from:to:cc:subject:date:message-id:reply-to; bh=xKEYrBl6jKIq2G6oFVE2qYwvyG5DlOwBdPmP0/v8Mi8=; b=Ag30kzxsCSunpsexzH9HCUZ/CMo4neT9czUQacYquB6jOIhbmlb0dVcvClaYhEPZjm z0D86y1jY4MHV1Z65xoke2fu6J9ND1PsyvVEfDVyG++B+xSqUGso6DjtmIunPqA6hSmp 45vNmfhSjqyerx4Vfcy+yTIpHufT9Ald7RfeqGGvcd7PSdGxMg/WvohztokvcZMFo6UL AwJT/5kbDrcPN/BXdIE3Aini4kDee6TBs+L+BcvqQq+58a1nIwOmemAQG77MyEbn5dED COrtX4sSXru9kjm5Ff9fZrsETNteiYdA5vt0yOqzYJOTaqPsoITohmmQLwsPlcG8lLnx iSxw== X-Gm-Message-State: AFqh2kpnbU++P+NBRRSVzSocyH/eQPRTCwkicpiy41sLkemB7YE/2Ktt ITmT+0u+vYlG6qKaqXDXqxz6skJ8Co8= X-Google-Smtp-Source: AMrXdXtMHaXsrqJJQnrtM4FoWfoG/EmEw4ziIcCzerseFThpXFlMsVrDUcU0Kj1ZNFDciqd+ZqtJXA== X-Received: by 2002:a17:902:a406:b0:189:6ab3:9e75 with SMTP id p6-20020a170902a40600b001896ab39e75mr71676973plq.15.1673399319656; Tue, 10 Jan 2023 17:08:39 -0800 (PST) Received: from nathanxps13 ([50.47.162.83]) by smtp.gmail.com with ESMTPSA id n15-20020a170902d2cf00b0018963b8e131sm8634378plc.290.2023.01.10.17.08.38 for (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 10 Jan 2023 17:08:38 -0800 (PST) Date: Tue, 10 Jan 2023 17:08:36 -0800 From: Nathan Bossart To: pgsql-hackers@postgresql.org Subject: delay starting WAL receiver Message-ID: <20230111010836.GA1550875@nathanxps13> MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="HcAYCG3uE/tztfnV" Content-Disposition: inline List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --HcAYCG3uE/tztfnV Content-Type: text/plain; charset=us-ascii Content-Disposition: inline I discussed this a bit in a different thread [0], but I thought it deserved its own thread. After setting wal_retrieve_retry_interval to 1ms in the tests, I noticed that the recovery tests consistently take much longer. Upon further inspection, it looks like a similar race condition to the one described in e5d494d's commit message. With some added debug logs, I see that all of the callers of MaybeStartWalReceiver() complete before SIGCHLD is processed, so ServerLoop() waits for a minute before starting the WAL receiver. The attached patch fixes this by adjusting DetermineSleepTime() to limit the sleep to at most 100ms when WalReceiverRequested is set, similar to how the sleep is limited when background workers must be restarted. [0] https://postgr.es/m/20221215224721.GA694065%40nathanxps13 -- Nathan Bossart Amazon Web Services: https://aws.amazon.com --HcAYCG3uE/tztfnV Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="v1-0001-handle-race-condition-when-restarting-wal-receive.patch" From 6f32238f119236322dfb16262a88c3a9c5141413 Mon Sep 17 00:00:00 2001 From: Nathan Bossart Date: Thu, 15 Dec 2022 14:11:43 -0800 Subject: [PATCH v1 1/1] handle race condition when restarting wal receivers --- src/backend/postmaster/postmaster.c | 28 ++++++++++++++++++++++------ 1 file changed, 22 insertions(+), 6 deletions(-) diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c index eac3450774..9d6f58e0b3 100644 --- a/src/backend/postmaster/postmaster.c +++ b/src/backend/postmaster/postmaster.c @@ -1601,9 +1601,9 @@ checkControlFile(void) * * In normal conditions we wait at most one minute, to ensure that the other * background tasks handled by ServerLoop get done even when no requests are - * arriving. However, if there are background workers waiting to be started, - * we don't actually sleep so that they are quickly serviced. Other exception - * cases are as shown in the code. + * arriving. However, if there are background workers or a WAL receiver + * waiting to be started, we make sure they are quickly serviced. Other + * exception cases are as shown in the code. */ static void DetermineSleepTime(struct timeval *timeout) @@ -1611,11 +1611,12 @@ DetermineSleepTime(struct timeval *timeout) TimestampTz next_wakeup = 0; /* - * Normal case: either there are no background workers at all, or we're in - * a shutdown sequence (during which we ignore bgworkers altogether). + * Normal case: either there are no background workers and no WAL receiver + * at all, or we're in a shutdown sequence (during which we ignore + * bgworkers and the WAL receiver altogether). */ if (Shutdown > NoShutdown || - (!StartWorkerNeeded && !HaveCrashedWorker)) + (!StartWorkerNeeded && !HaveCrashedWorker && !WalReceiverRequested)) { if (AbortStartTime != 0) { @@ -1674,6 +1675,21 @@ DetermineSleepTime(struct timeval *timeout) } } + /* + * If WalReceiverRequested is set, we're probably waiting on a SIGCHLD to + * arrive to clear WalReceiverPID before starting the new WAL receiver. We + * don't expect that to take long, so limit the sleep to 100ms so that we + * start the new WAL receiver promptly. + */ + if (WalReceiverRequested) + { + TimestampTz walrcv_wakeup; + + walrcv_wakeup = TimestampTzPlusMilliseconds(GetCurrentTimestamp(), 100); + if (next_wakeup == 0 || walrcv_wakeup < next_wakeup) + next_wakeup = walrcv_wakeup; + } + if (next_wakeup != 0) { long secs; -- 2.25.1 --HcAYCG3uE/tztfnV--