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 1s4yGq-002Io8-2D for pgsql-general@arkaria.postgresql.org; Thu, 09 May 2024 07:32:52 +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 1s4yGo-005QaQ-A3 for pgsql-general@arkaria.postgresql.org; Thu, 09 May 2024 07:32:50 +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 1s4yGn-005QaI-TK for pgsql-general@lists.postgresql.org; Thu, 09 May 2024 07:32:50 +0000 Received: from mail-yb1-xb2c.google.com ([2607:f8b0:4864:20::b2c]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.94.2) (envelope-from ) id 1s4yGk-0009J7-VG for pgsql-general@postgresql.org; Thu, 09 May 2024 07:32:49 +0000 Received: by mail-yb1-xb2c.google.com with SMTP id 3f1490d57ef6-de8b66d1726so1412909276.0 for ; Thu, 09 May 2024 00:32:47 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=curvedental.com; s=google; t=1715239966; x=1715844766; darn=postgresql.org; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:from:to:cc:subject:date:message-id:reply-to; bh=tGu3TMgpAoJhkVSB9+/rWM+KV8RkalmOldkeOBvJjho=; b=KvVIxP7HUUH7DeH30S5xfHWgwa6vAL01liLJRaIGURt3faY4u/obwmoODhv5mctRRL OSCO5+Yyq+oTgKtrL/bl1stRYZQYYPLh76T7kxz1LO+bo79HI7zJnc8SzT1Da32pD9PH dVsVH58Qrxm7D9tOVdtY9XhU6tntlXEmAcgmk= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1715239966; x=1715844766; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=tGu3TMgpAoJhkVSB9+/rWM+KV8RkalmOldkeOBvJjho=; b=tWnej5E8Dy/pXlx9e7Q54kprOf8USrLJf4s0O/OQ05W9g2/vPOF2EEm8/B6Ms6ULek LW7dHNe+biSpF2sbaq/6pbLrrLtYYGQzHf0tVzNyOHHpTBe3M6wdz77D4dgRbl5UfSpt mhcOiJKZh+wPx8Avx7sJo2lgmMGJFiSTDInLMazx/nHxzvQjyxnw9cQlOFna8eA7VvUJ spB90nPBbAbbYcX/4oTq5IFF0nC7H8gubDdfB0b8hJb97OuDRGLpfvZaDWRZu2p1+mQm M0Npr9oO5LunxO7hzSi+gp+nvdgO/R06vTAL+jTSVJO9HBhsqBrxdeOA/O0ZfRd7ZYOT hxAg== X-Gm-Message-State: AOJu0YxZPWOabOfbSbthuAk66aUwacV9XLNhsXQ1FJcJ8MnfYsrVYiML X+RP0PD5g22Vgf4jhD4Cw6wco9iBOoTBDPfYrEup2ojLJHy7c/Xen9C7t1CrG2E9Cutqsa31wnh msD0WqwDcNpXih6MQmsfMRg8icQXZ0cF7y6TI4XLyM5QXAAmB5OmfLjA= X-Google-Smtp-Source: AGHT+IF+vJg2p+nAn9r9uPFT8q/VlwvebzkTwzCHkMM5P120pRU9Cwfi4DEQVf4XF9WUePlAOtl89/8wXilQDFDLMYQ= X-Received: by 2002:a05:6902:2301:b0:deb:45e3:b0f9 with SMTP id 3f1490d57ef6-debcfc3559amr1563440276.29.1715239965942; Thu, 09 May 2024 00:32:45 -0700 (PDT) MIME-Version: 1.0 References: <8a534c5f-e400-4bb5-b39e-2017d259ff06@aklaver.com> <10bcc03d-fa3e-40b6-bdd2-cac0acd046f4@aklaver.com> In-Reply-To: <10bcc03d-fa3e-40b6-bdd2-cac0acd046f4@aklaver.com> From: Daniel McKenzie Date: Thu, 9 May 2024 08:32:36 +0100 Message-ID: Subject: Re: Unexpected data when subscribing to logical replication slot To: Adrian Klaver , tomas.vondra@enterprisedb.com Cc: pgsql-general@postgresql.org Content-Type: multipart/alternative; boundary="000000000000dfffd40618006cb2" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --000000000000dfffd40618006cb2 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable > > 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. 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"? 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. 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 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 Office: +1 403.910.5927 x 251 Mobile: +44 7712 159045 Website: www.curvedental.com *Curve Dental Confidentiality Notice* This message is intended exclusively for the individual or entity to which it is addressed. This communication may contain information that is proprietary, privileged, confidential, or otherwise legally exempt from disclosure. If you are not the named addressee, you are not authorized to read, print, retain, copy, or disseminate this message or any part of it. If you have received this message in error, please notify the sender immediately by replying to this e-mail and delete all copies of this message. On Wed, May 8, 2024 at 5:28=E2=80=AFPM Adrian Klaver wrote: > On 5/8/24 08:24, Daniel McKenzie wrote: > > It's running both (in docker containers) and also quite a few more > > docker containers running various .NET applications. > > I think what you found is that the r7a.medium instance is not capable > enough to do all that it is asked without introducing lag under load. > Answering the questions posed by Tomas Vondra would help get to the > actual cause of the lag. > > In meantime my suspicion is this part: > > "For example, when I use a psql terminal to update a user's last name > from "Jones" to "Smith" then I would expect the enrichment query to find > "Smith" but it will sometimes still find "Jones". It finds the old data > perhaps 1 in 50 times." > > If this is being run against the Postgres server my guess is that > synchronous_commit=3Don is causing the commit on the server to wait for > the WAL records to be flushed to disk and this is not happening in a > timely manner in the '... 1 in 50 times' you mention. In that case you > see the old values not the new committed values. This seems to be > confirmed when you set synchronous_commit=3Doff and don't see old values. > For completeness per: > > https://www.postgresql.org/docs/current/wal-async-commit.html > > "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. > > 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 (that is, it is > guaranteed not to be lost if the server crashes). ... > " > > > > > Daniel McKenzie > > Software Developer > > -- > Adrian Klaver > adrian.klaver@aklaver.com > > --000000000000dfffd40618006cb2 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Asynchro= nous commit introduces the risk of data loss. There is a short
time wind= ow between the report of transaction completion to the client
and the ti= me that the transaction is truly committed.

The documentation speaks about=C2=A0synchronous_commit changing how t= ransactions change behaviour for the client. So in this case, my psql termi= nal 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 commi= t is now being done in the background) but it's not clear how that affe= cts a replication slot subscriber.

What= we're struggling to understand is: why are we seeing any updates in th= e replication slot before they have been "truly committed"?

There appears to be a state of limbo between updati= ng data and that data being available to query (and our subscriber is picki= ng up changes in this period of time) but I can't pin down any document= ation which describes it.

We've had this= running in live now for years without a hiccup so we are surprised to lear= n that we have this massive race condition and it just so happens that the = hardware is fast enough to process the transaction before the .NET applicat= ion can react to replication slot changes.

Daniel McKenzie
Software Developer

= Office: +1 403.910.5927 x 251
Mobil= e: +44 7712 159045
Website:=C2=A0www.curvedental.com=

Curve Dental Confid= entiality Notice
This message is = intended exclusively for the individual or entity to which it is addressed.= This communication may=C2=A0conta= in information that is proprietary, privileged, confidential, or otherwise = legally exempt from disclosure. If you are=C2=A0not the named addressee, you are not authorized to read, prin= t, retain, copy, or disseminate this message or any=C2=A0part of it. If you have received this message in err= or, please notify the sender immediately by replying to this e-mail=C2=A0and delete all copies of this messag= e.


On Wed, May 8, 2024 at 5:2= 8=E2=80=AFPM Adrian Klaver <adrian.klaver@aklaver.com> wrote:
On 5/8/24 08:24, Daniel McKenzie wrote:
> It's running both (in docker containers) and also quite a few more=
> docker containers running various .NET applications.

I think what you found is that the r7a.medium instance is not capable
enough to do all that it is asked without introducing lag under load.
Answering the questions posed by Tomas Vondra would help get to the
actual cause of the lag.

In meantime my suspicion is this part:

"For example, when I use a psql terminal to update a user's last n= ame
from "Jones" to "Smith" then I would expect the enrichm= ent query to find
"Smith" but it will sometimes still find "Jones". It fi= nds the old data
perhaps 1 in 50 times."

If this is being run against the Postgres server my guess is that
synchronous_commit=3Don is causing the commit on the server to wait for the WAL records to be flushed to disk and this is not happening in a
timely manner in the '... 1 in 50 times' you mention. In that case = you
see the old values not the new committed values. This seems to be
confirmed when you set synchronous_commit=3Doff and don't see old value= s.
For completeness per:

https://www.postgresql.org/docs/current= /wal-async-commit.html

"However, for short transactions this delay is a major component of th= e
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.

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 (that is, it is
guaranteed not to be lost if the server crashes).=C2=A0 ...
"

>
> Daniel McKenzie
> Software Developer

--
Adrian Klaver
adrian.klave= r@aklaver.com

--000000000000dfffd40618006cb2--