Subject: Re: Why are wait events not reported even though it reads/writes a
 timeline history file?
To: Masahiro Ikeda <ikedamsh@oss.nttdata.com>
Cc: pgsql-hackers@postgresql.org
References: <d11b0c910b63684424e06772eb844ab5@oss.nttdata.com>
 <c2bed73d-2044-8ab1-075a-75ce0316a814@oss.nttdata.com>
 <3480dda4f5a043d8819de9e8653dc331@oss.nttdata.com>
From: Fujii Masao <masao.fujii@oss.nttdata.com>
Message-ID: <b208e403-e654-b609-3802-7998b21d016e@oss.nttdata.com>
Date: Tue, 28 Apr 2020 14:49:00 +0900
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.14; rv:68.0)
 Gecko/20100101 Thunderbird/68.7.0
MIME-Version: 1.0
In-Reply-To: <3480dda4f5a043d8819de9e8653dc331@oss.nttdata.com>
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Language: en-US
Content-Transfer-Encoding: 8bit
Precedence: bulk


On 2020/04/28 11:10, Masahiro Ikeda wrote:
> On 2020-04-27 12:25, Fujii Masao wrote:
>> On 2020/04/24 11:29, Masahiro Ikeda wrote:
>>> Hi,
>>>
>>> There are two unexpected codes for me about wait events for timeline history file.
>>> Please let me know your thoughts whether if we need to change.
>>>
>>>
>>> 1. readTimeLineHistory() function in timeline.c
>>>
>>> The readTimeLineHistory() reads a timeline history file,
>>> but it doesn't report “WAIT_EVENT_TIMELINE_HISTORY_READ".
>>
>> Yeah, this sounds strange.
>>
>>> In my understanding, sscanf() is blocking read.
>>> So, it's important to report a wait event.
>>
>> Shouldn't the wait event be reported during fgets() rather than sscanf()?
>>
>>> 2. writeTimeLineHistory() function in timeline.c
>>>
>>> The writeTimeLineHistory() function may write a timeline history file twice,
>>> but it reports “WAIT_EVENT_TIMELINE_HISTORY_WRITE" only once.
>>>
>>> It makes sense to report a wait event twice, because both of them use write().
>>
>> Yes.
>>
>>> I attached a patch to mention the code line number.
>>>
>>>
>>> I checked the commit log which "WAIT_EVENT_TIMELINE_HISTORY_READ" and
>>> "WAIT_EVENT_TIMELINE_HISTORY_WRITE" are committed and the discussion about it.
>>> But I can't find the reason.
>>>
>>> Please give me your comments.
>>> If we need to change, I can make a patch to fix them.
>>
>> Thanks! I agree to fix those issues.
> 
> Thanks for the comments. I attach a patch to fix those issues.
> Please review it.

Thanks for the patch!

         prevend = InvalidXLogRecPtr;
+       pgstat_report_wait_start(WAIT_EVENT_TIMELINE_HISTORY_READ);
         while (fgets(fline, sizeof(fline), fd) != NULL)
         {
                 /* skip leading whitespace and check for # comment */
@@ -172,6 +173,7 @@ readTimeLineHistory(TimeLineID targetTLI)
  
                 /* we ignore the remainder of each line */
         }
+       pgstat_report_wait_end();

Isn't it safer to report the wait event during fgets() rather than putting
those calls around the whole loop, like other code does? For example,
writeTimeLineHistory() reports the wait event during read() rather than
whole loop.

Regards,

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