Re: atrocious update performance

while you weren't looking, Tom Lane wrote:

> EXPLAIN won't tell you anything about triggers that might get fired
> during the UPDATE, so it's not much help for investigating possible
> FK performance problems. EXPLAIN ANALYZE will give you some indirect
> evidence: the difference between the total query time and the total time
> reported for the topmost plan node represents the time spent running
> triggers and physically updating the tuples. I suspect we are going
> to see a big difference.

It's still running.

> It took 20 seconds to EXPLAIN? That's pretty darn odd in itself.

It struck me, too.

> I'm starting to think there must be something quite whacked-out about
> your installation, but I haven't got any real good ideas about what.

Built from source. configure arguments:

./configure --prefix=/var/postgresql --bindir=/usr/bin
--enable-thread-safety --with-perl --with-python --with-openssl
--with-krb5=/usr/kerberos

I can answer more specific questions; otherwise, I'm not sure what to
look for, either. If we could take the machine out of production (oh,
hell; I think I just volunteered myself for weekend work) long enough
to reinstall everything to get a fair comparison...

So far as I know, though, it's a more or less stock Red Hat. 2.4.20-
something.

> (I'm assuming of course that there weren't a ton of other jobs eating
> CPU while you tried to do the EXPLAIN.)

CPU's spiked sopradically, which throttled everything else, but it never
stays high. top shows the current explain analyze running between 50-
ish% and negligible. iostat -k 3 shows an average of 3K/sec written, for
a hundred-odd tps.

I can't get any finer-grained than that, unfortunately; the machine was
handed to me with a single, contiguous filesystem, in production use.

> [ thinks for awhile... ] The only theory that comes to mind
> for making
> the planner so slow is oodles of dead tuples in pg_statistic. Could I
> trouble you to run
> vacuum full verbose pg_statistic;
> and send along the output?

INFO: vacuuming "pg_catalog.pg_statistic"
INFO: "pg_statistic": found 215 removable, 349 nonremovable row versions
in 7 pages
DETAIL: 0 dead row versions cannot be removed yet.
Nonremovable row versions range from 72 to 8132 bytes long.
There were 3 unused item pointers.
Total free space (including removable row versions) is 91572 bytes.
0 pages are or will become empty, including 0 at the end of the table.
7 pages containing 91572 free bytes are potential move destinations.
CPU 0.00s/0.00u sec elapsed 0.71 sec.
INFO: index "pg_statistic_relid_att_index" now contains 349 row versions
in 2 pages
DETAIL: 215 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: "pg_statistic": moved 120 row versions, truncated 7 to 5 pages
DETAIL: CPU 0.03s/0.01u sec elapsed 0.17 sec.
INFO: index "pg_statistic_relid_att_index" now contains 349 row versions
in 2 pages
DETAIL: 120 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: vacuuming "pg_toast.pg_toast_16408"
INFO: "pg_toast_16408": found 12 removable, 12 nonremovable row versions
in 5 pages
DETAIL: 0 dead row versions cannot be removed yet.
Nonremovable row versions range from 660 to 8178 bytes long.
There were 0 unused item pointers.
Total free space (including removable row versions) is 91576 bytes.
2 pages are or will become empty, including 0 at the end of the table.
5 pages containing 91576 free bytes are potential move destinations.
CPU 0.00s/0.00u sec elapsed 0.27 sec.
INFO: index "pg_toast_16408_index" now contains 12 row versions in 2 pages
DETAIL: 12 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.05 sec.
INFO: "pg_toast_16408": moved 10 row versions, truncated 5 to 3 pages
DETAIL: CPU 0.00s/0.00u sec elapsed 0.01 sec.
INFO: index "pg_toast_16408_index" now contains 12 row versions in 2 pages
DETAIL: 10 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.

Having never more than glanced at the output of "vacuum verbose", I
can't say whether that makes the cut for oodles. My suspicion is no.

/rls

--
Rosser Schwarz
Total Card, Inc.