Обсуждение: BUG #17870: Analyze on remote postgresql_fdw table never finish
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
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
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
Senior Postgresql DBA
https://dataegret.com/
Phone UA: +380 99 143 0000
Phone AU: +61 45 218 5678