Re: BUG #17871: JIT during postgresql_fdw remote_estimates EXPLAIN have very negatively effect on planning time

Maxim Boguk <maxim.boguk@gmail.com>

From: Maxim Boguk <maxim.boguk@gmail.com>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: pgsql-bugs@lists.postgresql.org
Date: 2023-03-28T02:27:51Z
Lists: pgsql-bugs
On Tue, Mar 28, 2023 at 1:53 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:

> PG Bug reporting form <noreply@postgresql.org> writes:
> > Checking what's going on the remote side leads to the following results:
> > remote estimate explain calls from fdw with jit=on
> > [EXPLAIN] LOG:  duration: 97.050 ms  statement: EXPLAIN SELECT topic_id,
> > review_id, move_to_invitation_state_time, no_interview_reply_time,
> > review_suggestion_chat_message_creation_time FROM
> > public.interview_review_info_archive
> > vs
> > remote estimate explain calls from fdw with jit=off
> > [EXPLAIN] LOG:  duration: 3.343 ms  statement: EXPLAIN SELECT topic_id,
> > review_id, move_to_invitation_state_time, no_interview_reply_time,
> > review_suggestion_chat_message_creation_time FROM
> > public.interview_review_info_archive
>
> Do you see the same discrepancy when you execute EXPLAIN manually
> on the remote side?  If so, I wouldn't blame postgres_fdw for it.
>
> I suppose interview_review_info_archive is a view not a plain table?
> In either case, could we see the DDL definition for it?
>
>                         regards, tom lane
>

Hi,

Yes interview_review_info_archive is not a normal table by natively
partitioned by range table with 100 partition:

negotiation_chat_archive=# \d+ interview_review_info_archive
                                              Partitioned table
"public.interview_review_info_archive"
                    Column                    |            Type
| Collation | Nullable | Default | Storage | Stats target | Description
----------------------------------------------+-----------------------------+-----------+----------+---------+---------+--------------+-------------
 topic_id                                     | bigint
 |           | not null |         | plain   |              |
 review_id                                    | bigint
 |           |          |         | plain   |              |
 move_to_invitation_state_time                | timestamp without time zone
|           |          |         | plain   |              |
 no_interview_reply_time                      | timestamp without time zone
|           |          |         | plain   |              |
 review_suggestion_chat_message_creation_time | timestamp without time zone
|           |          |         | plain   |              |
Partition key: RANGE (topic_id)
Indexes:
    "interview_review_info_archive_pkey" PRIMARY KEY, btree (topic_id)
Partitions: interview_review_info_archive_p001 FOR VALUES FROM ('0') TO
('100000000'),
...
            interview_review_info_archive_p100 FOR VALUES FROM
('9900000000') TO ('10000000000')

When I run EXPLAIN locally there are the same differences.
Under normal circumstances this behavior is not an issue because EXPLAIN is
only executed by DBA, but with postgresql_fdw issues 2-3 EXPLAIN per each
basic fdw query this behavior (triggering JIT on explain) has a very
negative effect on performance.


Simplest case show huge difference in theEXPLAIN performance with and
without JIT:
negotiation_chat_archive=# set jit to on;
SET
negotiation_chat_archive=# explain select * FROM
public.interview_review_info_archive;
                                                                     QUERY
PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------
 Gather  (cost=100.00..4602434.79 rows=354847702 width=40)
   Workers Planned: 7
   ->  Parallel Append  (cost=0.00..1053857.77 rows=50692498 width=40)
         ->  Parallel Seq Scan on interview_review_info_archive_p030
interview_review_info_archive_30  (cost=0.00..200959.41 rows=15759281
width=40)
...
         ->  Parallel Seq Scan on interview_review_info_archive_p005
interview_review_info_archive_5  (cost=0.00..0.11 rows=1 width=40)
         ->  Parallel Seq Scan on interview_review_info_archive_p009
interview_review_info_archive_9  (cost=0.00..0.11 rows=1 width=40)
(103 rows)
 JIT:
   Functions: 200
   Options: Inlining true, Optimization true, Expressions true, Deforming
true
(106 rows)
Time: 33.664 ms
PS: this sample contradicts Andreas' statement about "It should not trigger
all of JIT, just generating the bitcode, but not optimizing / emitting it."
(or I read EXPLAIN output wrong.)

vs
negotiation_chat_archive=# explain select * FROM
public.interview_review_info_archive;
...
         ->  Parallel Seq Scan on interview_review_info_archive_p005
interview_review_info_archive_5  (cost=0.00..0.11 rows=1 width=40)
         ->  Parallel Seq Scan on interview_review_info_archive_p009
interview_review_info_archive_9  (cost=0.00..0.11 rows=1 width=40)
(103 rows)
Time: 3.392 ms


-- 
Maxim Boguk
Senior Postgresql DBA
https://dataegret.com/

Phone UA: +380 99 143 0000
Phone AU: +61  45 218 5678