Обсуждение: help me understand logs

Поиск
Список
Период
Сортировка

help me understand logs

От
Scott Ribe
Дата:
What does this mean?

waiting for server to start....2022-05-10 02:31:15.580 GMT [181072] LOG: starting PostgreSQL 13.3 on
x86_64-pc-linux-gnu,compiled by gcc (GCC) 8.4.1 20200928 (Red Hat 8.4.1-1), 64-bit 
2022-05-10 02:31:15.580 GMT [181072] LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-05-10 02:31:15.584 GMT [181072] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-05-10 02:31:15.591 GMT [181072] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-05-10 02:31:19.306 GMT [181073] LOG: database system was interrupted; last known up at 2022-05-09 18:41:34 GMT
...........................................................2022-05-10 02:32:18.265 GMT [181073] LOG: entering standby
mode
......2022-05-10 02:32:23.784 GMT [181073] LOG: redo starts at 1985D/BA000028
2022-05-10 02:32:24.293 GMT [181073] WARNING: xlog min recovery request 19872/13105450 is past current point
1985D/BD719420
2022-05-10 02:32:24.293 GMT [181073] CONTEXT: writing block 10 of relation base/16438/120873453_vm
WAL redo at 1985D/BD7183C0 for Btree/VACUUM: ndeleted 92; nupdated 0
.2022-05-10 02:32:24.911 GMT [181073] WARNING: xlog min recovery request 19872/13105450 is past current point
1985D/C2460B80
2022-05-10 02:32:24.911 GMT [181073] CONTEXT: writing block 10 of relation base/16438/120873453_vm
WAL redo at 1985D/C245EE00 for Btree/INSERT_LEAF: off 169
2022-05-10 02:32:25.180 GMT [181073] WARNING: xlog min recovery request 19872/1412BD60 is past current point
1985D/C3B490C8
2022-05-10 02:32:25.180 GMT [181073] CONTEXT: writing block 12 of relation base/16438/120873453_vm
WAL redo at 1985D/C3B470A0 for Heap/LOCK: off 1: xid 3439094334: flags 0x00 LOCK_ONLY EXCL_LOCK KEYS_UPDATED
2022-05-10 02:32:25.397 GMT [181073] WARNING: xlog min recovery request 19872/13105450 is past current point
1985D/C4D210D0
2022-05-10 02:32:25.397 GMT [181073] CONTEXT: writing block 10 of relation base/16438/120873453_vm
WAL redo at 1985D/C4D21088 for Btree/INSERT_LEAF: off 61
... and so on, been going on for a while now

This is an alleged file copy of a pg_basebackup

--
Scott Ribe
scott_ribe@elevated-dev.com
https://www.linkedin.com/in/scottribe/






Re: help me understand logs

От
Scott Ribe
Дата:
> On May 9, 2022, at 8:45 PM, Scott Ribe <scott_ribe@elevated-dev.com> wrote:
>
> What does this mean?

It means I logged into the wrong container and started a second PG instance against a data directory?


Re: help me understand logs

От
"David G. Johnston"
Дата:
On Mon, May 9, 2022 at 7:45 PM Scott Ribe <scott_ribe@elevated-dev.com> wrote:
What does this mean?

waiting for server to start....2022-05-10 02:31:15.580 GMT [181072] LOG: starting PostgreSQL 13.3 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 8.4.1 20200928 (Red Hat 8.4.1-1), 64-bit
2022-05-10 02:31:15.580 GMT [181072] LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-05-10 02:31:15.584 GMT [181072] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-05-10 02:31:15.591 GMT [181072] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-05-10 02:31:19.306 GMT [181073] LOG: database system was interrupted; last known up at 2022-05-09 18:41:34 GMT
...........................................................2022-05-10 02:32:18.265 GMT [181073] LOG: entering standby mode
......2022-05-10 02:32:23.784 GMT [181073] LOG: redo starts at 1985D/BA000028
2022-05-10 02:32:24.293 GMT [181073] WARNING: xlog min recovery request 19872/13105450 is past current point 1985D/BD719420
2022-05-10 02:32:24.293 GMT [181073] CONTEXT: writing block 10 of relation base/16438/120873453_vm
WAL redo at 1985D/BD7183C0 for Btree/VACUUM: ndeleted 92; nupdated 0

... and so on, been going on for a while now

This is an alleged file copy of a pg_basebackup


I think you've managed to restore a functioning warm standby that found some WAL to process and proceeded to do so.

If you want to bring the server backup in non-standby mode you will need to remove the stuff that is making it be a standby.  I don't know that stuff off the top of my head and it also has recently changed.  The v13 documentation will be more useful than I for those specifics.

I don't know what the warnings are - they read like something that should crash the server...

David J.

Re: help me understand logs

От
Scott Ribe
Дата:
> On May 9, 2022, at 8:53 PM, David G. Johnston <david.g.johnston@gmail.com> wrote:
>
> I think you've managed to restore a functioning warm standby that found some WAL to process and proceeded to do so.

Yes, that is exactly what I was doing.

> If you want to bring the server backup in non-standby mode you will need to remove the stuff that is making it be a
standby. I don't know that stuff off the top of my head and it also has recently changed.  The v13 documentation will
bemore useful than I for those specifics. 
>
> I don't know what the warnings are - they read like something that should crash the server...

I'd not noticed those messages before. Reviewing another instance, I did see a few before it started into what I
recognizeas the "normal" sequence of applying WAL. 

My subsequent theory about confusing containers and starting a second PG instance, was itself the result of confusion,
andI had not done that after all. 

On a second try, it did the same thing, I left it alone, and it eventually came up.

I'd still like to understand what those warnings are, and why I usually see only a handful followed by a lot of
messagesabout WAL having applied, but this instance I see a lot of these, and then the server claims all is good
withouta log of those messages about WAL being applied.