Thread: Identical query on two machines, different plans....

Identical query on two machines, different plans....

From
Mario Splivalo
Date:
I have copied the database from production server to my laptop (pg_dump,
etc...) to do some testing.

While testing I have found out that one particular query is beeing much
slower on my machine than on the server (it's not just because my laptop
is much slower than the server), and found out that postgres is using
different plan on server than on my laptop. Both on server and on my
laptop is postgres-8.1.2, running on Debian (sarge on server, Ubuntu on
my laptop), with 2.6 kernel, I compiled postgres with gcc4 on both
machines.

The query is like this:

on the server:

pulitzer2=#  explain analyze select code_id from ticketing_codes where
code_group_id = 1000 and code_value = UPPER('C7ZP2U');

QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using ticketing_codes_uq_value_group_id on ticketing_codes
(cost=0.00..6.02 rows=1 width=4) (actual time=0.104..0.107 rows=1
loops=1)
   Index Cond: (((code_value)::text = 'C7ZP2U'::text) AND (code_group_id
= 1000))
 Total runtime: 0.148 ms
(3 rows)


And, on my laptop:

som_pulitzer2=#  explain analyze select code_id from ticketing_codes
where code_group_id = 1000 and code_value = UPPER('C7ZP2U');
                                                                  QUERY
PLAN

----------------------------------------------------------------------------------------------------------------------------------------------
 Bitmap Heap Scan on ticketing_codes  (cost=2.01..1102.05 rows=288
width=4) (actual time=88.164..88.170 rows=1 loops=1)
   Recheck Cond: (((code_value)::text = 'C7ZP2U'::text) AND
(code_group_id = 1000))
   ->  Bitmap Index Scan on ticketing_codes_uq_value_group_id
(cost=0.00..2.01 rows=288 width=0) (actual time=54.397..54.397 rows=1
loops=1)
         Index Cond: (((code_value)::text = 'C7ZP2U'::text) AND
(code_group_id = 1000))
 Total runtime: 88.256 ms
(5 rows)



This is the table ticketing_codes:
som_pulitzer2=# \d ticketing_codes;
                                      Table "public.ticketing_codes"
    Column     |         Type          |
Modifiers
---------------+-----------------------+-------------------------------------------------------------------
 code_id       | integer               | not null default
nextval('ticketing_codes_code_id_seq'::regclass)
 code_value    | character varying(10) | not null
 code_group_id | integer               | not null
Indexes:
    "ticketing_codes_pk" PRIMARY KEY, btree (code_id)
    "ticketing_codes_uq_value_group_id" UNIQUE, btree (code_value,
code_group_id)
Foreign-key constraints:
    "ticketing_codes_fk__ticketing_code_groups" FOREIGN KEY
(code_group_id) REFERENCES ticketing_code_groups(group_id)


And the \d command produces the same result on both my server and
laptop.

That query is beeing called from within function, the code is like this:

codeId := code_id from ticketing_codes where code_group_id = 1000 and
code_value = UPPER('C7ZP2U');

codeId has been declared as int4. When that query is run inside the
function, it takes around 20 seconds (compared to 88 miliseconds when I
call it from psql). The query is that very same query, just the values
1000 and 'C7ZP2U' are parametars for the function.

So, the second question would be why is that query much much slower when
run from within function? Is there a way to see an execution plan for
the query inside the function?

    Mike
--
Mario Splivalo
Mob-Art
mario.splivalo@mobart.hr

"I can do it quick, I can do it cheap, I can do it well. Pick any two."



Re: Identical query on two machines, different plans....

From
Csaba Nagy
Date:
You very likely forgot to run ANALYZE on your laptop after copying the
data. Observe the different row count estimates in the 2 plans...

HTH,
Csaba.


> QUERY PLAN
>
---------------------------------------------------------------------------------------------------------------------------------------------------
>  Index Scan using ticketing_codes_uq_value_group_id on ticketing_codes
> (cost=0.00..6.02 rows=1 width=4) (actual time=0.104..0.107 rows=1
                                                             ^^^^^^
> loops=1)
>    Index Cond: (((code_value)::text = 'C7ZP2U'::text) AND (code_group_id
> = 1000))
>  Total runtime: 0.148 ms
> (3 rows)
>
>
> PLAN
>
----------------------------------------------------------------------------------------------------------------------------------------------
>  Bitmap Heap Scan on ticketing_codes  (cost=2.01..1102.05 rows=288
                                                            ^^^^^^^^
> width=4) (actual time=88.164..88.170 rows=1 loops=1)
>    Recheck Cond: (((code_value)::text = 'C7ZP2U'::text) AND
> (code_group_id = 1000))
>    ->  Bitmap Index Scan on ticketing_codes_uq_value_group_id
> (cost=0.00..2.01 rows=288 width=0) (actual time=54.397..54.397 rows=1
> loops=1)
>          Index Cond: (((code_value)::text = 'C7ZP2U'::text) AND
> (code_group_id = 1000))
>  Total runtime: 88.256 ms
> (5 rows)
>



Re: Identical query on two machines, different plans....

From
Mario Splivalo
Date:
On Thu, 2006-04-20 at 15:59 +0200, Csaba Nagy wrote:
> You very likely forgot to run ANALYZE on your laptop after copying the
> data. Observe the different row count estimates in the 2 plans...
>
> HTH,
> Csaba.

Sometimes I wish I am Dumbo the Elephant, so I could cover myself with
me ears...

Thnx :)

    Mike
--
Mario Splivalo
Mob-Art
mario.splivalo@mobart.hr

"I can do it quick, I can do it cheap, I can do it well. Pick any two."



Re: Identical query on two machines, different plans....

From
Csaba Nagy
Date:
OK, I marked the wrong row counts, but the conclusion is the same.

Cheers,
Csaba.


> > QUERY PLAN
> >
---------------------------------------------------------------------------------------------------------------------------------------------------
> >  Index Scan using ticketing_codes_uq_value_group_id on ticketing_codes
> > (cost=0.00..6.02 rows=1 width=4) (actual time=0.104..0.107 rows=1
>                    ^^^^^^
> > loops=1)
> >    Index Cond: (((code_value)::text = 'C7ZP2U'::text) AND (code_group_id
> > = 1000))
> >  Total runtime: 0.148 ms
> > (3 rows)
> >
> >
> > PLAN
> >
----------------------------------------------------------------------------------------------------------------------------------------------
> >  Bitmap Heap Scan on ticketing_codes  (cost=2.01..1102.05 rows=288
>                                                             ^^^^^^^^
> > width=4) (actual time=88.164..88.170 rows=1 loops=1)
> >    Recheck Cond: (((code_value)::text = 'C7ZP2U'::text) AND
> > (code_group_id = 1000))
> >    ->  Bitmap Index Scan on ticketing_codes_uq_value_group_id
> > (cost=0.00..2.01 rows=288 width=0) (actual time=54.397..54.397 rows=1
                     ^^^^^^^^
> > loops=1)
> >          Index Cond: (((code_value)::text = 'C7ZP2U'::text) AND
> > (code_group_id = 1000))
> >  Total runtime: 88.256 ms
> > (5 rows)
> >
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 2: Don't 'kill -9' the postmaster