We have a number of Postgres functions that each call a number of other Postgres functions. If you simply
EXPLAIN ANALYSE a call like
SELECT parent_function(), the output is minimal, since it doesn't dive into the calls the parent_function makes.
Thanks to answers like this (Get query plan for SQL statement nested in a PL/pgSQL function), we discovered
So, we turned this stuff on:
auto_explain.log_min_duration = 0
auto_explain.log_analyze = true
auto_explain.log_verbose = true
auto_explain.log_timing = true
auto_explain.log_nested_statements = true
The good news is that it gave us what we were looking for: A way to see the timing of every nested statement called during a long-running function. However, the output is very verbose, and it's hard to see the parent-child relationship I'm "used" to seeing in profilers:
Is there a better way to view this log output? Ideally, it would group nested statements with their parents showing me, at a glance, where I should look.
pgbadger, but it's not configured to parse
auto_explain output, since
auto_explain of this verbosity isn't usually running on production servers.
Are there other log parsers (or other techniques) to help profile functions?