# Отчет

    => CREATE FUNCTION qty(aircraft_code char, fare_conditions varchar)
    RETURNS bigint AS $$
      SELECT count(*)
      FROM flights f
        JOIN boarding_passes bp ON bp.flight_id = f.flight_id
        JOIN seats s ON s.aircraft_code = f.aircraft_code AND s.seat_no = bp.seat_no
      WHERE f.aircraft_code = qty.aircraft_code AND s.fare_conditions = qty.fare_conditions;
    $$ STABLE LANGUAGE sql;

    CREATE FUNCTION

    => CREATE FUNCTION report()
    RETURNS TABLE(model text, economy bigint, comfort bigint, business bigint)
    AS $$
    DECLARE
      r record;
    BEGIN
      FOR r IN SELECT a.aircraft_code, a.model FROM aircrafts a ORDER BY a.model LOOP
        report.model := r.model;
        report.economy := qty(r.aircraft_code, 'Economy');
        report.comfort := qty(r.aircraft_code, 'Comfort');
        report.business := qty(r.aircraft_code, 'Business');
        RETURN NEXT;
      END LOOP;
    END;
    $$ STABLE LANGUAGE plpgsql;

    CREATE FUNCTION

Включаем вывод операторов и времени их выполнения в журнал:

    => SET log_min_duration_statement = 0;

    SET

    => SELECT * FROM report();

            model        | economy | comfort | business
    ---------------------+---------+---------+----------
     Аэробус A319-100    |  337129 |       0 |    70232
     Аэробус A320-200    |       0 |       0 |        0
     Аэробус A321-200    |  649388 |       0 |   127982
     Боинг 737-300       |  589901 |       0 |    59829
     Боинг 767-300       |  817621 |       0 |   127947
     Боинг 777-300       |  895896 |  132571 |    83080
     Бомбардье CRJ-200   | 1155683 |       0 |        0
     Сессна 208 Караван  |  111096 |       0 |        0
     Сухой Суперджет-100 | 2425034 |       0 |   342423
    (9 rows)

# Сообщения в журнале

    postgres$ tail -n 1 /var/log/postgresql/postgresql-10-main.log

    2019-02-13 13:18:07.598 MSK [15142] postgres@demo LOG:  duration: 26297.018 ms  statement: SELECT * FROM report();

Вложенные SQL-операторы не выводятся.

# Расширение auto_explain

    => LOAD 'auto_explain';

    LOAD

    => RESET log_min_duration_statement;

    RESET

    => SET auto_explain.log_min_duration = 0;

    SET

    => SET auto_explain.log_nested_statements = on;

    SET

    => SELECT * FROM report();

            model        | economy | comfort | business
    ---------------------+---------+---------+----------
     Аэробус A319-100    |  337129 |       0 |    70232
     Аэробус A320-200    |       0 |       0 |        0
     Аэробус A321-200    |  649388 |       0 |   127982
     Боинг 737-300       |  589901 |       0 |    59829
     Боинг 767-300       |  817621 |       0 |   127947
     Боинг 777-300       |  895896 |  132571 |    83080
     Бомбардье CRJ-200   | 1155683 |       0 |        0
     Сессна 208 Караван  |  111096 |       0 |        0
     Сухой Суперджет-100 | 2425034 |       0 |   342423
    (9 rows)

# Сообщения в журнале

Выведем несколько последних строк:

    postgres$ tail -n 30 /var/log/postgresql/postgresql-10-main.log

    	  ->  Gather  (cost=104104.20..104104.41 rows=2 width=8)
    	        Workers Planned: 2
    	        ->  Partial Aggregate  (cost=103104.20..103104.21 rows=1 width=8)
    	              ->  Hash Join  (cost=5453.83..102909.20 rows=78002 width=0)
    	                    Hash Cond: ((bp.seat_no)::text = (s.seat_no)::text)
    	                    ->  Hash Join  (cost=5437.56..101791.98 rows=412799 width=7)
    	                          Hash Cond: (bp.flight_id = f.flight_id)
    	                          ->  Parallel Seq Scan on boarding_passes bp  (cost=0.00..87685.35 rows=3302435 width=7)
    	                          ->  Hash  (cost=5101.84..5101.84 rows=26858 width=8)
    	                                Buckets: 65536 (originally 32768)  Batches: 1 (originally 1)  Memory Usage: 1766kB
    	                                ->  Seq Scan on flights f  (cost=0.00..5101.84 rows=26858 width=8)
    	                                      Filter: (aircraft_code = $1)
    	                    ->  Hash  (cost=15.64..15.64 rows=50 width=7)
    	                          Buckets: 1024  Batches: 1  Memory Usage: 5kB
    	                          ->  Bitmap Heap Scan on seats s  (cost=5.41..15.64 rows=50 width=7)
    	                                Recheck Cond: (aircraft_code = $1)
    	                                Filter: ((fare_conditions)::text = ($2)::text)
    	                                ->  Bitmap Index Scan on seats_pkey  (cost=0.00..5.39 rows=149 width=0)
    	                                      Index Cond: (aircraft_code = $1)
    2019-02-13 13:18:32.977 MSK [15142] postgres@demo CONTEXT:  SQL function "qty" statement 1
    	PL/pgSQL function report() line 9 at assignment
    2019-02-13 13:18:32.978 MSK [15142] postgres@demo LOG:  duration: 0.158 ms  plan:
    	Query Text: SELECT a.aircraft_code, a.model FROM aircrafts a ORDER BY a.model
    	Sort  (cost=3.51..3.53 rows=9 width=48)
    	  Sort Key: ((ml.model ->> lang()))
    	  ->  Seq Scan on aircrafts_data ml  (cost=0.00..3.36 rows=9 width=48)
    2019-02-13 13:18:32.978 MSK [15142] postgres@demo CONTEXT:  PL/pgSQL function report() line 5 at FOR over SELECT rows
    2019-02-13 13:18:32.978 MSK [15142] postgres@demo LOG:  duration: 24922.590 ms  plan:
    	Query Text: SELECT * FROM report();
    	Function Scan on report  (cost=0.25..10.25 rows=1000 width=56)

В журнал попадают вложенные запросы и планы выполнения - собственно, это и есть основная функция расширения.