Re: View with and without ::text casting performs differently.

Apologies, forgot to include Postgres version 9.1.9

- Brian F
On 09/05/2013 04:45 PM, Brian Fehrle wrote:
> Hi All,
>
> I have a view, that when created with our create statement works
> wonderfully, a query on the view with a standard where clause that
> narrows the result to a single row performs in under a single ms.
> However, when we export this view and re-import it (dump and restore
> of the database, which happens often), the exported version of the
> view has been modified by Postgres to include various typecasting of
> some columns to text.
>
> All columns that it typecasts to text are varchar(20), so there is
> nothing wrong in what it's doing there. However, with the view
> definition including the ::text casting, the query planner changes and
> it goes into a nested loop, taking a query from <1ms to over ten minutes.
>
> *NOTE: *When I execute the queries with and without ::text myself
> outside of the view, there is no issues. the query plan is correct and
> I get my result fast, it's only when putting the query in the view and
> then executing it does it do the nested loop and take forever.
>
>
>
> ----------- Query plan for view defined without ::text ---------------
> Nested Loop (cost=17.440..272.590 rows=1 width=1810) (actual
> time=0.515..0.527 rows=1 loops=1)
> -> Nested Loop (cost=17.440..265.480 rows=1 width=1275) (actual
> time=0.471..0.482 rows=1 loops=1)
> -> Nested Loop (cost=17.440..265.190 rows=1 width=761)
> (actual time=0.460..0.471 rows=1 loops=1)
> -> Nested Loop (cost=17.440..258.910 rows=1 width=186)
> (actual time=0.437..0.447 rows=1 loops=1)
> -> Nested Loop (cost=17.440..258.590 rows=1
> width=154) (actual time=0.417..0.425 rows=1 loops=1)
> -> Nested Loop (cost=17.440..252.240 rows=1
> width=160) (actual time=0.388..0.395 rows=1 loops=1)
> Join Filter:
> ((alpha_yankee.bravo_papa)::text = (six_zulu.kilo_uniform)::text)
> -> Nested Loop (cost=0.000..108.990
> rows=7 width=137) (actual time=0.107..0.109 rows=1 loops=1)
> -> Nested Loop
> (cost=0.000..102.780 rows=10 width=124) (actual time=0.077..0.078
> rows=1 loops=1)
> -> Index Scan using
> juliet_yankee on alpha_yankee (cost=0.000..18.240 rows=13 width=84)
> (actual time=0.043..0.044 rows=1 loops=1)
> Index Cond:
> ((bravo_charlie)::text = 'tango'::text)
> -> Index Scan using
> charlie_quebec on juliet_three (cost=0.000..6.490 rows=1 width=40)
> (actual time=0.029..0.029 rows=1 loops=1)
> Index Cond:
> ((echo)::text = (alpha_yankee.kilo_yankee)::text)
> Filter:
> ((four)::text = 'alpha_whiskey'::text)
> -> Index Scan using
> charlie_yankee on romeo (cost=0.000..0.610 rows=1 width=33) (actual
> time=0.027..0.027 rows=1 loops=1)
> Index Cond:
> ((echo)::text = (juliet_three.lima_victor)::text)
> Filter:
> ((lima_bravo)::text = 'alpha_whiskey'::text)
> -> Bitmap Heap Scan on papa six_zulu
> (cost=17.440..20.450 rows=1 width=64) (actual time=0.268..0.276
> rows=21 loops=1)
> Recheck Cond:
> (((charlie_victor)::text = (juliet_three.echo)::text) AND
> ((bravo_india)::text = (alpha_yankee.juliet_whiskey)::text))
> -> BitmapAnd
> (cost=17.440..17.440 rows=1 width=0) (actual time=0.255..0.255 rows=0
> loops=1)
> -> Bitmap Index Scan on
> alpha_foxtrot (cost=0.000..6.710 rows=28 width=0) (actual
> time=0.048..0.048 rows=21 loops=1)
> Index Cond:
> ((charlie_victor)::text = (juliet_three.echo)::text)
> -> Bitmap Index Scan on
> delta (cost=0.000..10.440 rows=108 width=0) (actual time=0.202..0.202
> rows=757 loops=1)
> Index Cond:
> ((bravo_india)::text = (alpha_yankee.juliet_whiskey)::text)
> -> Index Scan using whiskey_india on
> alpha_lima (cost=0.000..6.340 rows=1 width=57) (actual
> time=0.026..0.027 rows=1 loops=1)
> Index Cond: ((echo)::text =
> (six_zulu.bravo_india)::text)
> -> Index Scan using golf on whiskey_oscar
> (cost=0.000..0.310 rows=1 width=43) (actual time=0.017..0.018 rows=1
> loops=1)
> Index Cond: ((echo)::text =
> (alpha_lima.whiskey_six)::text)
> -> Index Scan using bravo_foxtrot on mike_mike
> lima_charlie (cost=0.000..6.270 rows=1 width=617) (actual
> time=0.020..0.020 rows=1 loops=1)
> Index Cond: ((echo)::text =
> (six_zulu.kilo_uniform)::text)
> -> Index Scan using charlie_papa on mike_oscar
> (cost=0.000..0.270 rows=1 width=530) (actual time=0.008..0.008 rows=1
> loops=1)
> Index Cond: ((echo)::text = (lima_charlie.yankee)::text)
> -> Index Scan using juliet_victor on juliet_six six_seven
> (cost=0.000..7.080 rows=1 width=556) (actual time=0.033..0.034 rows=1
> loops=1)
> Index Cond: ((echo)::text = 'tango'::text)
> Total runtime: 0.871 ms
> ----------------------------------------------------------------------------------------
>
> ----------- Query plan for view defined WITH ::text ---------------
> Nested Loop (cost=176136.470..3143249.320 rows=1 width=1810) (actual
> time=16357.306..815170.609 rows=1 loops=1)
> Join Filter: ((alpha_yankee.bravo_charlie)::text =
> (six_seven.echo)::text)
> -> Index Scan using juliet_victor on juliet_six six_seven
> (cost=0.000..7.080 rows=1 width=556) (actual time=0.035..0.038 rows=1
> loops=1)
> Index Cond: ((echo)::text = 'tango'::text)
> -> Nested Loop (cost=176136.470..3143242.190 rows=2 width=1275)
> (actual time=13071.765..812874.705 rows=6815445 loops=1)
> -> Nested Loop (cost=176136.470..3143241.560 rows=2
> width=1243) (actual time=13071.742..760766.802 rows=6815445 loops=1)
> -> Hash Join (cost=176136.470..3143228.850 rows=2
> width=1249) (actual time=13071.694..632785.712 rows=6815445 loops=1)
> Hash Cond: ((six_zulu.kilo_uniform)::text =
> (lima_charlie.echo)::text)
> -> Merge Join (cost=174404.520..3141496.860
> rows=2 width=160) (actual time=13023.713..619787.785 rows=6815445 loops=1)
> Merge Cond: ((juliet_three.echo)::text =
> (six_zulu.charlie)::text)
> Join Filter:
> (((alpha_yankee.juliet_whiskey)::text = (six_zulu.bravo_india)::text)
> AND ((alpha_yankee.bravo_papa)::text = (six_zulu.kilo_uniform)::text))
> -> Merge Join (cost=174391.960..1013040.600
> rows=5084399 width=137) (actual time=13023.660..68777.622 rows=7805731
> loops=1)
> Merge Cond:
> ((alpha_yankee.kilo_yankee)::text = (juliet_three.echo)::text)
> -> Index Scan using five on
> alpha_yankee (cost=0.000..739352.050 rows=9249725 width=84) (actual
> time=0.027..14936.587 rows=9204640 loops=1)
> -> Sort (cost=174391.750..175895.330
> rows=601433 width=53) (actual time=13023.526..14415.639 rows=7952904
> loops=1)
> Sort Key: juliet_three.echo
> Sort Method: quicksort Memory:
> 139105kB
> -> Hash Join
> (cost=62105.650..116660.060 rows=601433 width=53) (actual
> time=669.244..2278.990 rows=814472 loops=1)
> Hash Cond:
> ((juliet_three.lima_victor)::text = (romeo.echo)::text)
> -> Seq Scan on
> juliet_three (cost=0.000..40391.860 rows=814822 width=40) (actual
> time=0.009..677.160 rows=814473 loops=1)
> Filter:
> ((four)::text = 'alpha_whiskey'::text)
> -> Hash
> (cost=57562.740..57562.740 rows=363433 width=33) (actual
> time=668.812..668.812 rows=363736 loops=1)
> Buckets: 65536
> Batches: 1 Memory Usage: 23832kB
> -> Seq Scan on
> romeo (cost=0.000..57562.740 rows=363433 width=33) (actual
> time=0.012..489.104 rows=363736 loops=1)
> Filter: ((lima_bravo)::text = 'alpha_whiskey'::text)
> -> Materialize (cost=0.000..1192114.040
> rows=10236405 width=64) (actual time=0.030..72475.323 rows=140608673
> loops=1)
> -> Index Scan using alpha_foxtrot on
> papa six_zulu (cost=0.000..1166523.030 rows=10236405 width=64)
> (actual time=0.024..22466.849 rows=10176345 loops=1)
> -> Hash (cost=1568.500..1568.500 rows=13076
> width=1131) (actual time=47.954..47.954 rows=13054 loops=1)
> Buckets: 2048 Batches: 1 Memory Usage:
> 13551kB
> -> Hash Join (cost=19.950..1568.500
> rows=13076 width=1131) (actual time=0.415..24.461 rows=13054 loops=1)
> Hash Cond:
> ((lima_charlie.yankee)::text = (mike_oscar.echo)::text)
> -> Seq Scan on mike_mike
> lima_charlie (cost=0.000..1368.760 rows=13076 width=617) (actual
> time=0.006..5.948 rows=13054 loops=1)
> -> Hash (cost=18.310..18.310 rows=131
> width=530) (actual time=0.397..0.397 rows=131 loops=1)
> Buckets: 1024 Batches: 1
> Memory Usage: 73kB
> -> Seq Scan on mike_oscar
> (cost=0.000..18.310 rows=131 width=530) (actual time=0.007..0.221
> rows=131 loops=1)
> -> Index Scan using whiskey_india on alpha_lima
> (cost=0.000..6.340 rows=1 width=57) (actual time=0.017..0.017 rows=1
> loops=6815445)
> Index Cond: ((echo)::text =
> (six_zulu.bravo_india)::text)
> -> Index Scan using golf on whiskey_oscar (cost=0.000..0.310
> rows=1 width=43) (actual time=0.006..0.006 rows=1 loops=6815445)
> Index Cond: ((echo)::text =
> (alpha_lima.whiskey_six)::text)
> Total runtime: 815589.464 ms
> ----------------------------------------------------------------------------------------
>
> If I set enable_nestloop = off, then it works perfectly, however I
> don't really have the option to do this, I'd rather see what's causing it.
>
> Any thoughts?
>
> Thanks,
> - Brian F
>
>
>