Re: 27 second plan times

"Tom Lane" <tgl(at)sss(dot)pgh(dot)pa(dot)us> writes:

> Gregory Stark <stark(at)enterprisedb(dot)com> writes:
>> The SearchCatCache here is the one in get_attavgwidth called to estimate the
>> relation width.
>
> Hmm, that information is supposed to be cached ... could you provide the
> test case?

This case caused my machine to thrash and swap terribly with the backend
requiring over 1.3G of RAM to handle the explain.

What's really strange is that I got warnings about checkpoints happening too
frequently. How could an explain of a select cause checkpoints?! There are no
log entries for autovacuum but that's the only thing I can think of.

I'll dive back into gprof tomorrow, but for now it's time for sleep.

postgres=# copy (select 'create table t (' union all select 'a'||generate_series(1,1599)||' bool,' union all select 'a1600 bool);') to '/tmp/t';
COPY 1601
postgres=# \i /tmp/t
CREATE TABLE
postgres=# copy (select 'create table t'||generate_series(1,1000)||' () inherits (t);') to '/tmp/u';
COPY 1000
Time: 5.002 ms
postgres=#
postgres=# \i /tmp/u
postgres=# explain select * from t;
QUERY PLAN
------------------------------------------------------------------------
Result (cost=0.00..10510.50 rows=50050 width=1600)
-> Append (cost=0.00..10510.50 rows=50050 width=1600)
-> Seq Scan on t (cost=0.00..10.50 rows=50 width=1600)
-> Seq Scan on t1 t (cost=0.00..10.50 rows=50 width=1600)
-> Seq Scan on t2 t (cost=0.00..10.50 rows=50 width=1600)
...
-> Seq Scan on t999 t (cost=0.00..10.50 rows=50 width=1600)
-> Seq Scan on t1000 t (cost=0.00..10.50 rows=50 width=1600)
(1003 rows)

Time: 889727.115 ms

--
Gregory Stark
EnterpriseDB http://www.enterprisedb.com