Re: message log merge (streaming replication)

At Thu, 9 Jun 2022 16:26:24 +0900, Ian Lawrence Barwick <barwick(at)gmail(dot)com> wrote in
> 2022年6月9日(木) 14:32 Peter Adlersburg <peter(dot)adlersburg(at)gmail(dot)com>:
> >
> > Dear fellow DBA's,
> >
> >
> > While troubleshooting one of our production replication clusters (phys. streaming replication using the patroni framework)
> > I stumbled over a - at least for me - strange phenomenon in the postgres logs of the two cluster members:
> >
> > *** node-01 ***
> >
> > [postgres(at)db-node-01 main]$ grep 'LOG: database' postgresql-2022-06-05.log
> > time=2022-06-05 18:25:26 CEST, pid=1720 LOG: database system is shut down
> > time=2022-06-05 18:25:29 CEST, pid=3252374 LOG: database system was shut down at 2022-06-05 18:25:23 CEST
> > time=2022-06-05 18:25:31 CEST, pid=3252371 LOG: database system is ready to accept read only connections
> > time=2022-06-05 18:29:11 CEST, pid=3252371 LOG: database system is ready to accept connections
> > time=2022-06-05 18:32:01 CEST, pid=1816 LOG: database system was interrupted while in recovery at log time 2022-06-05 18:29:11 CEST
> > time=2022-06-05 18:32:03 CEST, pid=1813 LOG: database system is ready to accept read only connections
> > time=2022-06-05 19:00:26 CEST, pid=1813 LOG: database system is ready to accept connections
> >
> > *** node-02 ***
> >
> > [postgres(at)db-node-02 main]$ grep 'LOG: database' postgresql-2022-06-05.log
> > time=2022-06-05 18:25:26 CEST, pid=1720 LOG: database system is shut down
> > time=2022-06-05 18:25:29 CEST, pid=3252374 LOG: database system was shut down at 2022-06-05 18:25:23 CEST
> > time=2022-06-05 18:25:31 CEST, pid=3252371 LOG: database system is ready to accept read only connections
> > time=2022-06-05 18:29:11 CEST, pid=3252371 LOG: database system is ready to accept connections
> > time=2022-06-05 18:32:01 CEST, pid=1816 LOG: database system was interrupted while in recovery at log time 2022-06-05 18:29:11 CEST
> > time=2022-06-05 18:32:03 CEST, pid=1813 LOG: database system is ready to accept read only connections
> > time=2022-06-05 19:00:26 CEST, pid=1813 LOG: database system is ready to accept connections
> >
> > The output is by no means complete - I only kept the duplicate entries.
> >
> > My question:
> >
> > How is it possible that the error logs are 'merged' across the two database nodes?
>
> That's impossible to determine on the basis of the available information.
>
> How is logging set up? What kind of environments are the nodes running in?
> Is it possible they are able to write to a shared disk of some sort?
>
> > Are the message/error-logs also replicated?
>
> No.
>
> > Is this the intended behaviour?
>
> It's not typical behaviour, but I suppose it's conceivable someone designed
> such a setup for some reason.

If the node-02 is a replica of the node-01 or vise-versa, and the log
file is in $PGDATA, it's possible that pg_basebackup (or just cp)
copies in the server log file to the replica. In that case, the first
half of the log file of the day of taking the backup is taken over
from the primary and the last half differs.

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center