Troubleshoot performance related issue with nested SQL in function/procedure

 Verify that auto_explain works with ONLY shared_preload_libraries set to include auto_explain.

SET client_min_messages = 'log';
SET auto_explain.log_min_duration = 0;
SET auto_explain.log_analyze = true;
SET auto_explain.log_buffers = true;
SET auto_explain.log_nested_statements = true;

-- Test SQL Example
SELECT * FROM get_customer_summary(1, 'completed');

Output shows all 4 nested queries:

LOG:  duration: 0.008 ms  plan:
Query Text: SELECT 1.1
Result  (cost=0.00..0.01 rows=1 width=32) (actual time=0.002..0.003 rows=1 loops=1)
  Output: 1.1
Query Identifier: -7531280629008474172

LOG:  duration: 1.193 ms  plan:
Query Text: SELECT COUNT(*) FROM orders o WHERE o.customer_id = p_customer_id
Aggregate  (cost=18.63..18.64 rows=1 width=8) (actual time=1.176..1.176 rows=1 loops=1)
  Output: count(*)
  Buffers: shared read=1
  I/O Timings: shared read=1.144
  ->  Seq Scan on public.orders o  (cost=0.00..18.62 rows=3 width=0)
        Filter: (o.customer_id = 1)
        Rows Removed by Filter: 3
Query Identifier: -2397021968848467034

LOG:  duration: 1507.592 ms  plan:
Query Text: SELECT COUNT(*), pg_sleep(1.5) FROM orders o WHERE o.customer_id = p_customer_id
Aggregate  (cost=18.63..18.65 rows=1 width=12) (actual time=1507.585..1507.586 rows=1 loops=1)
  Output: count(*), pg_sleep('1.5'::double precision)
  Buffers: shared hit=1
  ->  Seq Scan on public.orders o  (cost=0.00..18.62 rows=3 width=0)
        Filter: (o.customer_id = 1)
        Rows Removed by Filter: 3
Query Identifier: -5717035855382371184

LOG:  duration: 0.025 ms  plan:
Query Text: SELECT o.customer_id, COUNT(*)::BIGINT, ...
GroupAggregate  (cost=0.00..20.37 rows=1 width=108) (actual time=0.022..0.022 rows=1 loops=1)
  Output: customer_id, count(*), sum((amount * 1.1)), avg((amount * 1.1)), 'completed'::character varying
  Buffers: shared hit=1
  ->  Seq Scan on public.orders o  (cost=0.00..20.35 rows=1 width=20)
        Filter: ((o.customer_id = 1) AND ((o.status)::text = 'completed'::text))
        Rows Removed by Filter: 3
Query Identifier: 4827049925723211578

LOG:  duration: 1589.046 ms  plan:
Query Text: SELECT * FROM get_customer_summary(1, 'completed');
Function Scan on public.get_customer_summary  (cost=0.25..10.25 rows=1000 width=108)
  Output: customer_id, total_orders, total_amount, avg_amount, status_filter
  Function Call: get_customer_summary(1, 'completed'::character varying)
  Buffers: shared hit=470 read=60
Query Identifier: 2175165029487630477

 customer_id | total_orders | total_amount |     avg_amount      | status_filter 
-------------+--------------+--------------+---------------------+---------------
           1 |            2 |      193.325 | 96.6625000000000000 | completed

Time: 1839.588 ms (00:01.840)