Content-Type: multipart/mixed; boundary="------------KIkJ90WJZAbeAWAKSQ6EsR8V"
Message-ID: <092dd515-b7b4-4fd0-8407-ceca2f02f6ec@iki.fi>
Date: Thu, 8 Aug 2024 10:03:29 +0300
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
From: Heikki Linnakangas <hlinnaka@iki.fi>
Subject: Re: BUG #18575: Sometimes pg_rewind mistakenly assumes that nothing
 needs to be done.
To: g.shelkovy@arenadata.io, pgsql-bugs@lists.postgresql.org
References: <18575-1b9b3b60e2a480de@postgresql.org>
Content-Language: en-US
In-Reply-To: <18575-1b9b3b60e2a480de@postgresql.org>
Archived-At: 
 <https://www.postgresql.org/message-id/092dd515-b7b4-4fd0-8407-ceca2f02f6ec%40iki.fi>
Precedence: bulk

This is a multi-part message in MIME format.
--------------KIkJ90WJZAbeAWAKSQ6EsR8V
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit

On 07/08/2024 15:19, PG Bug reporting form wrote:
> Sometimes pg_rewind mistakenly assumes that nothing needs to be done, which
> results in the replica having data that is not on the master.
> 
> ...
> + pg_rewind --progress --debug '--source-pgdata=standby1'
> '--target-pgdata=standby2'
> pg_rewind: Source timeline history:
> pg_rewind: Target timeline history:
> pg_rewind: 1: 0/0 - 0/0
> pg_rewind: servers diverged at WAL location 0/10392E8 on timeline 1
> pg_rewind: no rewind required
>
> ...
> Same query
> + psql -d postgres -a --no-psqlrc -p 5001
> select count(*) from a;
>   count
> --------
>   100000
> (1 row)
> 
> + echo 'Different results'
> Different results
> + psql -d postgres -a --no-psqlrc -p 5002
> select count(*) from a;
>   count
> --------
>   100340
> (1 row)
> 
> + echo 'Stop standby1'
> Stop standby1
> + pg_ctl -w -D standby1 stop -m fast
> waiting for server to shut down....2024-08-07 17:15:03.077 +05 [19703]
> DEBUG:  logger shutting down
>   done
> server stopped
> + echo 'Stop standby2'
> Stop standby2
> + pg_ctl -w -D standby2 stop -m fast
> waiting for server to shut down....2024-08-07 17:15:03.117 +05 [19713]
> DEBUG:  logger shutting down
>   done
> server stopped
> ```

I cannot reproduce this. On my laptop, the reported "servers diverged at 
WAL location" is always higher, and it performs rewind as expected:

g_rewind: Source timeline history:
pg_rewind: Target timeline history:
pg_rewind: 1: 0/0 - 0/0
pg_rewind: servers diverged at WAL location 0/1138F00 on timeline 1
pg_rewind: rewinding from last common checkpoint at 0/1138E88 on timeline 1

However while looking at the code, I noticed that the debug-output of 
the Source timeline history is broken. See attached patch to fix it. 
With that fix, I get:

pg_rewind: Source timeline history:
pg_rewind: 1: 0/0 - 0/1138F00
pg_rewind: 2: 0/1138F00 - 0/0
pg_rewind: Target timeline history:
pg_rewind: 1: 0/0 - 0/0
pg_rewind: 0 a: 1 0/0-0/1138F00 - b: 1 0/0-0/0
pg_rewind: servers diverged at WAL location 0/1138F00 on timeline 1
pg_rewind: rewinding from last common checkpoint at 0/1138E88 on timeline 1

That just fixes the debugging output, though, it doesn't change what it 
actually does.

Can you try the attached fix show the output you get with that please? 
Or alternatively, show the contents of the 
standby1/pg_wal/00000002.history file.

-- 
Heikki Linnakangas
Neon (https://neon.tech)

--------------KIkJ90WJZAbeAWAKSQ6EsR8V
Content-Type: text/x-patch; charset=UTF-8;
 name="fix-print-debug-source-history.patch"
Content-Disposition: attachment;
 filename="fix-print-debug-source-history.patch"
Content-Transfer-Encoding: base64

ZGlmZiAtLWdpdCBhL3NyYy9iaW4vcGdfcmV3aW5kL3BnX3Jld2luZC5jIGIvc3JjL2Jpbi9w
Z19yZXdpbmQvcGdfcmV3aW5kLmMKaW5kZXggMDg0MWFiNDEzNS4uMGY5ZDM4YWJkNSAxMDA2
NDQKLS0tIGEvc3JjL2Jpbi9wZ19yZXdpbmQvcGdfcmV3aW5kLmMKKysrIGIvc3JjL2Jpbi9w
Z19yZXdpbmQvcGdfcmV3aW5kLmMKQEAgLTg5Miw5ICs4OTIsOSBAQCBnZXRUaW1lbGluZUhp
c3RvcnkoVGltZUxpbmVJRCB0bGksIGJvb2wgaXNfc291cmNlLCBpbnQgKm5lbnRyaWVzKQog
CQkJcGdfbG9nX2RlYnVnKCJUYXJnZXQgdGltZWxpbmUgaGlzdG9yeToiKTsKIAogCQkvKgot
CQkgKiBQcmludCB0aGUgdGFyZ2V0IHRpbWVsaW5lIGhpc3RvcnkuCisJCSAqIFByaW50IHRo
ZSB0aW1lbGluZSBoaXN0b3J5CiAJCSAqLwotCQlmb3IgKGkgPSAwOyBpIDwgdGFyZ2V0TmVu
dHJpZXM7IGkrKykKKwkJZm9yIChpID0gMDsgaSA8ICpuZW50cmllczsgaSsrKQogCQl7CiAJ
CQlUaW1lTGluZUhpc3RvcnlFbnRyeSAqZW50cnk7CiAK

--------------KIkJ90WJZAbeAWAKSQ6EsR8V--