Hi,

Our application is using Postgres 7.4 and I'd like to understand the root
cause of this problem:

To speed up overall insert time, our application will write thousands of
rows, one by one, into a temp table (same structure as a permanent table),
then do a bulk insert from the temp table to the permanent table. After
this bulk insert is done, the temp table is truncated and the process is
repeated. We do this because Postgres can do many individual inserts to a
temp table much faster than to a permanent table.

The problem we are seeing is that over time, the cost of a single insert to
the temp table seems to grow. After a restart of postgres, a single insert
to the temp table takes about 3ms. Over a few days, this grows to about
60ms per insert. Restarting postgres drops this insert time back to 3ms,
supposedly because the temp table is re-created. Our workaround right now
is to restart the database every few days, but we don't like this solution
much.

Any idea where the bloat is happening? I believe that if we were dropping
and re-creating the temp table over and over, that could result in pg_class
bloat (among other catalog tables), but what is going wrong if we use the
same table over and over and truncate it?

Thanks,
Steve

"Steven Flatt" <steven.flatt@gmail.com> writes:
> Any idea where the bloat is happening? I believe that if we were dropping
> and re-creating the temp table over and over, that could result in pg_class
> bloat (among other catalog tables), but what is going wrong if we use the
> same table over and over and truncate it?

That seems very strange --- I too would have expected a TRUNCATE to
bring you back to ground zero performance-wise. I wonder whether the
issue is not directly related to the temp table but is just some generic
resource leakage problem in a very long-running backend. Have you
checked to see if the backend process bloats memory-wise, or perhaps has
a huge number of files open (I wonder if it could be leaking open file
handles to the successive generations of the temp table)? Are you sure
that the slowdown is specific to inserts into the temp table, as opposed
to generic SQL activity?

Also, which PG version is this exactly ("7.4" is not specific enough)?
On what platform? Can you show us the full schema definition for the
temp table and any indexes on it?

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

On 12/13/06, Steven Flatt <steven.flatt@gmail.com> wrote:
> Hi,
>
> Our application is using Postgres 7.4 and I'd like to understand the root
> cause of this problem:
>
> To speed up overall insert time, our application will write thousands of
> rows, one by one, into a temp table

1. how frequently are you commiting the transaction ?
if you commit less frequetly it will be faster.

2. If you use COPY instead of INSERT it will be faster.
using COPY is easy with DBD::Pg (perl). In versions
8.x i think there has been major speed improvements
in COPY.

I do not know the root cause of slowdown though.

Regds
mallah.



>

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo@postgresql.org so that your
message can get through to the mailing list cleanly

After running some further standalone tests using temp tables, I'm not
convinced the problem is specific to temp table usage. In fact it looks
like generic SQL activity degrades over time.

Having said that, what kinds of things should I be looking for that could
deteriorate/bloat over time? Ordinarily the culprit might be infrequent
vacuuming or analyzing, but that wouldn't be corrected by a restart of
Postgres. In our case, restarting Postgres gives us a huge performance
improvement (for a short while, anyways).

By the way, we are using PG 7.4.6 on FreeBSD 5.30.0170. The temp table has
15 columns: a timestamp, a double, and the rest integers. It has no
indexes.

Thanks,
Steve


On 12/13/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> "Steven Flatt" <steven.flatt@gmail.com> writes:
> > Any idea where the bloat is happening? I believe that if we were
> dropping
> > and re-creating the temp table over and over, that could result in
> pg_class
> > bloat (among other catalog tables), but what is going wrong if we use
> the
> > same table over and over and truncate it?
>
> That seems very strange --- I too would have expected a TRUNCATE to
> bring you back to ground zero performance-wise. I wonder whether the
> issue is not directly related to the temp table but is just some generic
> resource leakage problem in a very long-running backend. Have you
> checked to see if the backend process bloats memory-wise, or perhaps has
> a huge number of files open (I wonder if it could be leaking open file
> handles to the successive generations of the temp table)? Are you sure
> that the slowdown is specific to inserts into the temp table, as opposed
> to generic SQL activity?
>
> Also, which PG version is this exactly ("7.4" is not specific enough)?
> On what platform? Can you show us the full schema definition for the
> temp table and any indexes on it?
>
> regards, tom lane
>

"Steven Flatt" <steven.flatt@gmail.com> writes:
> Having said that, what kinds of things should I be looking for that could
> deteriorate/bloat over time? Ordinarily the culprit might be infrequent
> vacuuming or analyzing, but that wouldn't be corrected by a restart of
> Postgres. In our case, restarting Postgres gives us a huge performance
> improvement (for a short while, anyways).

Do you actually need to restart the postmaster, or is just starting a
fresh session (fresh backend) sufficient? And again, have you monitored
the backend process to see if it's bloating memory-wise or open-file-wise?

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

"Steven Flatt" <steven.flatt@gmail.com> writes:
> Having said that, what kinds of things should I be looking for that could
> deteriorate/bloat over time? Ordinarily the culprit might be infrequent
> vacuuming or analyzing, but that wouldn't be corrected by a restart of
> Postgres. In our case, restarting Postgres gives us a huge performance
> improvement (for a short while, anyways).

> By the way, we are using PG 7.4.6 on FreeBSD 5.30.0170. The temp table has
> 15 columns: a timestamp, a double, and the rest integers. It has no
> indexes.

Hm, *are* you vacuuming only infrequently? In particular, what is your
maintenance policy for pg_class?

Some experimentation with TRUNCATE and VACUUM VERBOSE shows that in 7.4,
a TRUNCATE of a temp table with no indexes and no toast table generates
three dead row versions in pg_class. (I'm surprised that it's as many
as three, but in any case the TRUNCATE would certainly have to do one
update of the table's pg_class entry and thereby generate one dead row
version.)

If you're being sloppy about vacuuming pg_class, then over time the
repeated-truncate pattern would build up a huge number of dead rows
in pg_class, *all with the same OID*. It's unsurprising that this
would create some slowness in looking up the temp table's pg_class
entry.

If this theory is correct, the reason that starting a fresh backend
makes it fast again is that the new backend creates a whole new temp
table with a new OID assigned, and so the adjacent litter in pg_class
doesn't matter anymore (or not so much anyway).

Solution would be to institute regular vacuuming of the system
catalogs...

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 7: You can help support the PostgreSQL project by donating at

http://www.postgresql.org/about/donate

Thanks for your replies.

Starting a fresh session (not restarting the postmaster) seems to be
sufficient to reset performance (and is an easy enough workaround). Still,
it would be nice to know the root cause of the problem.

The backend process does not seem to be bloating memory-wise (I'm using
vmstat to monitor memory usage on the machine). It also does not appear to
be bloating in terms of open file handles (using fstat, I can see the
backend process has 160-180 open file handles, not growing).

Regarding your other email -- interesting -- but we are vacuuming pg_class
every hour. So I don't think the answer lies there...

Steve

On 12/13/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> "Steven Flatt" <steven.flatt@gmail.com> writes:
> > Having said that, what kinds of things should I be looking for that
> could
> > deteriorate/bloat over time? Ordinarily the culprit might be infrequent
> > vacuuming or analyzing, but that wouldn't be corrected by a restart of
> > Postgres. In our case, restarting Postgres gives us a huge performance
> > improvement (for a short while, anyways).
>
> Do you actually need to restart the postmaster, or is just starting a
> fresh session (fresh backend) sufficient? And again, have you monitored
> the backend process to see if it's bloating memory-wise or open-file-wise?
>
> regards, tom lane
>

"Steven Flatt" <steven.flatt@gmail.com> writes:
> Regarding your other email -- interesting -- but we are vacuuming pg_class
> every hour. So I don't think the answer lies there...

That's good, but is the vacuum actually accomplishing anything? I'm
wondering if there's also a long-running transaction in the mix.
Try a manual "VACUUM VERBOSE pg_class;" after the thing has slowed down,
and see what it says about removable and nonremovable rows.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Here's the output of "VACUUM VERBOSE pg_class". I think it looks fine. I
even did it three times in a row, each about 10 minutes apart, just to see
what was changing:

--------------------
INFO: vacuuming "pg_catalog.pg_class"
INFO: index "pg_class_oid_index" now contains 3263 row versions in 175
pages
DETAIL: 5680 index row versions were removed.
150 index pages have been deleted, 136 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: index "pg_class_relname_nsp_index" now contains 3263 row versions in
1301
pages
DETAIL: 5680 index row versions were removed.
822 index pages have been deleted, 734 are currently reusable.
CPU 0.01s/0.01u sec elapsed 0.03 sec.
INFO: "pg_class": removed 5680 row versions in 109 pages
DETAIL: CPU 0.00s/0.01u sec elapsed 0.04 sec.
INFO: "pg_class": found 5680 removable, 3263 nonremovable row versions in
625 p
ages
DETAIL: 0 dead row versions cannot be removed yet.
There were 23925 unused item pointers.
0 pages are entirely empty.
CPU 0.02s/0.04u sec elapsed 0.10 sec.
VACUUM
--------------------
INFO: vacuuming "pg_catalog.pg_class"
INFO: index "pg_class_oid_index" now contains 3263 row versions in 175
pages
DETAIL: 24 index row versions were removed.
150 index pages have been deleted, 150 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: index "pg_class_relname_nsp_index" now contains 3263 row versions in
1301
pages
DETAIL: 24 index row versions were removed.
822 index pages have been deleted, 822 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: "pg_class": removed 24 row versions in 2 pages
DETAIL: CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: "pg_class": found 24 removable, 3263 nonremovable row versions in 625
pag
es
DETAIL: 0 dead row versions cannot be removed yet.
There were 29581 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
VACUUM
--------------------
INFO: vacuuming "pg_catalog.pg_class"
INFO: index "pg_class_oid_index" now contains 3263 row versions in 175
pages
DETAIL: 150 index pages have been deleted, 150 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: index "pg_class_relname_nsp_index" now contains 3263 row versions in
1301
pages
DETAIL: 822 index pages have been deleted, 822 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO: "pg_class": found 0 removable, 3263 nonremovable row versions in 625
page
s
DETAIL: 0 dead row versions cannot be removed yet.
There were 29605 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
VACUUM
--------------------

The one thing that seems to be steadily increasing is the number of unused
item pointers. Not sure if that's normal. I should also point out that
SELECT statements are not experiencing the same degradation as the INSERTs
to the temp table. SELECTs are performing just as well now (24 hours since
restarting the connection) as they did immediately after restarting the
connection. INSERTs to the temp table are 5 times slower now than they were
24 hours ago.

I wonder if the problem has to do with a long running ODBC connection.

Steve


On 12/14/06, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> "Steven Flatt" <steven.flatt@gmail.com> writes:
> > Regarding your other email -- interesting -- but we are vacuuming
> pg_class
> > every hour. So I don't think the answer lies there...
>
> That's good, but is the vacuum actually accomplishing anything? I'm
> wondering if there's also a long-running transaction in the mix.
> Try a manual "VACUUM VERBOSE pg_class;" after the thing has slowed down,
> and see what it says about removable and nonremovable rows.
>
> regards, tom lane
>

"Steven Flatt" <steven.flatt@gmail.com> writes:
> Here's the output of "VACUUM VERBOSE pg_class". I think it looks fine. I
> even did it three times in a row, each about 10 minutes apart, just to see
> what was changing:

Hm, look at the numbers of rows removed:

> INFO: "pg_class": found 5680 removable, 3263 nonremovable row versions in
> 625 pages
> DETAIL: 0 dead row versions cannot be removed yet.

> INFO: "pg_class": found 24 removable, 3263 nonremovable row versions in 625
> pages
> DETAIL: 0 dead row versions cannot be removed yet.

> INFO: "pg_class": found 0 removable, 3263 nonremovable row versions in 625
> pages
> DETAIL: 0 dead row versions cannot be removed yet.

The lack of unremovable dead rows is good, but why were there so many
dead rows the first time? You didn't say what the cycle time is on your
truncate-and-refill process, but the last two suggest that the average
rate of accumulation of dead pg_class rows is only a couple per minute,
in which case it's been a lot longer than an hour since the previous
VACUUM of pg_class. I'm back to suspecting that you don't vacuum
pg_class regularly. You mentioned having an hourly cron job to fire off
vacuums ... are you sure it's run as a database superuser?

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match