На своем сервере Postgres я использую модуль auto_explain
с включенным log_nested_statements
для регистрации других вызовов функций в функциях PL / pgSQL.
594 session_preload_libraries = 'auto_explain'
595
596 auto_explain.log_min_duration = 0
597 auto_explain.log_nested_statements = true
598 auto_explain.sample_rate = 1.0
У меня есть игрушечная функция PL / pgSQL baz(count int)
:
Schema | public
Name | baz
Result data type | text
Argument data types | count integer
Type | normal
Volatility | volatile
Parallel | unsafe
Owner | aerust
Security | invoker
Access privileges |
Language | plpgsql
Source code | +
| DECLARE +
| i int := 0; +
| result text := ''; +
| BEGIN +
| +
| IF (count < 1) THEN +
| RETURN result; +
| END IF; +
| +
| LOOP +
| EXIT WHEN i = count; +
| i := i + 1; +
| result := result || ' ' || foo();+
| END LOOP; +
| +
| RETURN result; +
| END; +
|
Description |
, который вызывает функцию SQL foo()
:
Schema | public
Name | foo
Result data type | text
Argument data types |
Type | normal
Volatility | immutable
Parallel | unsafe
Owner | aerust
Security | invoker
Access privileges |
Language | sql
Source code | SELECT 'foo ' || bar()
Description |
При первом вызове функции baz(1)
в соединении с базой данных я вижу, что каждый вложенный оператор регистрируется какчасть плана:
2019-03-19 15:25:05.765 PDT [37616] LOG: statement: select baz(1);
2019-03-19 15:25:05.768 PDT [37616] LOG: duration: 0.002 ms plan:
Query Text: SELECT 'bar'
Result (cost=0.00..0.01 rows=1 width=32)
2019-03-19 15:25:05.768 PDT [37616] CONTEXT: SQL function "bar" statement 1
SQL function "foo" during startup
SQL statement "SELECT result || ' ' || foo()"
PL/pgSQL function foo(integer) line 14 at assignment
2019-03-19 15:25:05.768 PDT [37616] LOG: duration: 0.001 ms plan:
Query Text: SELECT 'foo ' || bar()
Result (cost=0.00..0.01 rows=1 width=32)
2019-03-19 15:25:05.768 PDT [37616] CONTEXT: SQL function "foo" statement 1
SQL statement "SELECT result || ' ' || foo()"
PL/pgSQL function foo(integer) line 14 at assignment
2019-03-19 15:25:05.768 PDT [37616] LOG: duration: 0.952 ms plan:
Query Text: select baz(1);
Result (cost=0.00..0.26 rows=1 width=32)
Но, когда я снова вызываю функцию для того же соединения, я не вижу вложенных операторов в журналах:
2019-03-19 15:29:06.608 PDT [37616] LOG: statement: select baz(1);
2019-03-19 15:29:06.608 PDT [37616] LOG: duration: 0.046 ms plan:
Query Text: select baz(1);
Result (cost=0.00..0.26 rows=1 width=32)
Почему это так?И как получить вложенные операторы для регистрации при последующих вызовах функции во время того же подключения к базе данных?