Re: AutoVacuum Behaviour Question - Mailing list pgsql-general

From Bruce McAlister
Subject Re: AutoVacuum Behaviour Question
Date
Msg-id 46820E3F.7010009@blueface.ie
Whole thread Raw
In response to Re: AutoVacuum Behaviour Question  (Alvaro Herrera <alvherre@commandprompt.com>)
Responses Re: AutoVacuum Behaviour Question  (Alvaro Herrera <alvherre@commandprompt.com>)
Re: AutoVacuum Behaviour Question  (Bruce McAlister <bruce.mcalister@blueface.ie>)
List pgsql-general
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 :)



pgsql-general by date:

Previous
From: "Ashish Karalkar"
Date:
Subject: Auto Vaccume- Time based
Next
From: Richard Huxton
Date:
Subject: Re: problem importing data with psql