Hi. Fujita-san pointed out in a nearby thread [1] that EXPLAIN ANALYZE shows duplicate stats for partitions' triggers.
Example: create table p (a int) partition by list (a); create table p1 partition of p for values in (1); create table p2 partition of p for values in (2); create table p3 partition of p for values in (3); create trigger show_data before update on p1 for each row execute procedure trig_notice_func(); create trigger show_data before update on p2 for each row execute procedure trig_notice_func(); insert into p values (1), (2); explain (analyze, costs off, timing off) update p set a = a + 1; NOTICE: OLD: (1); NEW: (2) NOTICE: OLD: (2); NEW: (3) QUERY PLAN ---------------------------------------------- Update on p (actual rows=0 loops=1) Update on p1 Update on p2 Update on p3 -> Seq Scan on p1 (actual rows=1 loops=1) -> Seq Scan on p2 (actual rows=1 loops=1) -> Seq Scan on p3 (actual rows=0 loops=1) Planning time: 2.000 ms Trigger show_data on p1: calls=1 Trigger show_data on p2: calls=1 Trigger show_data on p1: calls=1 Trigger show_data on p2: calls=1 Execution time: 4.228 ms (13 rows) See that the information about the trigger show_data is shown twice for partitions p1 and p2. That happens because ExplainPrintTriggers() goes through both es_result_relations and es_leaf_result_relations to show the trigger information. As Fujita-san pointed out in the linked email, ExecSetupPartitionTupleRouting() adds a partition ResultRelInfo to es_leaf_result_relations even if it may already have been present in es_result_relations, which happens if a ResultRelInfo is reused in the case of update tuple routing. Attached is a patch to fix that. After the patch: explain (analyze, costs off, timing off) update p set a = a + 1; NOTICE: OLD: (1); NEW: (2) NOTICE: OLD: (2); NEW: (3) QUERY PLAN ---------------------------------------------- Update on p (actual rows=0 loops=1) Update on p1 Update on p2 Update on p3 -> Seq Scan on p1 (actual rows=1 loops=1) -> Seq Scan on p2 (actual rows=1 loops=1) -> Seq Scan on p3 (actual rows=0 loops=1) Planning time: 0.627 ms Trigger show_data on p1: calls=1 Trigger show_data on p2: calls=1 Execution time: 1.443 ms (11 rows) When working on this, I wondered if the es_leaf_result_relations should actually be named something like es_tuple_routing_result_rels, to denote the fact that they're created by tuple routing code. The current name might lead to someone thinking that it contains *all* leaf result rels, but that won't remain true after this patch. Thoughts? Thanks, Amit [1] https://www.postgresql.org/message-id/5A783549.4020409%40lab.ntt.co.jp
From 31e119c1adc34fabbf87d4516c8e37e1cd41e90b Mon Sep 17 00:00:00 2001 From: amit <amitlangot...@gmail.com> Date: Tue, 6 Feb 2018 10:40:45 +0900 Subject: [PATCH v1] Fix trigger behavior with update tuple routing Trigger stats shown by EXPLAIN ANALYZE may contain duplicate entries, because leaf partitions' ResultRelInfo is redundantly present in multiple EState lists. Reported by: Etsuro Fujita --- src/backend/executor/execPartition.c | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/src/backend/executor/execPartition.c b/src/backend/executor/execPartition.c index 106a96d910..619a8d7a99 100644 --- a/src/backend/executor/execPartition.c +++ b/src/backend/executor/execPartition.c @@ -178,6 +178,13 @@ ExecSetupPartitionTupleRouting(ModifyTableState *mtstate, resultRTindex, rel, estate->es_instrument); + + /* + * Since we're newly creating this ResultRelInfo, add it to + * someplace where explain.c could find them. + */ + estate->es_leaf_result_relations = + lappend(estate->es_leaf_result_relations, leaf_part_rri); } part_tupdesc = RelationGetDescr(partrel); @@ -210,9 +217,6 @@ ExecSetupPartitionTupleRouting(ModifyTableState *mtstate, mtstate != NULL && mtstate->mt_onconflict != ONCONFLICT_NONE); - estate->es_leaf_result_relations = - lappend(estate->es_leaf_result_relations, leaf_part_rri); - proute->partitions[i] = leaf_part_rri; i++; } -- 2.11.0