Re: WAL-files is not removing authomaticaly

The situation didn't changes, WAL segments not removing automatically. The
streaming replication works fine, here is the log files:

from master:
2021-03-16 06:28:51.787 EET [94341] [walreceiver] [pgadmin] [[unknown]]
[2.2.2.2]DEBUG: write 145/ED10A8E8 flush 145/ED10A8E8 apply 145/ED10A8E8
2021-03-16 06:28:51.869 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64662 socket=11
2021-03-16 06:28:51.874 EET [40017] [] [] [] []DEBUG: server process (PID
64662) exited with exit code 0
2021-03-16 06:28:51.878 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64664 socket=11
2021-03-16 06:28:51.882 EET [40017] [] [] [] []DEBUG: server process (PID
64664) exited with exit code 0
2021-03-16 06:28:51.886 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64666 socket=11
2021-03-16 06:28:51.890 EET [40017] [] [] [] []DEBUG: server process (PID
64666) exited with exit code 0
2021-03-16 06:28:55.896 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64673 socket=11
2021-03-16 06:28:55.902 EET [40017] [] [] [] []DEBUG: server process (PID
64673) exited with exit code 0
2021-03-16 06:28:56.909 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64679 socket=11
2021-03-16 06:28:56.913 EET [40017] [] [] [] []DEBUG: server process (PID
64679) exited with exit code 0
2021-03-16 06:28:57.919 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64682 socket=11
2021-03-16 06:28:57.925 EET [40017] [] [] [] []DEBUG: server process (PID
64682) exited with exit code 0
2021-03-16 06:28:59.940 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64687 socket=11
2021-03-16 06:28:59.946 EET [40017] [] [] [] []DEBUG: server process (PID
64687) exited with exit code 0
2021-03-16 06:28:59.951 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64689 socket=11
2021-03-16 06:28:59.956 EET [40017] [] [] [] []DEBUG: server process (PID
64689) exited with exit code 0
2021-03-16 06:28:59.960 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64691 socket=11
2021-03-16 06:28:59.964 EET [40017] [] [] [] []DEBUG: server process (PID
64691) exited with exit code 0
2021-03-16 06:28:59.968 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64693 socket=11
2021-03-16 06:28:59.973 EET [40017] [] [] [] []DEBUG: server process (PID
64693) exited with exit code 0
2021-03-16 06:28:59.977 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64695 socket=11
2021-03-16 06:28:59.980 EET [40017] [] [] [] []DEBUG: server process (PID
64695) exited with exit code 0
2021-03-16 06:28:59.984 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64697 socket=11
2021-03-16 06:28:59.987 EET [40017] [] [] [] []DEBUG: server process (PID
64697) exited with exit code 0
2021-03-16 06:28:59.990 EET [40017] [] [] [] []DEBUG: forked new backend,
pid=64700 socket=11
2021-03-16 06:28:59.993 EET [40017] [] [] [] []DEBUG: server process (PID
64700) exited with exit code 0
2021-03-16 06:29:00.820 EET [40024] [] [] [] []DEBUG: received inquiry for
database 0
2021-03-16 06:29:00.820 EET [40024] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:29:00.820 EET [40024] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:29:00.833 EET [64702] [] [] [] []DEBUG: autovacuum:
processing database "postgres"
2021-03-16 06:29:00.833 EET [40024] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:29:00.833 EET [40024] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:29:00.833 EET [40024] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:29:00.833 EET [40024] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:29:00.845 EET [40017] [] [] [] []DEBUG: server process (PID
64702) exited with exit code 0
2021-03-16 06:29:01.810 EET [94341] [walreceiver] [pgadmin] [[unknown]]
[2.2.2.2]DEBUG: write 145/ED10A8E8 flush 145/ED10A8E8 apply 145/ED10A8E8

from slave:
2021-03-16 06:31:41.115 EET [97581] [] [] [] []DEBUG: checkpointer updated
shared memory configuration values
2021-03-16 06:31:42.456 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35706 socket=11
2021-03-16 06:31:42.466 EET [97575] [] [] [] []DEBUG: server process (PID
35706) exited with exit code 0
2021-03-16 06:31:42.474 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35708 socket=11
2021-03-16 06:31:42.483 EET [97575] [] [] [] []DEBUG: server process (PID
35708) exited with exit code 0
2021-03-16 06:31:42.493 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35710 socket=11
2021-03-16 06:31:42.501 EET [97575] [] [] [] []DEBUG: server process (PID
35710) exited with exit code 0
2021-03-16 06:31:48.310 EET [97585] [] [] [] []DEBUG: sending write
145/ED1310C8 flush 145/ED1310C8 apply 145/ED1310C8 (reply requested)
2021-03-16 06:31:48.310 EET [97585] [] [] [] []DEBUG: sendtime 2021-03-16
06:31:48.310858+02 receipttime 2021-03-16 06:31:48.310745+02 replication
apply delay 0 ms transfer latency 0 ms
2021-03-16 06:31:48.951 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35721 socket=11
2021-03-16 06:31:48.961 EET [97575] [] [] [] []DEBUG: server process (PID
35721) exited with exit code 0
2021-03-16 06:31:52.772 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35728 socket=11
2021-03-16 06:31:52.778 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:31:52.778 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:31:52.778 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:31:52.778 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:31:52.793 EET [97575] [] [] [] []DEBUG: server process (PID
35728) exited with exit code 0
2021-03-16 06:31:52.799 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35730 socket=11
2021-03-16 06:31:52.806 EET [97575] [] [] [] []DEBUG: server process (PID
35730) exited with exit code 0
2021-03-16 06:31:53.816 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35733 socket=11
2021-03-16 06:31:53.821 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:31:53.821 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:31:53.821 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:31:53.821 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:31:53.835 EET [97575] [] [] [] []DEBUG: server process (PID
35733) exited with exit code 0
2021-03-16 06:31:53.842 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35735 socket=11
2021-03-16 06:31:53.850 EET [97575] [] [] [] []DEBUG: server process (PID
35735) exited with exit code 0
2021-03-16 06:31:53.858 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35737 socket=11
2021-03-16 06:31:53.866 EET [97575] [] [] [] []DEBUG: server process (PID
35737) exited with exit code 0
2021-03-16 06:31:57.183 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35744 socket=11
2021-03-16 06:31:57.190 EET [97575] [] [] [] []DEBUG: server process (PID
35744) exited with exit code 0
2021-03-16 06:31:58.333 EET [97585] [] [] [] []DEBUG: sending write
145/ED1310C8 flush 145/ED1310C8 apply 145/ED1310C8
2021-03-16 06:31:59.658 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35747 socket=11
2021-03-16 06:31:59.663 EET [35747] [[unknown]] [user_user] [database]
[172.16.2.35]DEBUG: parse <unnamed>: show transaction_read_only
2021-03-16 06:31:59.663 EET [35747] [[unknown]] [user_user] [database]
[172.16.2.35]DEBUG: bind <unnamed> to <unnamed>
2021-03-16 06:31:59.666 EET [97575] [] [] [] []DEBUG: server process (PID
35747) exited with exit code 0
2021-03-16 06:32:03.897 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35753 socket=11
2021-03-16 06:32:03.901 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:32:03.901 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:32:03.901 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:32:03.901 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:32:03.915 EET [97575] [] [] [] []DEBUG: server process (PID
35753) exited with exit code 0
2021-03-16 06:32:07.924 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35760 socket=11
2021-03-16 06:32:07.928 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:32:07.928 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:32:07.928 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:32:07.928 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:32:07.941 EET [97575] [] [] [] []DEBUG: server process (PID
35760) exited with exit code 0
2021-03-16 06:32:07.953 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35762 socket=11
2021-03-16 06:32:07.964 EET [97575] [] [] [] []DEBUG: server process (PID
35762) exited with exit code 0
2021-03-16 06:32:07.973 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35764 socket=11
2021-03-16 06:32:07.983 EET [97575] [] [] [] []DEBUG: server process (PID
35764) exited with exit code 0
2021-03-16 06:32:08.355 EET [97585] [] [] [] []DEBUG: sending write
145/ED1310C8 flush 145/ED1310C8 apply 145/ED1310C8
2021-03-16 06:32:16.557 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35768 socket=11
2021-03-16 06:32:16.562 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:32:16.562 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:32:16.562 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:32:16.562 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:32:16.575 EET [97575] [] [] [] []DEBUG: server process (PID
35768) exited with exit code 0
2021-03-16 06:32:17.583 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35770 socket=11
2021-03-16 06:32:17.587 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:32:17.587 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:32:17.587 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:32:17.588 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:32:17.601 EET [97575] [] [] [] []DEBUG: server process (PID
35770) exited with exit code 0
2021-03-16 06:32:18.377 EET [97585] [] [] [] []DEBUG: sending write
145/ED1310C8 flush 145/ED1310C8 apply 145/ED1310C8 (reply requested)
2021-03-16 06:32:18.378 EET [97585] [] [] [] []DEBUG: sendtime 2021-03-16
06:32:18.378397+02 receipttime 2021-03-16 06:32:18.378306+02 replication
apply delay 0 ms transfer latency 0 ms
2021-03-16 06:32:20.419 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35773 socket=11
2021-03-16 06:32:20.428 EET [97575] [] [] [] []DEBUG: server process (PID
35773) exited with exit code 0
2021-03-16 06:32:20.995 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35775 socket=11
2021-03-16 06:32:21.000 EET [97583] [] [] [] []DEBUG: received inquiry for
database 13212
2021-03-16 06:32:21.000 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/global.stat"
2021-03-16 06:32:21.000 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_13212.stat"
2021-03-16 06:32:21.000 EET [97583] [] [] [] []DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
2021-03-16 06:32:21.013 EET [97575] [] [] [] []DEBUG: server process (PID
35775) exited with exit code 0
2021-03-16 06:32:21.021 EET [97575] [] [] [] []DEBUG: forked new backend,
pid=35777 socket=11

чт, 11 мар. 2021 г. в 11:18, Laurenz Albe <laurenz(dot)albe(at)cybertec(dot)at>:

> On Thu, 2021-03-11 at 09:43 +0200, Andrew Anderson wrote:
> > > Never, ever, remove WAL files manually.
> > > A crash might render your database unrecoverable.
> > You're right, it's not a good idea.
> >
> > > You'll have to figure out what is blocking WAL removal.
> > This is my favorite dream!
> >
> > > Are there archive failures reported in "pg_stat_archiver" and the log?
> > master=# select * from pg_stat_archiver;
> > archived_count | last_archived_wal | last_archived_time
> | failed_count | last_failed_wal | last_failed_time |
> stats_reset
> >
> ----------------+--------------------------+-------------------------------+--------------+-----------------+------------------+------------------------------
> > 3021 | 000000010000000B000000C9 | 2021-03-11
> 08:53:56.133796+02 | 0 | | |
> 2021-01-06 14:33:40.70147+02
> > (1 row)
> >
> > In today's logs there is no any errors:
> > $ grep "FATAL\|WARNING" /opt/pglogs/master.log
> > $
> >
> > $ grep "FATAL\|WARNING" /opt/pglogs/slave.log
> > $
> >
> > > You say that replication is working fine, but try
> > >
> > > SELECT pg_current_wal_lsn();
> > >
> > > on the primary and compare that with the "restart_lsn" of the
> replication slot.
> >
> > It parameters is differ:
> > master=# SELECT pg_current_wal_lsn();
> > pg_current_wal_lsn
> > --------------------
> > B/CB099398
> > (1 row)
> >
> > master=# select * from pg_replication_slots;
> > slot_name | plugin | slot_type | datoid | database |
> temporary | active | active_pid | xmin | catalog_xmin | restart_lsn |
> confirmed_flush_lsn
> >
> ----------------------+--------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
> > standby_slot | | physical | | | f | t
> | 2631806 | | | B/CB0AC068 |
> > (1 row)
> >
> > But when I add new data to the table on master, it apears on slave.
> >
> > > Look for strange messages in the log file on both servers.
> > Looking for strange messages gives nothing, in today's logs there is no
> any strange messages, just about connects of applications.
>
> All that looks fine.
>
> If that happens again, set "log_min_messages" to "debug2".
> Then the log file will contain information abotu the WAL segments that
> PostgreSQL is trying to remove. That might give you some insight.
>
> Yours,
> Laurenz Albe
> --
> Cybertec | https://www.cybertec-postgresql.com
>
>