BUG #16799: postgresql log issue(last completed transaction was at log time)

Started by PG Bug reporting formover 5 years ago4 messagesbugs
Jump to latest
#1PG Bug reporting form
noreply@postgresql.org

The following bug has been logged on the website:

Bug reference: 16799
Logged by: oleg9301
Email address: oleg9301@gmail.com
PostgreSQL version: 12.5
Operating system: debian 10
Description:

OS:Linux hostname 4.19.0-12-amd64 #1 SMP Debian 4.19.152-1 (2020-10-18)
x86_64 GNU/Linux (debian 10)

After recovering postgresql from barman, in version 12.5 I don't have next
string
"last completed transaction was at log time %s"
In postgresql 11.9-1.pgdg100+1 everything fine.

2020-12-31 17:37:25.529 MSK [25753] LOG: starting PostgreSQL 12.5 (Debian
12.5-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6)
8.3.0, 64-bit
2020-12-31 17:37:25.529 MSK [25753] LOG: listening on IPv4 address
"127.0.0.1", port 5432
2020-12-31 17:37:25.530 MSK [25753] LOG: listening on Unix socket
"/var/run/postgresql/.s.PGSQL.5432"
2020-12-31 17:37:25.575 MSK [25755] LOG: database system was interrupted;
last known up at 2020-12-31 15:10:34 MSK
2020-12-31 17:37:25.600 MSK [25755] LOG: redo starts at 11/E9000028
2020-12-31 17:37:25.608 MSK [25755] LOG: consistent recovery state reached
at 11/E904C2D8
2020-12-31 17:37:26.342 MSK [25755] LOG: redo done at 11/EFFFFF50
2020-12-31 17:37:26.656 MSK [25753] LOG: database system is ready to accept
connections

#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: PG Bug reporting form (#1)
Re: BUG #16799: postgresql log issue(last completed transaction was at log time)

PG Bug reporting form <noreply@postgresql.org> writes:

After recovering postgresql from barman, in version 12.5 I don't have next
string
"last completed transaction was at log time %s"
In postgresql 11.9-1.pgdg100+1 everything fine.

I don't see any reason to believe there's a bug here. That message
would only appear if at least one transaction commit or abort record was
replayed from WAL, and it's quite possible there wouldn't have been.

regards, tom lane

#3oleg9301 xz
oleg9301@gmail.com
In reply to: Tom Lane (#2)
Re: BUG #16799: postgresql log issue(last completed transaction was at log time)

There is always transations to commit, I(barman) do pg_basebackup once a
day, and recieve wal with pg_receivewal(standby slot). And everything is
fine, i have all data on OLAP DB(restore 6 times in day)
(all WAL files playing correctly).

чт, 31 дек. 2020 г. в 18:21, Tom Lane <tgl@sss.pgh.pa.us>:

Show quoted text

PG Bug reporting form <noreply@postgresql.org> writes:

After recovering postgresql from barman, in version 12.5 I don't have

next

string
"last completed transaction was at log time %s"
In postgresql 11.9-1.pgdg100+1 everything fine.

I don't see any reason to believe there's a bug here. That message
would only appear if at least one transaction commit or abort record was
replayed from WAL, and it's quite possible there wouldn't have been.

regards, tom lane

#4Tom Lane
tgl@sss.pgh.pa.us
In reply to: oleg9301 xz (#3)
Re: BUG #16799: postgresql log issue(last completed transaction was at log time)

oleg9301 xz <oleg9301@gmail.com> writes:

чт, 31 дек. 2020 г. в 18:21, Tom Lane <tgl@sss.pgh.pa.us>:

PG Bug reporting form <noreply@postgresql.org> writes:

After recovering postgresql from barman, in version 12.5 I don't have
next string
"last completed transaction was at log time %s"
In postgresql 11.9-1.pgdg100+1 everything fine.

I don't see any reason to believe there's a bug here. That message
would only appear if at least one transaction commit or abort record was
replayed from WAL, and it's quite possible there wouldn't have been.

There is always transations to commit, I(barman) do pg_basebackup once a
day, and recieve wal with pg_receivewal(standby slot). And everything is
fine, i have all data on OLAP DB(restore 6 times in day)
(all WAL files playing correctly).

Hmm. I poked a bit into the code, and I see what is different in v12:
commit 7acf8a876 ("Make crash recovery ignore recovery target settings")
caused all of recoveryStopsAfter() to be skipped when
!ArchiveRecoveryRequested ... including the part that updates
recoveryLastXTime.

Fujii-san, Peter, was that actually intended? The commit message
doesn't mention it. It's certainly arguable that this is cosmetic
and we don't care enough to contort the code to keep the old behavior
here.

regards, tom lane