Thread: unreliable behaviour of track_functions
Hi All!
I've been experimenting with track_functions options and what I've saw it's
really puzzling me.
Documentation says:
/ SQL-language functions that are simple enough to be "inlined" into the
calling query will not be tracked, regardless of this setting./
But it came up, it depends on much more factors, like duration or placing it
in the query, it is totally non-deterministic behaviour.
This really simple SQL function:
CREATE FUNCTION a(a bigint)
RETURNS bigint
STABLE
LANGUAGE SQL
AS $$
SELECT $1
$$;
Is not shown in the pg_stat_user_functions at all. It is started to be shown
when one line:
select pg_sleep(1);
is added???
Another one, gets tracked only if I use:
SELECT get_unique_term(2556);
If it lands in FROM then it's not tracked...
SELECT * FROM get_unique_term(2556);
That's the body of the function:
CREATE FUNCTION get_unique_term(i_game_pin bigint)
RETURNS TABLE(term text, category text)
STABLE
LANGUAGE SQL
AS $$
SELECT
i.term,
i.dict_category_id
FROM (SELECT
categories.term,
categories.dict_category_id
FROM categories
EXCEPT ALL
SELECT
games.term,
games.category
FROM games
WHERE game_pin = $1) i
ORDER BY (random())
LIMIT 1;
$$;
What's going on here? That's pretty unreliable behaviour...
My version of postgres:
PostgreSQL 9.6.6 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.3
20140911 (Red Hat 4.8.3-9), 64-bit
show track_functions;
track_functions
-----------------
all
(1 wiersz)
--
Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html
On 03/31/2018 04:40 PM, pinker wrote: > Hi All! > > I've been experimenting with track_functions options and what I've saw it's > really puzzling me. > Documentation says: > / SQL-language functions that are simple enough to be "inlined" into the > calling query will not be tracked, regardless of this setting./ > > But it came up, it depends on much more factors, like duration or placing it > in the query, it is totally non-deterministic behaviour. > > This really simple SQL function: > CREATE FUNCTION a(a bigint) > RETURNS bigint > STABLE > LANGUAGE SQL > AS $$ > SELECT $1 > $$; > > Is not shown in the pg_stat_user_functions at all. It is started to be shown > when one line: > select pg_sleep(1); > > is added??? > > Another one, gets tracked only if I use: > SELECT get_unique_term(2556); > > If it lands in FROM then it's not tracked... > SELECT * FROM get_unique_term(2556); > > That's the body of the function: > CREATE FUNCTION get_unique_term(i_game_pin bigint) > RETURNS TABLE(term text, category text) > STABLE > LANGUAGE SQL > AS $$ > SELECT > i.term, > i.dict_category_id > FROM (SELECT > categories.term, > categories.dict_category_id > FROM categories > EXCEPT ALL > SELECT > games.term, > games.category > FROM games > WHERE game_pin = $1) i > ORDER BY (random()) > LIMIT 1; > $$; > > What's going on here? That's pretty unreliable behaviour... ?: https://www.postgresql.org/docs/10/static/monitoring-stats.html#PG-STAT-USER-FUNCTIONS-VIEW "...But if you want to see new results with each query, be sure to do the queries outside any transaction block. Alternatively, you can invoke pg_stat_clear_snapshot(), which will discard the current transaction's statistics snapshot (if any). The next use of statistical information will cause a new snapshot to be fetched. A transaction can also see its own statistics (as yet untransmitted to the collector) in the views pg_stat_xact_all_tables, pg_stat_xact_sys_tables, pg_stat_xact_user_tables, and pg_stat_xact_user_functions. These numbers do not act as stated above; instead they update continuously throughout the transaction. " > > > My version of postgres: > PostgreSQL 9.6.6 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.3 > 20140911 (Red Hat 4.8.3-9), 64-bit > > show track_functions; > track_functions > ----------------- > all > (1 wiersz) > > > > > > > > > -- > Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html > > -- Adrian Klaver adrian.klaver@aklaver.com
Adrian Klaver-4 wrote > https://www.postgresql.org/docs/10/static/monitoring-stats.html#PG-STAT-USER-FUNCTIONS-VIEW > > "...But if you want to see new results with each query, be sure to do > the queries outside any transaction block. Alternatively, you can invoke > pg_stat_clear_snapshot(), which will discard the current transaction's > statistics snapshot (if any). The next use of statistical information > will cause a new snapshot to be fetched. > > A transaction can also see its own statistics (as yet untransmitted to > the collector) in the views pg_stat_xact_all_tables, > pg_stat_xact_sys_tables, pg_stat_xact_user_tables, and > pg_stat_xact_user_functions. These numbers do not act as stated above; > instead they update continuously throughout the transaction. > > " > Adrian Klaver > adrian.klaver@ Thank you for that, but does this strange behaviour should not be better documented? If somebody (like me, I have some time ago being unaware of this behaviour) wants to build a monitoring system that base on the view pg_stat_user_functions, should not be informed what to expect? -- Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html
On 03/31/2018 05:17 PM, pinker wrote: > Adrian Klaver-4 wrote >> https://www.postgresql.org/docs/10/static/monitoring-stats.html#PG-STAT-USER-FUNCTIONS-VIEW >> >> "...But if you want to see new results with each query, be sure to do >> the queries outside any transaction block. Alternatively, you can invoke >> pg_stat_clear_snapshot(), which will discard the current transaction's >> statistics snapshot (if any). The next use of statistical information >> will cause a new snapshot to be fetched. >> >> A transaction can also see its own statistics (as yet untransmitted to >> the collector) in the views pg_stat_xact_all_tables, >> pg_stat_xact_sys_tables, pg_stat_xact_user_tables, and >> pg_stat_xact_user_functions. These numbers do not act as stated above; >> instead they update continuously throughout the transaction. >> >> " >> Adrian Klaver > >> adrian.klaver@ > > > Thank you for that, but does this strange behaviour should not be better > documented? This came from the documentation, so I am not sure what you mean by better documented? > If somebody (like me, I have some time ago being unaware of this behaviour) > wants to build a monitoring system that base on the view > pg_stat_user_functions, should not be informed what to expect? See comment above. > > > > > -- > Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html > > -- Adrian Klaver adrian.klaver@aklaver.com
I mean this part describing track_function: https://www.postgresql.org/docs/10/static/runtime-config-statistics.html Enables tracking of function call counts and time used. Specify pl to track only procedural-language functions, all to also track SQL and C language functions. The default is none, which disables function statistics tracking. Only superusers can change this setting. Note SQL-language functions that are simple enough to be “inlined” into the calling query will not be tracked, regardless of this setting. Only case described here, that exclude function from being tracked it's inlining, not the time and not the place in the query. So I would expect that pg_stat_user_function will show me that my function was executed. Good that are other ways to do it, but changing track_functions to 'all' I would expect all calls will be tracked... -- Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html
I mean this part describing track_function: https://www.postgresql.org/docs/10/static/runtime-config-statistics.html Enables tracking of function call counts and time used. Specify pl to track only procedural-language functions, all to also track SQL and C language functions. The default is none, which disables function statistics tracking. Only superusers can change this setting. Note SQL-language functions that are simple enough to be “inlined” into the calling query will not be tracked, regardless of this setting. Only case described here, that exclude function from being tracked it's inlining, not the time and not the place in the query. So I would expect that pg_stat_user_function will show me that my function was executed. Good that are other ways to do it, but changing track_functions to 'all' I would expect all calls will be tracked... -- Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html
and to be clear I was experimenting with pg_stat_clear_snapshot() after your answer, but it doesn't change behaviour of track_functions. -- Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html
On 04/01/2018 06:02 AM, pinker wrote: > I mean this part describing track_function: > > https://www.postgresql.org/docs/10/static/runtime-config-statistics.html > > Enables tracking of function call counts and time used. Specify pl to track > only procedural-language functions, all to also track SQL and C language > functions. The default is none, which disables function statistics tracking. > Only superusers can change this setting. > > Note > SQL-language functions that are simple enough to be “inlined” into the > calling query will not be tracked, regardless of this setting. > > Only case described here, that exclude function from being tracked it's > inlining, not the time and not the place in the query. The below might help: https://wiki.postgresql.org/wiki/Inlining_of_SQL_functions In particular for your second case(place in query): " Table functions A table function call is any instance where func(args) appears where a table is expected. (This is, for most functions, a PostgreSQL extension to the SQL standard.) For example: select * from func(123); " For your first case: Inlining conditions for scalar functions "the function body consists of a single, simple, SELECT expression" So from your OP: CREATE FUNCTION a(a bigint) RETURNS bigint STABLE LANGUAGE SQL AS $$ SELECT $1 $$; If you change to: CREATE FUNCTION a(a bigint) RETURNS bigint STABLE LANGUAGE SQL AS $$ SELECT 'test'; SELECT $1 $$; then before change: test=> select * from pg_stat_user_functions ; funcid | schemaname | funcname | calls | total_time | self_time ---------+------------+----------+-------+------------+----------- 1386647 | public | a | 2 | 1251.598 | 1251.598 (1 row) after change: test=> select * from pg_stat_user_functions ; funcid | schemaname | funcname | calls | total_time | self_time ---------+------------+----------+-------+------------+----------- 1386647 | public | a | 3 | 1251.682 | 1251.682 > So I would expect that pg_stat_user_function will show me that my function > was executed. Good that are other ways to do it, but changing > track_functions to 'all' I would expect all calls will be tracked... > > > > -- > Sent from: http://www.postgresql-archive.org/PostgreSQL-general-f1843780.html > > -- Adrian Klaver adrian.klaver@aklaver.com