Re: [HACKERS] Stats for triggers on partitioned tables not shown in EXPLAIN ANALYZE
On Fri, Aug 18, 2017 at 1:15 AM, Noah Misch wrote: > The above-described topic is currently a PostgreSQL 10 open item. Robert, > since you committed the patch believed to have created it, you own this open > item. If some other commit is more relevant or if this does not belong as a > v10 open item, please let us know. Otherwise, please observe the policy on > open item ownership[1] and send a status update within three calendar days of > this message. Include a date for your subsequent status update. Testers may > discover new open items at any time, and I want to plan to get them all fixed > well in advance of shipping v10. Consequently, I will appreciate your efforts > toward speedy resolution. Thanks. > > [1] > https://www.postgresql.org/message-id/20170404140717.GA2675809%40tornado.leadboat.com Committed and back-patched the proposed patch. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] Stats for triggers on partitioned tables not shown in EXPLAIN ANALYZE
Fujita-san, Thanks for reporting the bugs and patches to fix the same. On 2017/08/15 21:20, Etsuro Fujita wrote: > Hi hackers, > > I noticed that runtime stats for BEFORE ROW INSERT triggers on leaf > partitions of partitioned tables aren't reported in EXPLAIN ANALYZE. Here > is an example: > > postgres=# create table trigger_test (a int, b text) partition by list (a); > CREATE TABLE > postgres=# create table trigger_test1 partition of trigger_test for values > in (1); > CREATE TABLE > postgres=# create trigger before_ins_row_trig BEFORE INSERT ON > trigger_test1 FOR EACH ROW EXECUTE PROCEDURE trigger_data(); > CREATE TRIGGER > postgres=# create trigger after_ins_row_trig AFTER INSERT ON trigger_test1 > FOR EACH ROW EXECUTE PROCEDURE trigger_data(); > CREATE TRIGGER > postgres=# explain analyze insert into trigger_test values (1, 'foo'); > NOTICE: before_ins_row_trig() BEFORE ROW INSERT ON trigger_test1 > NOTICE: NEW: (1,foo) > NOTICE: after_ins_row_trig() AFTER ROW INSERT ON trigger_test1 > NOTICE: NEW: (1,foo) > QUERY PLAN > - > > Insert on trigger_test (cost=0.00..0.01 rows=1 width=36) (actual > time=0.193..0.193 rows=0 loops=1) >-> Result (cost=0.00..0.01 rows=1 width=36) (actual time=0.002..0.003 > rows=1 loops=1) > Planning time: 0.027 ms > Trigger after_ins_row_trig on trigger_test1: time=0.075 calls=1 > Execution time: 0.310 ms > (5 rows) > > where trig_data() is borrowed from the regression test in postgres_fdw. > The stats for the AFTER ROW INSERT trigger after_ins_row_trig are well > shown in the output, but the stats for the BEFORE ROW INSERT trigger > before_ins_row_trig aren't at all. I think we should show the latter as > well. Right. ExplainPrintTriggers() is unable to find the leaf partition ResultRelInfos in the insert tuple-routing case, because they are not present in EState.es_result_relations. If a leaf partition happened to have an insert AR trigger, corresponding ResultRelInfo *would be* present in EState.es_trig_target_relations, but that would be useless to show the information about insert BR triggers that might also be present, because that ResultRelInfo is created long after the BR triggers are executed. So, the instrumentation information corresponding to the BR triggers' invocation is not updated in that ResultRelInfo, giving the impression that they were never invoked (report_triggers does not list such triggers). > Another thing I noticed is: runtime stats for BEFORE STATEMENT > UPDATE/DELETE triggers on partitioned table roots aren't reported in > EXPLAIN ANALYZE, either, as shown in a below example: > > postgres=# create trigger before_upd_stmt_trig BEFORE UPDATE ON > trigger_test FOR EACH STATEMENT EXECUTE PROCEDURE trigger_func(); > CREATE TRIGGER > postgres=# create trigger after_upd_stmt_trig AFTER UPDATE ON trigger_test > FOR EACH STATEMENT EXECUTE PROCEDURE trigger_func(); > CREATE TRIGGER > postgres=# explain analyze update trigger_test set b = 'bar' where a = 1; > NOTICE: trigger_func() called: action = UPDATE, when = BEFORE, > level = STATEMENT > NOTICE: trigger_func() called: action = UPDATE, when = AFTER, level > = STATEMENT > QUERY PLAN > > -- > > - > Update on trigger_test (cost=0.00..25.88 rows=6 width=42) (actual > time=0.296..0.296 rows=0 loops=1) >Update on trigger_test1 >-> Seq Scan on trigger_test1 (cost=0.00..25.88 rows=6 width=42) > (actual time=0.010..0.011 rows=1 loops=1) > Filter: (a = 1) > Planning time: 0.152 ms > Trigger after_upd_stmt_trig on trigger_test: time=0.141 calls=1 > Execution time: 0.476 ms > (7 rows) > > where trigger_func() is borrowed from the regression test, too. The stats > for the BEFORE STATEMENT UPDATE trigger before_upd_stmt_trig aren't shown > at all in the output. I think this should also be fixed. Yes. Again, ExplainPrintTriggers() fails to find the ResultRelInfos for the root partitioned table in the update/delete cases, because they are not present in EState.es_result_relations. If the root partitioned table happened to have an AS trigger, corresponding ResultRelInfo *would be* present in EState.es_trig_target_relations, but that would be useless to show the information about update/delete BS triggers that might also be present, because that ResultRelInfo is created long after the BS triggers are executed. So, the instrumentation information corresponding to the BS triggers' invocation is not updated in that ResultRelInfo, giving the impression that they were never invoked. > So here is a > patch for fixing both issues. Changes I made are: > > * To fix the former, I added a new List member es_leaf_result_relations to > EState, modified ExecSetupPartitionTupl
[HACKERS] Stats for triggers on partitioned tables not shown in EXPLAIN ANALYZE
Hi hackers, I noticed that runtime stats for BEFORE ROW INSERT triggers on leaf partitions of partitioned tables aren't reported in EXPLAIN ANALYZE. Here is an example: postgres=# create table trigger_test (a int, b text) partition by list (a); CREATE TABLE postgres=# create table trigger_test1 partition of trigger_test for values in (1); CREATE TABLE postgres=# create trigger before_ins_row_trig BEFORE INSERT ON trigger_test1 FOR EACH ROW EXECUTE PROCEDURE trigger_data(); CREATE TRIGGER postgres=# create trigger after_ins_row_trig AFTER INSERT ON trigger_test1 FOR EACH ROW EXECUTE PROCEDURE trigger_data(); CREATE TRIGGER postgres=# explain analyze insert into trigger_test values (1, 'foo'); NOTICE: before_ins_row_trig() BEFORE ROW INSERT ON trigger_test1 NOTICE: NEW: (1,foo) NOTICE: after_ins_row_trig() AFTER ROW INSERT ON trigger_test1 NOTICE: NEW: (1,foo) QUERY PLAN - Insert on trigger_test (cost=0.00..0.01 rows=1 width=36) (actual time=0.193..0.193 rows=0 loops=1) -> Result (cost=0.00..0.01 rows=1 width=36) (actual time=0.002..0.003 rows=1 loops=1) Planning time: 0.027 ms Trigger after_ins_row_trig on trigger_test1: time=0.075 calls=1 Execution time: 0.310 ms (5 rows) where trig_data() is borrowed from the regression test in postgres_fdw. The stats for the AFTER ROW INSERT trigger after_ins_row_trig are well shown in the output, but the stats for the BEFORE ROW INSERT trigger before_ins_row_trig aren't at all. I think we should show the latter as well. Another thing I noticed is: runtime stats for BEFORE STATEMENT UPDATE/DELETE triggers on partitioned table roots aren't reported in EXPLAIN ANALYZE, either, as shown in a below example: postgres=# create trigger before_upd_stmt_trig BEFORE UPDATE ON trigger_test FOR EACH STATEMENT EXECUTE PROCEDURE trigger_func(); CREATE TRIGGER postgres=# create trigger after_upd_stmt_trig AFTER UPDATE ON trigger_test FOR EACH STATEMENT EXECUTE PROCEDURE trigger_func(); CREATE TRIGGER postgres=# explain analyze update trigger_test set b = 'bar' where a = 1; NOTICE: trigger_func() called: action = UPDATE, when = BEFORE, level = STATEMENT NOTICE: trigger_func() called: action = UPDATE, when = AFTER, level = STATEMENT QUERY PLAN -- - Update on trigger_test (cost=0.00..25.88 rows=6 width=42) (actual time=0.296..0.296 rows=0 loops=1) Update on trigger_test1 -> Seq Scan on trigger_test1 (cost=0.00..25.88 rows=6 width=42) (actual time=0.010..0.011 rows=1 loops=1) Filter: (a = 1) Planning time: 0.152 ms Trigger after_upd_stmt_trig on trigger_test: time=0.141 calls=1 Execution time: 0.476 ms (7 rows) where trigger_func() is borrowed from the regression test, too. The stats for the BEFORE STATEMENT UPDATE trigger before_upd_stmt_trig aren't shown at all in the output. I think this should also be fixed. So here is a patch for fixing both issues. Changes I made are: * To fix the former, I added a new List member es_leaf_result_relations to EState, modified ExecSetupPartitionTupleRouting so that it creates ResultRelInfos with the EState's es_instrument and then saves them in that list, and modified ExplainPrintTriggers to show stats for BEFORE ROW INSERT triggers on leaf partitions (if any) by looking at that list. I also modified copy.c so that ExecSetupPartitionTupleRouting and related things are performed in CopyFrom after its EState creation. * To fix the latter, I modified ExplainPrintTriggers to show stats for BEFORE STATEMENT UPDATE/DELETE triggers on partitioned table roots (if any) by looking at the es_root_result_relations array. * While fixing these, I noticed that AFTER ROW INSERT triggers on leaf partitions and BEFORE STATEMENT UPDATE/DELETE triggers on partitioned table roots re-open relations and re-create ResultRelInfos (trigger-only ResultRelInfos!) in ExecGetTriggerResultRel when executing triggers (and that in the above examples, the stats for AFTER ROW INSERT trigger/AFTER STATEMENT UPDATE trigger are shown the result for es_trig_target_relations in ExplainPrintTriggers). But that wouldn't be efficient (and EXPLAIN ANALYZE might produce odd outputs), so I modified ExecGetTriggerResultRel so that it searches es_leaf_result_relations and es_root_result_relations in addition to es_result_relations. Best regards, Etsuro Fujita *** a/src/backend/commands/copy.c --- b/src/backend/commands/copy.c *** *** 1415,1473 BeginCopy(ParseState *pstate, (errcode(ERRCODE_UNDEFINED_COLUMN), errmsg("table \"%s\" does not have OIDs",