Re: Something Weird Going on with VACUUM ANALYZE

From: Shaun Thomas <sthomas(at)optionshouse(dot)com>
To: Jeff Janes <jeff(dot)janes(at)gmail(dot)com>
Cc: PostgreSQL General <pgsql-general(at)postgresql(dot)org>
Subject: Re: Something Weird Going on with VACUUM ANALYZE
Date: 2013-09-19 13:19:43
Message-ID: 523AF9EF.6010009@optionshouse.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

On 09/18/2013 11:50 AM, Jeff Janes wrote:

> That line is the final line of a multi-line log entry. To know what
> it is about, you need to look at the lines before it in the logfile.
> Perhaps it is failing to obtain a lock or something.

Thanks for the input, Jeff. The full chunk for that PID (22078) is:

|2013-09-17 03:20:08 CDT|LOG: automatic vacuum of table
"table_redacted": could not (re)acquire exclusive lock for truncate scan
2013-09-17 03:20:08 CDT|STATEMENT: VACUUM (VERBOSE, ANALYZE);
2013-09-17 03:20:37 CDT|LOG: sending cancel to blocking autovacuum PID
23000
DETAIL: Process 22078 waits for ShareUpdateExclusiveLock on relation
18745 of database 16384.
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);

Which suggests an autovacuum was screwing with the launch time of the
database-wide VACUUM VERBOSE, or at least interfered with that one
table. What that doesn't explain, is why the VACUUM VERBOSE would finish
much sooner when this happens. 17 minutes in this case (if it was
blocking, or 37 if it was just stuck on that one table) instead of the
usual 55. I could see it starting later, but it should still take 55
minutes.

It did it again today, but this time, it "finished" in 25 minutes, and
didn't send a cancel to the other autovacuum. The fact it's so much
faster after encountering the truncate scan error, makes me wonder if
the analyze portion (high CPU usage) just plain stops working after that.

The first line also seems extremely misleading. a manually launched
vacuum is not an autovacuum, so why is it complaining about an
autovacuum? Shouldn't the PID doing the autovacuum emit the log message?
This all seems a little sketchy.

--
Shaun Thomas
OptionsHouse | 141 W. Jackson Blvd. | Suite 500 | Chicago IL, 60604
312-676-8870
sthomas(at)optionshouse(dot)com

______________________________________________

See http://www.peak6.com/email_disclaimer/ for terms and conditions related to this email

In response to

Responses

Browse pgsql-general by date

  From Date Subject
Next Message David Johnston 2013-09-19 13:34:48 Re: How to evaluate if a query is correct?
Previous Message Dave Cramer 2013-09-19 12:47:24 reading cvs logs with pgadmin queries