Re: strange performance regression between 7.4 and 8.1

On Thu, 1 Mar 2007, Alex Deucher wrote:

> here are some examples. Analyze is still running on the new db, I'll
> post results when that is done. Mostly what our apps do is prepared
> row selects from different tables:
> select c1,c2,c3,c4,c5 from t1 where c1='XXX';
>
> old server:
> db=# EXPLAIN ANALYZE select c1,c2 from t1 where c2='6258261';
> QUERY PLAN
> ---------------------------------------------------------------------------------------------------------------------------
> Index Scan using t1_c2_index on t1 (cost=0.00..166.89 rows=42
> width=26) (actual time=5.722..5.809 rows=2 loops=1)
> Index Cond: ((c2)::text = '6258261'::text)
> Total runtime: 5.912 ms
> (3 rows)
>
> db=# EXPLAIN ANALYZE select c1,c2 from t1 where c1='6258261';
> QUERY PLAN
> ----------------------------------------------------------------------------------------------------------------------------
> Index Scan using t1_c1_key on t1 (cost=0.00..286.08 rows=72
> width=26) (actual time=12.423..12.475 rows=12 loops=1)
> Index Cond: ((c1)::text = '6258261'::text)
> Total runtime: 12.538 ms
> (3 rows)
>
>
> new server:
> db=# EXPLAIN ANALYZE select c1,c2 from t1 where c2='6258261';
> QUERY PLAN
> ----------------------------------------------------------------------------------------------------------------------------
> Index Scan using t1_c2_index on t1 (cost=0.00..37.63 rows=11
> width=26) (actual time=33.461..51.377 rows=2 loops=1)
> Index Cond: ((c2)::text = '6258261'::text)
> Total runtime: 51.419 ms
> (3 rows)
>
> db=# EXPLAIN ANALYZE select c1,c2 from t1 where c1='6258261';
> QUERY PLAN
> --------------------------------------------------------------------------------------------------------------------------------
> Index Scan using t1_c1_index on t1 (cost=0.00..630.45 rows=2907
> width=26) (actual time=45.733..46.271 rows=12 loops=1)
> Index Cond: ((c1)::text = '6258261'::text)
> Total runtime: 46.325 ms
> (3 rows)

Notice the huge disparity here betwen the expected number of rows (2907) and
the actual rows? That's indicative of needing to run analyze. The time is
only about 4x the 7.4 runtime and that's with the analyze running merrily
along in the background. It's probably not as bad off as you think. At least
this query isn't 10x. :-)

Run these again for us after analyze is complete.

--
Jeff Frost, Owner <jeff(at)frostconsultingllc(dot)com>
Frost Consulting, LLC http://www.frostconsultingllc.com/
Phone: 650-780-7908 FAX: 650-649-1954