pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: Brian Fehrle <brianf@consistentstate.com>
To: pgsql-performance@postgresql.org
Subject: Re: View with and without  ::text casting performs differently.
Date: Thu, 05 Sep 2013 16:46:55 -0600
Message-ID: <522909DF.4070307@consistentstate.com> (raw)
In-Reply-To: <5229097C.4070401@consistentstate.com>
References: <5229097C.4070401@consistentstate.com>
List-Unsubscribe:  <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>

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
>
>
>

view thread (8+ messages)  latest in thread

Message-ID: <522909DF.4070307@consistentstate.com>
Permalink:  ../522909DF.4070307@consistentstate.com/
Also on:    postgresql.org/message-id/522909DF.4070307@consistentstate.com

 · 

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: pgsql-performance@postgresql.org
  Cc: brianf@consistentstate.com
  Subject: Re: View with and without  ::text casting performs differently.
  In-Reply-To: <522909DF.4070307@consistentstate.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox