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 (Postgres query plan of a UDF invocation written in pgpsql), we discovered auto_explain.
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?