Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1s55Nv-0034Pk-Pz for pgsql-general@arkaria.postgresql.org; Thu, 09 May 2024 15:08:40 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1s55Nu-008HgJ-6s for pgsql-general@arkaria.postgresql.org; Thu, 09 May 2024 15:08:38 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1s55Mf-008D7Y-5d for pgsql-general@lists.postgresql.org; Thu, 09 May 2024 15:07:22 +0000 Received: from fhigh6-smtp.messagingengine.com ([103.168.172.157]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1s55MZ-000CVy-Q1 for pgsql-general@postgresql.org; Thu, 09 May 2024 15:07:20 +0000 Received: from compute7.internal (compute7.nyi.internal [10.202.2.48]) by mailfhigh.nyi.internal (Postfix) with ESMTP id 85E3D11400B1; Thu, 9 May 2024 11:07:14 -0400 (EDT) Received: from mailfrontend2 ([10.202.2.163]) by compute7.internal (MEProxy); Thu, 09 May 2024 11:07:14 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=aklaver.com; h= cc:cc:content-transfer-encoding:content-type:content-type:date :date:from:from:in-reply-to:in-reply-to:message-id:mime-version :references:reply-to:subject:subject:to:to; s=fm2; t=1715267234; x=1715353634; bh=+Cnv5mF0ZlV8PNxdgMwJC3ix8YY5uUZToyMBZ0HuBQc=; b= h/V6o115fNnKP4VmqsnHwk2/+jNm0zfHsdD5MmCB62kjPtyBtIGenIoKbOJBB3kS XvlNV1KW2hISk0c3kHUj/TdtDiDgeGDT/UHkD9smOLjBctS791V9wRDoHn5Z3IOe bWbeL3LTmT/Cfgx3E09nnhaGcyfpwNKMrIK8S73yZVW4KRUEDG5zDoxFG6tONjO4 vmLattilfCRpDEwTp7/FCrqU3MhLzwebaXFodqXctpOQFY8gexjO0BgK1natFP2a lAXI/PFhdTrr231PJdl7iA83I1IFflaVhc5XWDvDeo7nHKz/QCB3OKOQe/OCl96n 8js6g979ERBrXbhokkIb7A== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d= messagingengine.com; h=cc:cc:content-transfer-encoding :content-type:content-type:date:date:feedback-id:feedback-id :from:from:in-reply-to:in-reply-to:message-id:mime-version :references:reply-to:subject:subject:to:to:x-me-proxy:x-me-proxy :x-me-sender:x-me-sender:x-sasl-enc; s=fm3; t=1715267234; x= 1715353634; bh=+Cnv5mF0ZlV8PNxdgMwJC3ix8YY5uUZToyMBZ0HuBQc=; b=Y vLtippWhRT/LMWY2UXiVe6eqNRX/BR6VhZWlbCP6JmTwiMqXL4LjPCNXsnB4eGii lBWzkVLdKAN/kiFeLd90erP/OKR5O/vUBbCBpDbkYQ57FitQEaMu6kAaswy1G4E9 +mMPdXEFkzvKMmqMO8ByMqUMP/K3+rqCK6bezNvTWTngL7pRSXD4gh+CCAyxHxQJ B2g6jrIPd88vTUeq50c/4Cz5LKr8Yq2ro345LH3sDhyp+8Fy4ycd/atqJRyGxRTp G/Wm3QBu+PqlzZI5bk3xKguwc6OvwZCbIwTDabCNUYoUGgFSHnjiggggtieM2fzr EDbitmFgn4U/fK8buCWmA== X-ME-Sender: X-ME-Received: X-ME-Proxy-Cause: gggruggvucftvghtrhhoucdtuddrgedvledrvdefvddgkeefucetufdoteggodetrfdotf fvucfrrhhofhhilhgvmecuhfgrshhtofgrihhlpdfqfgfvpdfurfetoffkrfgpnffqhgen uceurghilhhouhhtmecufedttdenucesvcftvggtihhpihgvnhhtshculddquddttddmne cujfgurhepkfffgggfuffvvehfhfgjtgfgsehtkeertddtvdejnecuhfhrohhmpeetughr ihgrnhcumfhlrghvvghruceorggurhhirghnrdhklhgrvhgvrhesrghklhgrvhgvrhdrtg homheqnecuggftrfgrthhtvghrnhepueegleektdegtdehtdejgfettedtvedtieffhfff udeulefhkeegtddvteelfffgnecuffhomhgrihhnpehpohhsthhgrhgvshhqlhdrohhrgh dpthhhvgdrnhgvthenucevlhhushhtvghrufhiiigvpedtnecurfgrrhgrmhepmhgrihhl fhhrohhmpegrughrihgrnhdrkhhlrghvvghrsegrkhhlrghvvghrrdgtohhm X-ME-Proxy: Feedback-ID: i76984098:Fastmail Received: by mail.messagingengine.com (Postfix) with ESMTPA; Thu, 9 May 2024 11:07:13 -0400 (EDT) Message-ID: Date: Thu, 9 May 2024 08:07:12 -0700 MIME-Version: 1.0 User-Agent: Mozilla Thunderbird Subject: Re: Unexpected data when subscribing to logical replication slot To: Daniel McKenzie , tomas.vondra@enterprisedb.com Cc: pgsql-general@postgresql.org References: <8a534c5f-e400-4bb5-b39e-2017d259ff06@aklaver.com> <10bcc03d-fa3e-40b6-bdd2-cac0acd046f4@aklaver.com> Content-Language: en-US From: Adrian Klaver In-Reply-To: Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk On 5/9/24 00:32, Daniel McKenzie wrote: > Asynchronous commit introduces the risk of data loss. There is a short > time window between the report of transaction completion to the client > and the time that the transaction is truly committed. > To get anywhere with this issue you will need to provide the information Tomas Vondra requested upstream: " Where/how does the enrichment query run? How does the whole process look like? I guess an application is receiving decoded changes as JSON, and then querying the database? " and " Would be good to have some sort of reproducer - ideally a script that sets up an instance + replication, and demonstrates the issue. Or at least a sufficiently detailed steps to reproduce it without having to guess what exactly you did. " > > The documentation speaks about synchronous_commit changing how > transactions change behaviour for the client. So in this case, my psql > terminal is the client, and I would expect a faster commit (from its > perspective) and then a period of risk (as a process usually done as > part of the commit is now being done in the background) but it's not > clear how that affects a replication slot subscriber. > > What we're struggling to understand is: why are we seeing any updates in > the replication slot before they have been "truly committed"? From: https://www.postgresql.org/docs/current/wal-async-commit.html "As described in the previous section, transaction commit is normally synchronous: the server waits for the transaction's WAL records to be flushed to permanent storage before returning a success indication to the client. The client is therefore guaranteed that a transaction reported to be committed will be preserved, even in the event of a server crash immediately after. However, for short transactions this delay is a major component of the total transaction time. Selecting asynchronous commit mode means that the server returns success as soon as the transaction is logically completed, before the WAL records it generated have actually made their way to disk. This can provide a significant boost in throughput for small transactions." It is about the state of the WAL record, in synchronous_commit=on the commit will not happen on the server and be seen by the client until the WAL record has been recorded as saved to disk. For synchronous_commit=off the commit happens as soon as COMMIT is reached in the transaction and the WAL record save happens after that. I don't use wal2json so I don't know how it deals with the above. > > There appears to be a state of limbo between updating data and that data > being available to query (and our subscriber is picking up changes in > this period of time) but I can't pin down any documentation which > describes it. The answer awaits a the full description of the process requested by Tomas Vondra. Best guess, the fact that synchronous_commit=off 'cures' it implies that in synchronous_commit=on mode you are picking up data on the receiving and sending end at different points in '... the server waits for the transaction's WAL records to be flushed to permanent storage before returning a success indication to the client.' > > We've had this running in live now for years without a hiccup so we are > surprised to learn that we have this massive race condition and it just I would not say "...perhaps 1 in 50 times" is massive. > so happens that the hardware is fast enough to process the transaction > before the .NET application can react to replication slot changes. > > Daniel McKenzie > Software Developer -- Adrian Klaver adrian.klaver@aklaver.com