Subject: Re: Performance killed with FDW when using CAST.
To: pgsql-admin@lists.postgresql.org
References: 
 <CACut7uSz_3JiJ4w80VrQYECtOAt1Ya5E=EdLBAJ2_DnYwqsjGA@mail.gmail.com>
 <3e9c9857-f95e-a5b4-151a-6634a589a9e7@2ndquadrant.com>
 <CACut7uTytT_mUmge6x489oy+95dLgxonJaY-8sA7ebxBtppsoQ@mail.gmail.com>
From: Ron <ronljohnsonjr@gmail.com>
Message-ID: <b5bdb06b-e35e-3b15-feac-5c965b2a3aad@gmail.com>
Date: Tue, 16 Apr 2019 22:00:03 -0500
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101
 Thunderbird/60.6.1
MIME-Version: 1.0
In-Reply-To: 
 <CACut7uTytT_mUmge6x489oy+95dLgxonJaY-8sA7ebxBtppsoQ@mail.gmail.com>
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 8bit
Content-Language: en-US
Precedence: bulk


On 4/16/19 9:40 PM, Jorge Torralba wrote:
> Thanks for taking the time to look.
>
> Both servers are on ....
>
>    version
> ----------------------------------------------------------------------------------------------------------------------------------
>  PostgreSQL 11.2 (Debian 11.2-1.pgdg90+1) on x86_64-pc-linux-gnu, compiled 
> by gcc (Debian 6.3.0-18+deb9u1) 6.3.0 20170516, 64-bit
>
> I have reduced the query to select only two columns for simplicity with 
> the same results.
>
> The table contain about 50 million rows
>
> On the server hosting the table ..... Hiding private data.
>
> alertsdb_recent_events=#  select id, attributes -> 'account_incident_id' 
> from recent_events where account_id = 1 AND (attributes -> 
> 'account_incident_id')::integer = 2617116 limit 5;
>                   id                  | ?column?
> --------------------------------------+----------
>  ***** | 2617116
>  ***** | 2617116
>  ***** | 2617116
>  ***** | 2617116
>  ***** | 2617116
> (5 rows)
>
> Time: 82.868 ms
>
>
> # explain  select id, attributes -> 'account_incident_id' from 
> recent_events where account_id = 1 AND (attributes -> 
> 'account_incident_id')::integer = 2617116 limit 5;
>      QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------------------------------
>  Limit  (cost=0.56..3.77 rows=5 width=48)
>    ->  Index Scan using 
> recent_event_account_id_attributes_account_incident_id_idx on 
> recent_events  (cost=0.56..56.31 rows=87 width=48)
>          Index Cond: ((account_id = 1) AND (((attributes -> 
> 'account_incident_id'::text))::integer = 2617116))
> (3 rows)
>
> Time: 71.907 ms
>
> # explain  analyze select id, attributes -> 'account_incident_id' from 
> recent_events where account_id = 1 AND (attributes -> 
> 'account_incident_id')::integer = 2617116 limit 5;
>                           QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>  Limit  (cost=0.56..3.77 rows=5 width=48) (actual time=0.019..0.025 rows=5 
> loops=1)
>    ->  Index Scan using 
> recent_event_account_id_attributes_account_incident_id_idx on 
> recent_events  (cost=0.56..56.31 rows=87 width=48) (actual 
> time=0.018..0.023 rows=5 loops=1)
>          Index Cond: ((account_id = 1) AND (((attributes -> 
> 'account_incident_id'::text))::integer = 2617116))
>  Planning Time: 0.124 ms
>  Execution Time: 0.038 ms
> (5 rows)
>
> Time: 80.782 ms
>
>
> On the server that communicates with the FDW server .....
>
> # explain  select id, attributes -> 'account_incident_id' from 
> recent_events where account_id = 1 AND (attributes -> 
> 'account_incident_id')::integer = 2617116 limit 5;
>                                      QUERY PLAN
> -------------------------------------------------------------------------------------
>  Limit  (cost=100.00..426.27 rows=5 width=48)
>    ->  Foreign Scan on recent_events (cost=100.00..6663659.61 rows=102117 
> width=48)
>          Filter: (((attributes -> 'account_incident_id'::text))::integer = 
> 2617116)
> (3 rows)
>
> Time: 85.276 ms
>
>
> # explain  analyze select id, attributes -> 'account_incident_id' from 
> recent_events where account_id = 1 AND (attributes -> 
> 'account_incident_id')::integer = 2617116 limit 5;
>     QUERY PLAN
> ---------------------------------------------------------------------------------------------------------------------------------------
>  Limit  (cost=100.00..426.27 rows=5 width=48) (actual 
> time=21242.087..26387.257 rows=5 loops=1)
>    ->  Foreign Scan on recent_events (cost=100.00..6663703.90 rows=102117 
> width=48) (actual time=21242.086..26387.252 rows=5 loops=1)
>          Filter: (((attributes -> 'account_incident_id'::text))::integer = 
> 2617116)
>          Rows Removed by Filter: 724249
>  Planning Time: 1.164 ms
>  Execution Time: 26387.851 ms
> (6 rows)
>
> Time: 26528.113 ms (00:26.528)
>
> The query killer is the ...
>
> AND (attributes -> 'account_incident_id')::integer = 2617116
>
> Run the query this way ...
>
> select id, attributes -> 'account_incident_id' from recent_events where 
> account_id = 1  limit 5;
>
> and the results is only 10ms slower than on the hosting server directly 
> which is what we are expecting.  It's like the casting of the hstore 
> column is just not playing nice.

Casting the left side of a predicate is not recommended.  What if you cast 
2617166 to be the same type as attributes -> 'account_incident_id'?


-- 
Angular momentum makes the world go 'round.