Re: BUG #16691: Autovacuum stops processing certain databases until postgresql rebooted

Hi, Dear PostgreSQL Developers.
We are still facing this issue.
We reboot the cluster every 5-7 days.Any help plz?

вт, 3 нояб. 2020 г. в 14:14, Max Vikharev <bm(dot)kinder(at)gmail(dot)com>:

> We are facing a problem right now.
>
> In logs we see that autovacuum is processing mostly one table in database
> in 1 second cycle
>
> automatic vacuum of table "DATABASE.pg_catalog.pg_shdepend"
>
> We did strace "postgres: autovacuum launcher". It tries to read from
> global/679366931 in cycle.
>
> open("global/679366931", O_RDWR) = 6
> lseek(6, 0, SEEK_END) = 16384
> kill(11798, SIGUSR1) = 0
> open("pg_stat_tmp/global.stat", O_RDONLY) = 7
> fstat(7, {st_mode=S_IFREG|0600, st_size=11292, ...}) = 0
> read(7, "\235\274\245\1\312\177n\322.V\2\0'\v\0\0\0\0\0\0\4U\0\0\0\0\0\0u\326\313\26"..., 4096) = 4096
> read(7, "iZ\272\17\344\0\0\0w\337\334}\343\0\0\0000\362\255\0\0\0\0\0\265\241\332\0\0\0\0\0"..., 4096) = 4096
> read(7, "\0\0\0\0\0\0\0\0\0\0\0\0U\2\0\0\0\0\0\0\0\0B\277\0\0\0\0\1\0\0\0"..., 4096) = 3100
> close(7) = 0
> sendto(11, "\1\0\0\0 \0\0\0\6\270v\322.V\2\0\346\26o\322.V\2\0\0\0\0\0\1\0\0\0", 32, 0, NULL, 0) = 32
> select(0, NULL, NULL, NULL, {0, 10000}) = ? ERESTARTNOHAND (To be restarted if no handler)
> --- SIGUSR2 {si_signo=SIGUSR2, si_code=SI_USER, si_pid=12052, si_uid=114} ---
> rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call)
> open("pg_stat_tmp/global.stat", O_RDONLY) = 7
> fstat(7, {st_mode=S_IFREG|0600, st_size=11292, ...}) = 0
> read(7, "\235\274\245\1z\270v\322.V\2\0'\v\0\0\0\0\0\0\4U\0\0\0\0\0\0u\326\313\26"..., 4096) = 4096
> read(7, "iZ\272\17\344\0\0\0w\337\334}\343\0\0\0000\362\255\0\0\0\0\0\265\241\332\0\0\0\0\0"..., 4096) = 4096
> read(7, "\0\0\0\0\0\0\0\0\0\0\0\0U\2\0\0\0\0\0\0\0\0B\277\0\0\0\0\1\0\0\0"..., 4096) = 3100
> close(7) = 0
> open("pg_stat_tmp/global.stat", O_RDONLY) = 7
> fstat(7, {st_mode=S_IFREG|0600, st_size=11292, ...}) = 0
> read(7, "\235\274\245\1z\270v\322.V\2\0'\v\0\0\0\0\0\0\4U\0\0\0\0\0\0u\326\313\26"..., 4096) = 4096
> read(7, "iZ\272\17\344\0\0\0w\337\334}\343\0\0\0000\362\255\0\0\0\0\0\265\241\332\0\0\0\0\0"..., 4096) = 4096
> read(7, "\0\0\0\0\0\0\0\0\0\0\0\0U\2\0\0\0\0\0\0\0\0B\277\0\0\0\0\1\0\0\0"..., 4096) = 3100
> close(7) = 0
> close(6) = 0
> open("global/679366931", O_RDWR) = 6
> lseek(6, 0, SEEK_END) = 16384
> open("pg_stat_tmp/global.stat", O_RDONLY) = 7
> fstat(7, {st_mode=S_IFREG|0600, st_size=11292, ...}) = 0
> read(7, "\235\274\245\1z\270v\322.V\2\0'\v\0\0\0\0\0\0\4U\0\0\0\0\0\0u\326\313\26"..., 4096) = 4096
> read(7, "iZ\272\17\344\0\0\0w\337\334}\343\0\0\0000\362\255\0\0\0\0\0\265\241\332\0\0\0\0\0"..., 4096) = 4096
> read(7, "\0\0\0\0\0\0\0\0\0\0\0\0U\2\0\0\0\0\0\0\0\0B\277\0\0\0\0\1\0\0\0"..., 4096) = 3100
> close(7) = 0
> open("pg_stat_tmp/global.stat", O_RDONLY) = 7
> fstat(7, {st_mode=S_IFREG|0600, st_size=11292, ...}) = 0
> read(7, "\235\274\245\1z\270v\322.V\2\0'\v\0\0\0\0\0\0\4U\0\0\0\0\0\0u\326\313\26"..., 4096) = 4096
> read(7, "iZ\272\17\344\0\0\0w\337\334}\343\0\0\0000\362\255\0\0\0\0\0\265\241\332\0\0\0\0\0"..., 4096) = 4096
> read(7, "\0\0\0\0\0\0\0\0\0\0\0\0U\2\0\0\0\0\0\0\0\0B\277\0\0\0\0\1\0\0\0"..., 4096) = 3100
> close(7) = 0
> epoll_create1(EPOLL_CLOEXEC) = 7
> epoll_ctl(7, EPOLL_CTL_ADD, 12, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=772071960, u64=94859419771416}}) = 0
> epoll_ctl(7, EPOLL_CTL_ADD, 9, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=772071984, u64=94859419771440}}) = 0
> close(7) = 0
> epoll_create1(EPOLL_CLOEXEC) = 7
> epoll_ctl(7, EPOLL_CTL_ADD, 12, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=772071960, u64=94859419771416}}) = 0
> epoll_ctl(7, EPOLL_CTL_ADD, 9, {EPOLLIN|EPOLLERR|EPOLLHUP, {u32=772071984, u64=94859419771440}}) = 0
> epoll_wait(7, 0x56462e04e260, 1, 554) = -1 EINTR (Interrupted system call)
>
> lsof
>
> postgres 12202 postgres 6u REG 8,3 16384 47329946 /var/lib/postgresql/12/alytics_main/global/679366931
> postgres 30607 postgres 239u REG 8,3 16384 47329946 /var/lib/postgresql/12/alytics_main/global/679366931
>
> DATABASE=# SELECT pg_relation_filepath('pg_database');
> pg_relation_filepath
> ----------------------
> global/679366931
>
>
> > It sounds like it's failing to advance that database's datfrozenxid
> > and/or datminmxid. You might try to figure out which table is holding
> > those values back by comparing pg_class.relfrozenxid and relminmxid
> > to those pg_database columns. Then look to see if autovacuum is
> > failing on that table, and/or try a manual vacuum to see what happens.
> We found tables with pg_database.datfrozenxid = pg_class.relfrozenxid or
> pg_database.datminmxid = pg_class.relminmxid. We executed "vacuum verbose"
> on that tables and it did the work correctly, in output we see that there
> were 0 dead tuples in all tables and there are logs with ERROR/WARNING log
> level.
>
> In postgresql logs we see that after pg_toast were vacuumed autovacuum
> started to process next tables
>
> 2020-11-03 12:54:31 MSK DATABASE [local] [38649]: [2] STATEMENT: vacuum verbose pg_toast.pg_toast_687578781;
> 2020-11-03 12:55:24 MSK DATABASE [local] [38649]: [4] STATEMENT: vacuum verbose pg_toast.pg_toast_687578787;
> 2020-11-03 12:56:10 MSK DATABASE [local] [38649]: [6] STATEMENT: vacuum verbose pg_toast.pg_toast_687578793;
> 2020-11-03 12:56:32 MSK DATABASE [local] [38649]: [8] STATEMENT: vacuum verbose pg_toast.pg_toast_687578799;
> 2020-11-03 12:59:50 MSK DATABASE [33266]: [2] LOG: automatic vacuum of table "DATABASE.public.another_table": index scans: 1
>
> But it still processes only one database in cycle. I mean that there are
> tables in other databases that should be processed and there are free
> autovacuum workers, but queued tables are not processed.
>
> вс, 1 нояб. 2020 г. в 20:01, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>:
>
>> Max Vikharev <bm(dot)kinder(at)gmail(dot)com> writes:
>> >> finishing that table and moving to another in the same database
>>
>> > Yes, that case. Vacuum processes relations in one database In cycle
>>
>> It sounds like it's failing to advance that database's datfrozenxid
>> and/or datminmxid. You might try to figure out which table is holding
>> those values back by comparing pg_class.relfrozenxid and relminmxid
>> to those pg_database columns. Then look to see if autovacuum is
>> failing on that table, and/or try a manual vacuum to see what happens.
>>
>> regards, tom lane
>>
>