Re: Something Weird Going on with VACUUM ANALYZE

Shaun Thomas wrote:
> This is PostgreSQL 9.1.9.
>
> So we've had "vacuumdb -avz" launched via cron at 3am for a few years
> now, and recently noticed some queries behaving very badly. While
> checking pg_stat_user_tables, I see this for several hundred of them:
>
> relname | last_analyze
> ---------------------+----------------------------------
> some_table | 13-SEP-13 03:27:13.289291 -05:00
> another_table | 13-SEP-13 03:33:51.262007 -05:00
> yet_another_table | 13-SEP-13 03:23:27.630734 -05:00
>
> Yet last_vacuum shows this:
>
> relname | last_vacuum
> --------------------+----------------------------------
> some_table | 17-SEP-13 03:23:41.84311 -05:00
> another_table | 17-SEP-13 03:21:25.588267 -05:00
> yet_another_table | 17-SEP-13 03:21:28.944848 -05:00
>
> So I thought to myself, "Self, that's pretty freaking odd." The last
> vacuumdb (with analyze flag enabled) was this morning at 3am.
>
> Apparently something magical happened last Friday, and now analyze is
> broken somehow? Am I missing something, here? The log claims everything
> worked out OK:
>
> 2013-09-17 03:20:37 CDT|STATEMENT: VACUUM (VERBOSE, ANALYZE);
> 2013-09-17 03:37:31 CDT|LOG: duration: 2246467.567 ms statement:
> VACUUM (VERBOSE, ANALYZE);

It does sound odd.

What happens if you run VACUUM (VERBOSE, ANALYZE) manually?
Are the statistics updated?
Are there any warnings?

> These are from the same pid doing the vacuum. What's weird, is that the
> lines don't match up in time. The reported duration is 37 minutes, and
> since the vacuum launches at 3:00am, it matches with the last line. If
> that's the case, what on Earth is that line at 3:20 all about? The
> durations for the last few days have also been about 50% shorter than
> historically, which is mysterious all by itself.

No idea about this.
Is there a lot of load on the system?

Yours,
Laurenz Albe