Thread: plpgsql plugin - stmt_beg/end is not called for top level block of statements

plpgsql plugin - stmt_beg/end is not called for top level block of statements

From
Pavel Stehule
Date:
Hi

I am playing with plpgsql profiling and and plpgsql plugin API. I found so callback stmt_beg and stmt_end was not called for top statement due direct call exec_stmt_block function.

<-->estate.err_text = NULL;
<-->estate.err_stmt = (PLpgSQL_stmt *) (func->action);
<-->rc = exec_stmt_block(&estate, func->action);
<-->if (rc != PLPGSQL_RC_RETURN)
<-->{
<--><-->estate.err_stmt = NULL;
<--><-->estate.err_text = NULL;

Isn't better to call exec_stmt there? Then plpgsql plugin function will be called really for every plpgsql statement.

Regards

Pavel

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Pavel Stehule
Date:


po 19. 11. 2018 v 19:37 odesílatel Pavel Stehule <pavel.stehule@gmail.com> napsal:
Hi

I am playing with plpgsql profiling and and plpgsql plugin API. I found so callback stmt_beg and stmt_end was not called for top statement due direct call exec_stmt_block function.

<-->estate.err_text = NULL;
<-->estate.err_stmt = (PLpgSQL_stmt *) (func->action);
<-->rc = exec_stmt_block(&estate, func->action);
<-->if (rc != PLPGSQL_RC_RETURN)
<-->{
<--><-->estate.err_stmt = NULL;
<--><-->estate.err_text = NULL;

Isn't better to call exec_stmt there? Then plpgsql plugin function will be called really for every plpgsql statement.

Now, the statement's hook is not called for every plpgsql_stmt_block statement. It is not big issue, but it is not consistent - and this inconsistency should be repaired inside extension. Better to be consistent and every plpgsql statement call identically.

patch attached - all regress tests passed. This patch has a effect only on plpgsql extensions.

Regards

Pavel


Regards

Pavel
Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Michael Paquier
Date:
On Sun, Dec 16, 2018 at 10:33:38AM +0100, Pavel Stehule wrote:
> Now, the statement's hook is not called for every plpgsql_stmt_block
> statement. It is not big issue, but it is not consistent - and this
> inconsistency should be repaired inside extension. Better to be consistent
> and every plpgsql statement call identically.
>
> patch attached - all regress tests passed. This patch has a effect only on
> plpgsql extensions.

I can see the inconsistency in the code, still do you have a simple
plpgsql extension where it is possible to see the difference in
behavior?  This involves execution of functions, triggers and event
triggers, and exec_stmt_block is used since the beginning of times.
--
Michael

Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Pavel Stehule
Date:


st 19. 12. 2018 v 6:45 odesílatel Michael Paquier <michael@paquier.xyz> napsal:
On Sun, Dec 16, 2018 at 10:33:38AM +0100, Pavel Stehule wrote:
> Now, the statement's hook is not called for every plpgsql_stmt_block
> statement. It is not big issue, but it is not consistent - and this
> inconsistency should be repaired inside extension. Better to be consistent
> and every plpgsql statement call identically.
>
> patch attached - all regress tests passed. This patch has a effect only on
> plpgsql extensions.

I can see the inconsistency in the code, still do you have a simple
plpgsql extension where it is possible to see the difference in
behavior?  This involves execution of functions, triggers and event
triggers, and exec_stmt_block is used since the beginning of times.

What I know, there is only few plpgsql's extensions - 3 variations on debugger support, 1 profiler and plpgsql_check. It was not a issue, because these extensions doesn't hit this problem.

When I wrote a coverity  check to plpgsql_check I found it. The outer BEGIN has a property of usual plpgsql statement - positive lineno, but it was not executed newer.

I can imagine some tracking extension, that will do some initializations on plpgsql_stmt_block statement hook - but the most important will not be called ever.

Regards

Pavel







--
Michael

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Michael Paquier
Date:
On Wed, Dec 19, 2018 at 07:04:50AM +0100, Pavel Stehule wrote:
> I can imagine some tracking extension, that will do some
> initializations on plpgsql_stmt_block statement hook - but the most
> important will not be called ever.

I was just studying this stuff and reviewing this patch with fresh
eyes, and it seems to me that it is actually incorrect.  This changes
the execution logic so as stmt_beg and stmt_end are called
additionally each time a function, a trigger or an event trigger is
executed.  If one looks closely at the code, he/she could notice that
func_beg and func_end are already present as hook points to watch what
is happening in the execution, as these are here to give entry points
for execution functions, so it seems to me that we don't need extra
watch calls as proposed, because there is already everything needed,
and that the current points are correct.
--
Michael

Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Pavel Stehule
Date:


st 26. 12. 2018 v 6:09 odesílatel Michael Paquier <michael@paquier.xyz> napsal:
On Wed, Dec 19, 2018 at 07:04:50AM +0100, Pavel Stehule wrote:
> I can imagine some tracking extension, that will do some
> initializations on plpgsql_stmt_block statement hook - but the most
> important will not be called ever.

I was just studying this stuff and reviewing this patch with fresh
eyes, and it seems to me that it is actually incorrect.  This changes
the execution logic so as stmt_beg and stmt_end are called
additionally each time a function, a trigger or an event trigger is
executed.  If one looks closely at the code, he/she could notice that
func_beg and func_end are already present as hook points to watch what
is happening in the execution, as these are here to give entry points
for execution functions, so it seems to me that we don't need extra
watch calls as proposed, because there is already everything needed,
and that the current points are correct.

The design about this feature has not clean borders - I see a problem with func_beg and func_end because these handlers should to share some logic with stmt_beg, stmt_end when handler for stmt_block is not empty.

More the some behave can be surprise for developer - example - if use handler for smt_beg

then for code

$$
BEGIN
  RETURN x;
END;
$$

is called only once - what is expected;

but for code

$$
BEGIN
  BEGIN
    RETURN x;
  END;
END
$$

is called two times, what is not expected, if you don't know some about this inconsistency.

So it is reason, why I don't think so current behave is correct. On second hand, the impact is very small - only few extensions uses plpgsql plugin API, and workaround is not hard. So I can live with current state if nobody see this issue (sure - it is minor issue).

Regards

Pavel
 
--
Michael

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Michael Paquier
Date:
On Wed, Dec 26, 2018 at 07:02:04AM +0100, Pavel Stehule wrote:
> is called two times, what is not expected, if you don't know some about
> this inconsistency.
>
> So it is reason, why I don't think so current behave is correct. On second
> hand, the impact is very small - only few extensions uses plpgsql plugin
> API, and workaround is not hard. So I can live with current state if nobody
> see this issue (sure - it is minor issue).

Hm.  Using the following functions based on the code of above, I can
see the following numbers if I place some trackers (elog(WARNING)
entries) at the beginning of each callback part of plpgsql_check.c to
measure how many times a callback is done:
CREATE OR REPLACE FUNCTION public.f2()
RETURNS void
LANGUAGE plpgsql
AS $$
DECLARE x int;
BEGIN
  x := 2;
  RETURN;
END;
$$;
CREATE OR REPLACE FUNCTION public.f3()
RETURNS void
LANGUAGE plpgsql
AS $$
DECLARE x int;
BEGIN
  BEGIN
    x := 3;
    RETURN;
    END;
  END
$$;

On HEAD, for plpgsql_check_function_tb('f2()'):
- stmt_beg is called 4 times.
- stmt_end is called 3 times.
- func_setup is called 2 times.
- func_beg is called 2 times.
- func_end is called 2 times.
For plpgsql_check_function_tb('f3()'):
- stmt_beg is called 3 times.
- stmt_end is called 3 times.
- func_setup is called 1 time.
- func_beg is called 1 time.
- func_end is called 2 times.

So based on the previous example f2 gets over f3 one extra stmt_beg,
one extra func_beg and one extra func_setup.

With patched HEAD, I got for f2:
- stmt_beg is called 6 times.
- stmt_end is called 5 times.
- func_setup is called 2 times.
- func_beg is called 2 times.
- func_end is called 2 times.
And for f3:
- stmt_beg is called 6 times.
- stmt_end is called 5 times.
- func_setup is called 2 times.
- func_beg is called 2 times.
- func_end is called 2 times.
--
Michael

Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Pavel Stehule
Date:


pá 28. 12. 2018 v 3:26 odesílatel Michael Paquier <michael@paquier.xyz> napsal:
On Wed, Dec 26, 2018 at 07:02:04AM +0100, Pavel Stehule wrote:
> is called two times, what is not expected, if you don't know some about
> this inconsistency.
>
> So it is reason, why I don't think so current behave is correct. On second
> hand, the impact is very small - only few extensions uses plpgsql plugin
> API, and workaround is not hard. So I can live with current state if nobody
> see this issue (sure - it is minor issue).

Hm.  Using the following functions based on the code of above, I can
see the following numbers if I place some trackers (elog(WARNING)
entries) at the beginning of each callback part of plpgsql_check.c to
measure how many times a callback is done:
CREATE OR REPLACE FUNCTION public.f2()
RETURNS void
LANGUAGE plpgsql
AS $$
DECLARE x int;
BEGIN
  x := 2;
  RETURN;
END;
$$;
CREATE OR REPLACE FUNCTION public.f3()
RETURNS void
LANGUAGE plpgsql
AS $$
DECLARE x int;
BEGIN
  BEGIN
    x := 3;
    RETURN;
    END;
  END
$$;

On HEAD, for plpgsql_check_function_tb('f2()'):
- stmt_beg is called 4 times.
- stmt_end is called 3 times.
- func_setup is called 2 times.
- func_beg is called 2 times.
- func_end is called 2 times.
For plpgsql_check_function_tb('f3()'):
- stmt_beg is called 3 times.
- stmt_end is called 3 times.
- func_setup is called 1 time.
- func_beg is called 1 time.
- func_end is called 2 times.

So based on the previous example f2 gets over f3 one extra stmt_beg,
one extra func_beg and one extra func_setup.

With patched HEAD, I got for f2:
- stmt_beg is called 6 times.
- stmt_end is called 5 times.
- func_setup is called 2 times.
- func_beg is called 2 times.
- func_end is called 2 times.
And for f3:
- stmt_beg is called 6 times.
- stmt_end is called 5 times.
- func_setup is called 2 times.
- func_beg is called 2 times.
- func_end is called 2 times.
--
Michael

These numbers are little bit strange - maybe due using plpgsql_check. I wrote simple extension (see attachment)

        CREATE OR REPLACE FUNCTION public.f2()
         RETURNS void
         LANGUAGE plpgsql
1       AS $function$
2       DECLARE x int;
3       BEGIN
4         x := 2;
5         RETURN;
6       END;
7       $function$

        CREATE OR REPLACE FUNCTION public.f3()
         RETURNS void
         LANGUAGE plpgsql
1       AS $function$
2       DECLARE x int;
3       BEGIN
4         BEGIN
5           x := 3;
6           RETURN;
7           END;
8         END
9       $function$

load 'simple';
select f2();

postgres=# select f2();
NOTICE:  func setup: "f2()"
NOTICE:  func beg: "f2()"
NOTICE:  stmt beg - ln: 4
NOTICE:  stmt end - ln: 4
NOTICE:  stmt beg - ln: 5
NOTICE:  stmt end - ln: 5
NOTICE:  func end: "f2()"

NOTICE:  func setup: "f3()"
NOTICE:  func beg: "f3()"
NOTICE:  stmt beg - ln: 4
NOTICE:  stmt beg - ln: 5
NOTICE:  stmt end - ln: 5
NOTICE:  stmt beg - ln: 6
NOTICE:  stmt end - ln: 6
NOTICE:  stmt end - ln: 4
NOTICE:  func end: "f3()"

patched

postgres=# select f2();
NOTICE:  func setup: "f2()"
NOTICE:  func beg: "f2()"
NOTICE:  stmt beg - ln: 3
NOTICE:  stmt beg - ln: 4
NOTICE:  stmt end - ln: 4
NOTICE:  stmt beg - ln: 5
NOTICE:  stmt end - ln: 5
NOTICE:  stmt end - ln: 3
NOTICE:  func end: "f2()"

postgres=# select f3();
NOTICE:  func setup: "f3()"
NOTICE:  func beg: "f3()"
NOTICE:  stmt beg - ln: 3
NOTICE:  stmt beg - ln: 4
NOTICE:  stmt beg - ln: 5
NOTICE:  stmt end - ln: 5
NOTICE:  stmt beg - ln: 6
NOTICE:  stmt end - ln: 6
NOTICE:  stmt end - ln: 4
NOTICE:  stmt end - ln: 3
NOTICE:  func end: "f3()"

There is only one difference - the plugin routine stmt_begin and stmt_end is called for line 3. Nothing less, nothing more.

Internal evaluation of plpgsql code is same - the change is only for plugin code - one more stmt_beg and stmt_end call - as expected and wanted.

Real impact - now, I have to push my code to func_beg, func_end, stmt_beg, stmt_end. With patch I can push my code just to stmt_beg, stmt_end.

Regards

Pavel



Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Michael Paquier
Date:
On Fri, Dec 28, 2018 at 07:57:45AM +0100, Pavel Stehule wrote:
> There is only one difference - the plugin routine stmt_begin and stmt_end
> is called for line 3. Nothing less, nothing more.

Thanks for the detailed explanation!  With your simple example it is
easy enough to see the difference, and indeed the callback stack is
more consistent the way you propose.

> Internal evaluation of plpgsql code is same - the change is only for plugin
> code - one more stmt_beg and stmt_end call - as expected and wanted.

Okay, that makes sense, now I got your point.  Perhaps somebody else
has an opinion to offer or has an objection with the proposed change?
--
Michael

Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Michael Paquier
Date:
On Fri, Dec 28, 2018 at 04:50:11PM +0900, Michael Paquier wrote:
> Okay, that makes sense, now I got your point.  Perhaps somebody else
> has an opinion to offer or has an objection with the proposed change?

And committed this one, after playing more with the instrumentation
callbacks and checking that the change was consistent for functions,
triggers and event triggers.

Attached is the set of tests I used which has some regression tests.
The results won't fail with HEAD at 4203842a, and will generate some
diffs after e0ef136d as Pavel's patch has changed the generated
output.
--
Michael

Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Michael Paquier
Date:
On Sun, Dec 30, 2018 at 02:40:57PM +0900, Michael Paquier wrote:
> Attached is the set of tests I used which has some regression tests.
> The results won't fail with HEAD at 4203842a, and will generate some
> diffs after e0ef136d as Pavel's patch has changed the generated
> output.

And of course those were not attached..
--
Michael

Attachment

Re: plpgsql plugin - stmt_beg/end is not called for top level blockof statements

From
Pavel Stehule
Date:
Hi

ne 30. 12. 2018 v 6:51 odesílatel Michael Paquier <michael@paquier.xyz> napsal:
On Sun, Dec 30, 2018 at 02:40:57PM +0900, Michael Paquier wrote:
> Attached is the set of tests I used which has some regression tests.
> The results won't fail with HEAD at 4203842a, and will generate some
> diffs after e0ef136d as Pavel's patch has changed the generated
> output.

And of course those were not attached..

Thank you for commit.

Regards

Pavel

--
Michael