Thread

  1. BUG #17870: Analyze on remote postgresql_fdw table never finish

    PG Bug reporting form <noreply@postgresql.org> — 2023-03-27T07:35:39Z

    The following bug has been logged on the website:
    
    Bug reference:      17870
    Logged by:          Maxim Boguk
    Email address:      maxim.boguk@gmail.com
    PostgreSQL version: 13.9
    Operating system:   Linux
    Description:        
    
    Hi,
    
    I found strange situation when I try to populate local statistic from remote
    postgesql_fdw table:
    analyze verbose cold_replica_fdw.interview_review_info_archive;
    - never ends,
    
    Local and remote DB in the same datacenter with more total bandwidth 20Gbps
    and latency under 0.1ms (both tested/verified), so no network issues.
    
    What I see on local side with set client_min_messages to debug5;:
    hh_data=# analyze verbose cold_replica_fdw.interview_review_info_archive;
    DEBUG:  discarding connection 0x563656981900
    DEBUG:  sinval catchup complete, cleaning queue
    DEBUG:  StartTransaction(1) name: unnamed; blockState: DEFAULT; state:
    INPROGRESS, xid/subid/cid: 0/1/0
    DEBUG:  CommitTransaction(1) name: unnamed; blockState: STARTED; state:
    INPROGRESS, xid/subid/cid: 0/1/0
    DEBUG:  StartTransaction(1) name: unnamed; blockState: DEFAULT; state:
    INPROGRESS, xid/subid/cid: 0/1/0
    DEBUG:  new postgres_fdw connection 0x56365698fc40 for server "cold_replica"
    (user mapping oid 263996607, userid 10)
    DEBUG:  starting remote transaction on connection 0x56365698fc40
    INFO:  analyzing "cold_replica_fdw.interview_review_info_archive"
    and  stays there for hours...
    
    What I see on the remove database with log_min_duration_statement set to 0
    to FDW user:
    2023-03-27 10:11:24.763 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/0 txid:0] [SET] LOG:  duration: 0.086 ms  statement: SET
    application_name='postgres_fdw';
    2023-03-27 10:11:24.763 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/0 txid:0] [SET] LOG:  duration: 0.029 ms  statement: SET
    search_path = pg_catalog
    2023-03-27 10:11:24.764 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/0 txid:0] [SET] LOG:  duration: 0.166 ms  statement: SET timezone =
    'UTC'
    2023-03-27 10:11:24.764 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/0 txid:0] [SET] LOG:  duration: 0.023 ms  statement: SET datestyle
    = ISO
    2023-03-27 10:11:24.765 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/0 txid:0] [SET] LOG:  duration: 0.032 ms  statement: SET
    intervalstyle = postgres
    2023-03-27 10:11:24.765 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/0 txid:0] [SET] LOG:  duration: 0.032 ms  statement: SET
    extra_float_digits = 3
    2023-03-27 10:11:24.766 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/356802672 txid:0] [START TRANSACTION] LOG:  duration: 0.021 ms 
    statement: START TRANSACTION ISOLATION LEVEL REPEATABLE READ
    2023-03-27 10:11:24.767 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/356802672 txid:0] [SELECT] LOG:  duration: 0.446 ms  statement:
    SELECT
    pg_catalog.pg_relation_size('public.interview_review_info_archive'::pg_catalog.regclass)
    / 8192
    2023-03-27 10:11:24.861 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/356802672 txid:0] [DECLARE CURSOR] LOG:  duration: 92.942 ms 
    statement: DECLARE c1 CURSOR FOR 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
    2023-03-27 10:11:28.268 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/356802672 txid:0] [FETCH] LOG:  duration: 3406.462 ms  statement:
    FETCH 100 FROM c1
    2023-03-27 10:11:28.269 UTC 636130
    negotiation_chat_archive_ro.fdw@negotiation_chat_archive from [local]
    [vxid:39/356802672 txid:0] [FETCH] LOG:  duration: 0.094 ms  statement:
    FETCH 100 FROM c1
    
    and then continue fetch forever, on the last attempt it fetched from cursor
    over 5M times before I canceled analyze statement.
    
    public.interview_review_info_archive - huge native partitioned by range
    table with 100 partitions and 2TB+ size.
    
    Is it expected that the analyze of foreign table will fetch whole table to
    local size (quite a task for 2TB table)?
    
    PS: I don't want enable a remote estimates because it adds huge planning
    overhead (with remote_estimate 'true'):
     Foreign Scan on cold_replica_fdw.interview_review_info_archive 
    (cost=14.10..14.14 rows=1 width=40) (actual time=3.966..4.681 rows=1
    loops=1)
       Output: topic_id, review_id, move_to_invitation_state_time,
    no_interview_reply_time, review_suggestion_chat_message_creation_time
       Remote SQL: 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 ORDER BY topic_id ASC NULLS LAST LIMIT
    1::bigint
     Planning Time: 13.646 ms
     Execution Time: 5.347 ms
    
    
  2. Re: BUG #17870: Analyze on remote postgresql_fdw table never finish

    Tom Lane <tgl@sss.pgh.pa.us> — 2023-03-27T14:43:13Z

    PG Bug reporting form <noreply@postgresql.org> writes:
    > Is it expected that the analyze of foreign table will fetch whole table to
    > local size (quite a task for 2TB table)?
    
    Yes.  There's an improvement in the works for v16 (8ad51b5f4).
    
    			regards, tom lane
    
    
    
    
  3. Re: BUG #17870: Analyze on remote postgresql_fdw table never finish

    Maxim Boguk <maxim.boguk@gmail.com> — 2023-03-28T06:34:32Z

    On Tue, Mar 28, 2023 at 1:43 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
    
    > PG Bug reporting form <noreply@postgresql.org> writes:
    > > Is it expected that the analyze of foreign table will fetch whole table
    > to
    > > local size (quite a task for 2TB table)?
    >
    > Yes.  There's an improvement in the works for v16 (8ad51b5f4).
    >
    >                         regards, tom lane
    >
    
    Thank you for an explanation.
    So using use_remote_estimate only way to work with huge fdw tables atm.
    Is this behaviour of analyze over fdw documented somewhere?
    
    
    -- 
    Maxim Boguk
    Senior Postgresql DBA
    https://dataegret.com/
    
    Phone UA: +380 99 143 0000
    Phone AU: +61  45 218 5678