Thread

  1. Re: [PATCH] Add NESTED_STATEMENTS option to EXPLAIN

    Zsolt Parragi <zsolt.parragi@percona.com> — 2026-05-28T22:08:37Z

    +<programlisting>
    +EXPLAIN (ANALYZE, NESTED_STATEMENTS, FORMAT JSON) SELECT my_function();
    
    and
    
    +   Each nested plan is a valid JSON document that can be parsed independently.
    +   The metadata headers (statement number, nesting level, query text) and the
    +   summary appear as plain text between the JSON blocks.  The
    +   <literal>Execution Time</literal> field is included inside each nested
    +   plan's JSON structure when <literal>SUMMARY</literal> is enabled.
    +   Percentages are shown only in the text-format summary, not inside the
    +   structured plan objects.0
    
    Are you sure this is correct? My expectation would be for FORMAT JSON
    to output a valid, usable JSON document. E.g.:
    
    bin/psql -X -t -A -d db -c "EXPLAIN (FORMAT JSON) SELECT ..." > file.json
    
    writes a valid json file which I can then parse with any json parser.
    
    If I do the same with NESTED_STATEMENTS, I get an invalid json. It's
    not only a concatenation of multiple json documents, but also includes
    additional completely non-json text in it. It seems difficult to
    parse/use.
    
    Same goes for XML/YAML.
    
    +			if (!is_trigger && nested_exec_level == 1 &&
    +				stmt_time > nested_slowest_time)
    +			{
    +				nested_slowest_time = stmt_time;
    +				nested_slowest_num = nested_total_count;
    +			}
    
    Why is the slowest statement check limited to nesting level 1?
    
    For example, see the following test case where it doesn't display any
    slowest statement:
    
    CREATE TABLE big(n int);
    INSERT INTO big SELECT g FROM generate_series(1, 200000) g;
    CREATE TABLE t_a(id int primary key);
    CREATE TABLE t_log(id int);
    INSERT INTO t_a VALUES (1);
    CREATE OR REPLACE FUNCTION slow_trig() RETURNS trigger LANGUAGE plpgsql AS $$
    DECLARE r bigint;
    BEGIN
      SELECT count(*) FROM big a, generate_series(1, 40) b INTO r;
      INSERT INTO t_log VALUES (NEW.id);
      RETURN NEW;
    END;
    $$;
    CREATE TRIGGER slow_trigger AFTER UPDATE ON t_a
      FOR EACH ROW EXECUTE FUNCTION slow_trig();
    EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING ON)
    UPDATE t_a SET id = id WHERE id = 1;
    
    Trigger time calculation also doesn't work for multiple nesting levels, see:
    
    CREATE TABLE t(i int);
    CREATE FUNCTION trg() RETURNS trigger LANGUAGE plpgsql AS $$
    BEGIN PERFORM pg_sleep(0.05); RETURN NEW; END $$;
    CREATE TRIGGER trg BEFORE INSERT ON t FOR EACH ROW EXECUTE FUNCTION trg();
    CREATE FUNCTION f() RETURNS void LANGUAGE plpgsql AS $$
    BEGIN INSERT INTO t VALUES(1); END $$;
    EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF, TIMING OFF, BUFFERS
    OFF) SELECT f();
    
    And staying with the topic of triggers, are you sure that all
    statements that are executed within triggers should get a trigger
    label? Wouldn't it be better to track only directly trigger-executed
    statements?
    
    +   <literal>SUMMARY</literal> is enabled.  Level-1 statements (those
    +   directly inside the called function) also show a percentage of total
    +   nested time.  Deeper-level statements show only absolute time because
    +   their time is already included in their level-1 parent's reported time.
    +   Nested statements are numbered in completion order.
    
    Wouldn't start-time ordering be better rather than completion? Right
    now, it includes children before the caller, which could look
    confusing. With a multi level difference between statement it is
    clearer, but if a level 2 statement follows a level 1 statement, my
    first thought that the level 1 statement called the level 2. But it
    didn't, the next level 1 did.