Re: RFC: Logging plan of the running query

On 2021-08-11 00:21, Fujii Masao wrote:

> On 2021/08/10 21:22, torikoshia wrote:
>> I have updated the patch in this way.
>
> Thanks for updating the patch!
>
>
>> In this patch, getting the plan to the DO statement is as follows.
>
> Looks good to me.
>
>
>> Any thoughts?
>
> + ereport(LOG_SERVER_ONLY,
> + (errmsg("plan of the query running on backend with PID %d is:\n%s",
> + MyProcPid, es->str->data),
> + errhidestmt(true)));
>
> Shouldn't we hide context information by calling errhidecontext(true)?

Agreed.

> While "make installcheck" regression test was running, I repeated
> executing pg_log_current_query_plan() and got the failure of join_hash
> test
> with the following diff. This means that pg_log_current_query_plan()
> could
> cause the query that should be completed successfully to fail with the
> error.
> Isn't this a bug?

Thanks for finding the bug.
I also reproduced it.

> I *guess* that the cause of this issue is that ExplainNode() can call
> InstrEndLoop() more than once unexpectedly.

As far as I looked into, pg_log_current_plan() can call InstrEndLoop()
through ExplainNode().
I added a flag to ExplainState to avoid calling InstrEndLoop() when
ExplainNode() is called from pg_log_current_plan().

>
>
> ------------------------------------------------------------------------------
> $$
> select count(*) from simple r join simple s using (id);
> $$);
> - initially_multibatch | increased_batches
> -----------------------+-------------------
> - f | f
> -(1 row)
> -
> +ERROR: InstrEndLoop called on running node
> +CONTEXT: PL/pgSQL function hash_join_batches(text) line 6 at FOR
> over EXECUTE statement
> rollback to settings;
> -- parallel with parallel-oblivious hash join
> savepoint settings;
> @@ -687,11 +684,9 @@
> left join (select b1.id, b1.t from join_bar b1 join join_bar b2
> using (id)) ss
> on join_foo.id < ss.id + 1 and join_foo.id > ss.id - 1;
> $$);
> - multibatch
> -------------
> - t
> -(1 row)
> -
> +ERROR: InstrEndLoop called on running node
> +CONTEXT: parallel worker
> +PL/pgSQL function hash_join_batches(text) line 6 at FOR over EXECUTE
> statement
> rollback to settings;
> -- single-batch with rescan, parallel-aware
> savepoint settings;
>
> ------------------------------------------------------------------------------
>
> Regards,

--
Regards,

--
Atsushi Torikoshi
NTT DATA CORPORATION