Subject: Re: RFC: Logging plan of the running query
To: torikoshia <torikoshia@oss.nttdata.com>,
 Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Cc: Dilip Kumar <dilipbalaut@gmail.com>,
 Pgsql Hackers <pgsql-hackers@postgresql.org>
References: <cf8501bcd95ba4d727cbba886ba9eea8@oss.nttdata.com>
 <CALj2ACXpvVeLstnNG1Oris0VpxbSdLNdh_r-v6YxTEY5vcDHAA@mail.gmail.com>
 <CAFiTN-tbi83fB0j0S7-kj9TraUkim03M3S+oXdYe6sMZ7nxVYA@mail.gmail.com>
 <CALj2ACVH-fhO5htnM2UbV7mvP3+0+zYHBamCTC8KWTtSb5+8=g@mail.gmail.com>
 <CAFiTN-vQcDtyc5aRF1RNo-VgRzMcZ4E1qKTybvHpzUV1FEjqBA@mail.gmail.com>
 <CALj2ACWiVHpOqEztxHRtUR1oiDzPGUnguqv2EfEmQSv7jH93aw@mail.gmail.com>
 <CAFiTN-vOTFRK1xoAWRAGJ+54mSpDxmenAFexbySRhgy7hNH5Fg@mail.gmail.com>
 <CAFiTN-u6yqaxQyfX0jUMqDZ22fePfuQuQmzuozTxC34ca+ZByg@mail.gmail.com>
 <c6682a25f3f0e9bd520707342219eac5@oss.nttdata.com>
 <0842b5da697a03869fb50be93817e4e1@oss.nttdata.com>
 <CALj2ACUpznbsLbOg9mauSQZfU2eDxnNLYXcBHaAp1yWxMKLK9g@mail.gmail.com>
 <1c1590d3962cea6e06621da76677b5f3@oss.nttdata.com>
 <CALj2ACVeOvBcN2-MZh-P3FKxsxOv-DD=fUgAMQEY8vPEhoJUQw@mail.gmail.com>
 <dfc25182d91ed9491f77c0c8ca5b71fd@oss.nttdata.com>
 <64f716c44629e303b66e6c24502147cc@oss.nttdata.com>
From: Fujii Masao <masao.fujii@oss.nttdata.com>
Message-ID: <632e99eb-8090-53e6-1b1a-101601904cbd@oss.nttdata.com>
Date: Thu, 1 Jul 2021 15:34:26 +0900
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.14; rv:78.0)
 Gecko/20100101 Thunderbird/78.11.0
MIME-Version: 1.0
In-Reply-To: <64f716c44629e303b66e6c24502147cc@oss.nttdata.com>
Content-Type: text/plain; charset=windows-1252; format=flowed
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Archived-At: 
 <https://www.postgresql.org/message-id/632e99eb-8090-53e6-1b1a-101601904cbd%40oss.nttdata.com>
Precedence: bulk


On 2021/06/22 11:30, torikoshia wrote:
> On Thu, Jun 10, 2021 at 11:09 AM torikoshia <torikoshia@oss.nttdata.com> wrote:
>> On 2021-06-09 23:04, Fujii Masao wrote:
> 
>> > auto_explain can log the plan of even nested statement
>> > if auto_explain.log_nested_statements is enabled.
>> > But ISTM that pg_log_current_plan() cannot log that plan.
>> > Is this intentional?
>>
>> > I think that it's better to make pg_log_current_plan() log
>> > the plan of even nested statement.
>>
>> +1. It would be better.
>> But currently plan information is got from ActivePortal and ISTM there
>> are no easy way to retrieve plan information of nested statements from
>> ActivePortal.
>> Anyway I'll do some more research.
> 
> I haven't found a proper way yet but it seems necessary to use something other than ActivePortal and I'm now thinking this could be a separate patch in the future. 

     DO $$
     BEGIN
     PERFORM pg_sleep(100);
     END$$;

When I called pg_log_current_query_plan() to send the signal to
the backend executing the above query, I got the following log message.
I think that this is not expected message. I guess this issue happened
because the information about query text and plan is retrieved
from ActivePortal. If this understanding is right, ISTM that we should
implement new mechanism so that we can retrieve those information
even while nested query is being executed.

     LOG:  backend with PID 42449 is not running a query

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION