Alvaro Herrera wrote:
> Bruce McAlister wrote:
>
>> I have just checked the pg_stat_all_tables in the pg_catalog schema and
>> I can see the index scans etc table values incrementing. The data in the
>> tables seems to be updating. Just an FYI, I've enabled manual vacuum
>> analyze runs on the blueface-service database up until we've found whats
>> going wrong here. The output from the select query you suggested is as
>> follows:
>>
>> datname | datconfig
>> -------------------------+-----------
>> postgres |
>> blueface-webmail |
> [etc]
>
> Ok so it's not that you manually disabled autovacuum. And pgstat is
> working on those databases. And all databases share the postgresql.conf
> autovacuum configuration.
>
Yes, thats correct, all those databases fall under a single
postgresql.conf configuration file.
>> I enabled the log_line_prefix option and put in a %p in the value, and I
>> only get the following output from the logs:
>>
>> Jun 26 23:46:07 bfiedb01 postgres[2836]: [ID 748848 local0.debug] [5-1]
>> 2836 DEBUG: autovacuum: processing database "blueface-crm"
>> Jun 26 23:47:32 bfiedb01 postgres[2863]: [ID 748848 local0.debug] [5-1]
>> 2863 DEBUG: autovacuum: processing database "blueface-crm"
>
> I assume that there is no other line for process 2836 before the line
> for process 2863. Can you recheck that?
>
No, there are no other lines between the two autovacuum runs. This is a
more recent snippet, straight from the log file, no modifications:
Jun 27 08:01:03 bfiedb01 postgres[15801]: [ID 748848 local0.debug] [5-1]
15801 DEBUG: autovacuum: processing database "blueface-crm"
Jun 27 08:02:57 bfiedb01 postgres[15826]: [ID 748848 local0.debug] [5-1]
15826 DEBUG: autovacuum: processing database "blueface-crm"
Jun 27 08:04:55 bfiedb01 postgres[15871]: [ID 748848 local0.debug] [5-1]
15871 DEBUG: autovacuum: processing database "blueface-crm"
> What does
> select datname, age(datfrozenxid) from pg_database;
> show?
>
select datname, age(datfrozenxid) from pg_database;
datname | age
-------------------------+-----------
postgres | 103837746
blueface-webmail | 103851569
blueface-billingreports | 103943960
blueface-service | 100002166
blueface-cards | 103948279
template1 | 103831712
template0 | 387945736
blueface-crmsupport | 103933017
blueface-qualmon | 103881267
asterisk-cdrgw | 103959639
hylafax | 103847354
thelab-sipswitch | 103827152
whitelabel-ibb | 103813843
whitelabel-pleasant | 103796261
whitelabel-rapid | 103791708
whitelabel-test | 103787680
whitelabel-worlddest | 103782784
blueface-crm | 441746613
blueface-billedcalls | 100127483
asterisk-cdr | 100004575
mysipswitch | 103842683
whitelabel-ice | 103805834
>
>> I've also just run a manual 'VACUUM ANALYZE FULL VERBOSE;' just to
>> ensure it goes through manually.
>
> And it does finish successfully?
>
Yes, the full vacuum completed successfully.
>
>> What does the DEBUG1 output of a normal autovacuum run look like in the
>> log file?
>
> Nothing interesting shows up:
>
> LOG: autovacuum: processing database "test1"
> LOG: autovacuum: processing database "test2"
>
> If you try with debug2, it looks a bit more interesting:
>
> LOG: autovacuum: processing database "test2"
> DEBUG: autovac: will VACUUM foo
> DEBUG: vacuuming "public.foo"
> DEBUG: "foo": removed 10000 row versions in 55 pages
> DETAIL: CPU 0.00s/0.00u sec elapsed 0.00 sec.
> DEBUG: "foo": found 10000 removable, 0 nonremovable row versions in 55 pages
> DETAIL: 0 dead row versions cannot be removed yet.
> There were 0 unused item pointers.
> 0 pages are entirely empty.
> CPU 0.00s/0.00u sec elapsed 0.00 sec.
> DEBUG: "foo": truncated 55 to 0 pages
> DETAIL: CPU 0.00s/0.00u sec elapsed 0.00 sec.
>
I will run with DEBUG2 for a while and see if my output looks anything
like this :)
>
> The only thing I can think of right now is that pgstats does not have
> entries for the other databases for some reason. How can that happen
> escapes me.
>
If you need any information to try and get to the bottom of it all, then
please let me know. It would be nice to return to autovacuum runs :)
