Oh, I didn't realize that analyze gave that much more info. I've got a lot to learn about this tuning stuff ;-) I've attached the output. I see from the new output where the slow query is taking its time (the nested loop at line 10), but I still have no idea why this plan is getting chosen.... Thanks! - DAP >-----Original Message----- >From: pgsql-performance-owner@xxxxxxxxxxxxxx >[mailto:pgsql-performance-owner@xxxxxxxxxxxxxx] On Behalf Of >Russell Smith >Sent: Tuesday, November 16, 2004 11:36 PM >To: pgsql-performance@xxxxxxxxxxxxxx >Subject: Re: query plan question > >On Wed, 17 Nov 2004 02:54 pm, you wrote: >> I have a query for which postgres is generating a different >plan on different machines. The database schema is the same, >the dataset is the same, the configuration is the same (e.g., >pg_autovacuum running in both cases), both systems are Solaris >9. The main difference in the two systems is that one is sparc >and the other is intel. >> >> The query runs in about 40 ms on the intel box, but takes >about 18 seconds on the sparc box. Now, the intel boxes we >have are certainly faster, but I'm curious why the query plan >might be different. >> >> For the intel: >> >> QUERY PLAN >> Unique (cost=11.50..11.52 rows=2 width=131) >> -> Sort (cost=11.50..11.50 rows=2 width=131) >> Sort Key: up.prefix, s.name, s.tuid, s.foundryversion >> -> Hash Join (cost=10.42..11.49 rows=2 width=131) >> Hash Cond: ("outer".dbid = "inner"."schema") >> -> Seq Scan on "schema" s (cost=0.00..1.02 >rows=2 width=128) >> -> Hash (cost=10.41..10.41 rows=4 width=11) >> -> Nested Loop (cost=0.00..10.41 >rows=4 width=11) >> -> Nested Loop (cost=0.00..2.14 >rows=4 width=4) >> -> Seq Scan on flow fl >(cost=0.00..0.00 rows=1 width=4) >> Filter: (servicetype = 646) >> -> Index Scan using >usage_flow_i on "usage" u (cost=0.00..2.06 rows=6 width=8) >> Index Cond: (u.flow = >"outer".dbid) >> -> Index Scan using >usageparameter_usage_i on usageparameter up (cost=0.00..2.06 >rows=1 width=15) >> Index Cond: (up."usage" = >"outer".dbid) >> Filter: ((prefix)::text <> >> 'xsd'::text) >> >> For the sparc: >> >> QUERY PLAN >> Unique (cost=10.81..10.83 rows=1 width=167) >> -> Sort (cost=10.81..10.82 rows=1 width=167) >> Sort Key: up.prefix, s.name, s.tuid, s.foundryversion >> -> Nested Loop (cost=9.75..10.80 rows=1 width=167) >> Join Filter: ("outer".flow = "inner".dbid) >> -> Hash Join (cost=9.75..10.79 rows=1 width=171) >> Hash Cond: ("outer".dbid = "inner"."schema") >> -> Seq Scan on "schema" s >(cost=0.00..1.02 rows=2 width=128) >> -> Hash (cost=9.75..9.75 rows=1 width=51) >> -> Nested Loop (cost=0.00..9.75 >rows=1 width=51) >> Join Filter: >("inner"."usage" = "outer".dbid) >> -> Index Scan using >usage_flow_i on "usage" u (cost=0.00..4.78 rows=1 width=8) >> -> Index Scan using >usageparameter_schema_i on usageparameter up (cost=0.00..4.96 >rows=1 width=51) >> Filter: >((prefix)::text <> 'xsd'::text) >> -> Seq Scan on flow fl (cost=0.00..0.00 >rows=1 width=4) >> Filter: (servicetype = 646) >> >Unique (cost=11.50..11.52 rows=2 width=131) Unique >(cost=10.81..10.83 rows=1 width=167) > >The estimations for the cost is basically the same, 10ms for >the first row. Can you supply Explain analyze to see what >it's actually doing? > >Russell Smith > >---------------------------(end of >broadcast)--------------------------- >TIP 6: Have you searched our list archives? > > http://archives.postgresql.org >
QUERY PLAN "Unique (cost=10.81..10.83 rows=1 width=167) (actual time=19390.684..19390.687 rows=1 loops=1)" " -> Sort (cost=10.81..10.82 rows=1 width=167) (actual time=19390.678..19390.679 rows=1 loops=1)" " Sort Key: up.prefix, s.name, s.tuid, s.foundryversion" " -> Nested Loop (cost=9.75..10.80 rows=1 width=167) (actual time=19377.051..19390.391 rows=1 loops=1)" " Join Filter: ("outer".flow = "inner".dbid)" " -> Hash Join (cost=9.75..10.79 rows=1 width=171) (actual time=19173.684..19181.827 rows=770 loops=1)" " Hash Cond: ("outer".dbid = "inner"."schema")" " -> Seq Scan on "schema" s (cost=0.00..1.02 rows=2 width=128) (actual time=0.240..0.693 rows=20 loops=1)" " -> Hash (cost=9.75..9.75 rows=1 width=51) (actual time=19173.354..19173.354 rows=0 loops=1)" " -> Nested Loop (cost=0.00..9.75 rows=1 width=51) (actual time=30.456..19166.759 rows=770 loops=1)" " Join Filter: ("inner"."usage" = "outer".dbid)" " -> Index Scan using usage_flow_i on "usage" u (cost=0.00..4.78 rows=1 width=8) (actual time=0.593..9.576 rows=771 loops=1)" " -> Index Scan using usageparameter_schema_i on usageparameter up (cost=0.00..4.96 rows=1 width=51) (actual time=16.171..22.411 rows=770 loops=771)" " Filter: ((prefix)::text <> 'xsd'::text)" " -> Seq Scan on flow fl (cost=0.00..0.00 rows=1 width=4) (actual time=0.007..0.260 rows=1 loops=770)" " Filter: (servicetype = 646)" "Total runtime: 19391.173 ms"
QUERY PLAN "Unique (cost=11.50..11.52 rows=2 width=131) (actual time=0.724..0.727 rows=1 loops=1)" " -> Sort (cost=11.50..11.50 rows=2 width=131) (actual time=0.722..0.723 rows=1 loops=1)" " Sort Key: up.prefix, s.name, s.tuid, s.foundryversion" " -> Hash Join (cost=10.42..11.49 rows=2 width=131) (actual time=0.551..0.670 rows=1 loops=1)" " Hash Cond: ("outer".dbid = "inner"."schema")" " -> Seq Scan on "schema" s (cost=0.00..1.02 rows=2 width=128) (actual time=0.027..0.129 rows=20 loops=1)" " -> Hash (cost=10.41..10.41 rows=4 width=11) (actual time=0.478..0.478 rows=0 loops=1)" " -> Nested Loop (cost=0.00..10.41 rows=4 width=11) (actual time=0.355..0.455 rows=1 loops=1)" " -> Nested Loop (cost=0.00..2.14 rows=4 width=4) (actual time=0.179..0.249 rows=3 loops=1)" " -> Seq Scan on flow fl (cost=0.00..0.00 rows=1 width=4) (actual time=0.057..0.112 rows=1 loops=1)" " Filter: (servicetype = 646)" " -> Index Scan using usage_flow_i on "usage" u (cost=0.00..2.06 rows=6 width=8) (actual time=0.115..0.121 rows=3 loops=1)" " Index Cond: (u.flow = "outer".dbid)" " -> Index Scan using usageparameter_usage_i on usageparameter up (cost=0.00..2.06 rows=1 width=15) (actual time=0.044..0.046 rows=0 loops=3)" " Index Cond: (up."usage" = "outer".dbid)" " Filter: ((prefix)::text <> 'xsd'::text)" "Total runtime: 0.842 ms"