Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <d1259a3a-fbab-439f-7983-bb19aebecd5f@huawei.com>
Date:   Mon, 24 Jul 2023 20:29:08 +0800
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:102.0) Gecko/20100101
 Thunderbird/102.6.0
Subject: Re: [PATCH] ring-buffer: Fix wrong stat of cpu_buffer->read
Content-Language: en-US
To:     Steven Rostedt <rostedt@goodmis.org>
CC:     <mhiramat@kernel.org>, <vnagarnaik@google.com>,
        <linux-kernel@vger.kernel.org>,
        <linux-trace-kernel@vger.kernel.org>
References: <20230724054040.3489499-1-zhengyejian1@huawei.com>
 <20230724044304.5a93a266@rorschach.local.home>
From:   Zheng Yejian <zhengyejian1@huawei.com>
In-Reply-To: <20230724044304.5a93a266@rorschach.local.home>
Content-Type: text/plain; charset="UTF-8"; format=flowed
Content-Transfer-Encoding: 7bit
Precedence: bulk

On 2023/7/24 16:43, Steven Rostedt wrote:
> Do you folks find it fun to post a fix right after I send Linus a pull request? ;-)

It's always so coincidental :-)

> 
> Thanks, I'll queue it up (but I will wait a bit before posting in case
> more fixes trickle in)

Thanks!

-- Zheng Yejian

> 
> -- Steve
> 
> 
> On Mon, 24 Jul 2023 13:40:40 +0800
> Zheng Yejian <zhengyejian1@huawei.com> wrote:
> 
>> When pages are removed in rb_remove_pages(), 'cpu_buffer->read' is set
>> to 0 in order to make sure any read iterators reset themselves. However,
>> this will mess 'entries' stating, see following steps:
>>
>>    # cd /sys/kernel/tracing/
>>    # 1. Enlarge ring buffer prepare for later reducing:
>>    # echo 20 > per_cpu/cpu0/buffer_size_kb
>>    # 2. Write a log into ring buffer of cpu0:
>>    # taskset -c 0 echo "hello1" > trace_marker
>>    # 3. Read the log:
>>    # cat per_cpu/cpu0/trace_pipe
>>         <...>-332     [000] .....    62.406844: tracing_mark_write: hello1
>>    # 4. Stop reading and see the stats, now 0 entries, and 1 event readed:
>>    # cat per_cpu/cpu0/stats
>>     entries: 0
>>     [...]
>>     read events: 1
>>    # 5. Reduce the ring buffer
>>    # echo 7 > per_cpu/cpu0/buffer_size_kb
>>    # 6. Now entries became unexpected 1 because actually no entries!!!
>>    # cat per_cpu/cpu0/stats
>>     entries: 1
>>     [...]
>>     read events: 0
>>
>> To fix it, introduce 'page_removed' field to count total removed pages
>> since last reset, then use it to let read iterators reset themselves
>> instead of changing the 'read' pointer.
>>
>> Fixes: 83f40318dab0 ("ring-buffer: Make removal of ring buffer pages atomic")
>> Signed-off-by: Zheng Yejian <zhengyejian1@huawei.com>
>> ---
>>   kernel/trace/ring_buffer.c | 22 ++++++++++++----------
>>   1 file changed, 12 insertions(+), 10 deletions(-)
>>
>> diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
>> index de061dd47313..46b4a3c7c3bf 100644
>> --- a/kernel/trace/ring_buffer.c
>> +++ b/kernel/trace/ring_buffer.c
>> @@ -523,6 +523,8 @@ struct ring_buffer_per_cpu {
>>   	rb_time_t			before_stamp;
>>   	u64				event_stamp[MAX_NEST];
>>   	u64				read_stamp;
>> +	/* pages removed since last reset */
>> +	unsigned long			pages_removed;
>>   	/* ring buffer pages to update, > 0 to add, < 0 to remove */
>>   	long				nr_pages_to_update;
>>   	struct list_head		new_pages; /* new pages to add */
>> @@ -559,6 +561,7 @@ struct ring_buffer_iter {
>>   	struct buffer_page		*head_page;
>>   	struct buffer_page		*cache_reader_page;
>>   	unsigned long			cache_read;
>> +	unsigned long			cache_pages_removed;
>>   	u64				read_stamp;
>>   	u64				page_stamp;
>>   	struct ring_buffer_event	*event;
>> @@ -1957,6 +1960,8 @@ rb_remove_pages(struct ring_buffer_per_cpu *cpu_buffer, unsigned long nr_pages)
>>   		to_remove = rb_list_head(to_remove)->next;
>>   		head_bit |= (unsigned long)to_remove & RB_PAGE_HEAD;
>>   	}
>> +	/* Read iterators need to reset themselves when some pages removed */
>> +	cpu_buffer->pages_removed += nr_removed;
>>   
>>   	next_page = rb_list_head(to_remove)->next;
>>   
>> @@ -1978,12 +1983,6 @@ rb_remove_pages(struct ring_buffer_per_cpu *cpu_buffer, unsigned long nr_pages)
>>   		cpu_buffer->head_page = list_entry(next_page,
>>   						struct buffer_page, list);
>>   
>> -	/*
>> -	 * change read pointer to make sure any read iterators reset
>> -	 * themselves
>> -	 */
>> -	cpu_buffer->read = 0;
>> -
>>   	/* pages are removed, resume tracing and then free the pages */
>>   	atomic_dec(&cpu_buffer->record_disabled);
>>   	raw_spin_unlock_irq(&cpu_buffer->reader_lock);
>> @@ -4395,6 +4394,7 @@ static void rb_iter_reset(struct ring_buffer_iter *iter)
>>   
>>   	iter->cache_reader_page = iter->head_page;
>>   	iter->cache_read = cpu_buffer->read;
>> +	iter->cache_pages_removed = cpu_buffer->pages_removed;
>>   
>>   	if (iter->head) {
>>   		iter->read_stamp = cpu_buffer->read_stamp;
>> @@ -4849,12 +4849,13 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
>>   	buffer = cpu_buffer->buffer;
>>   
>>   	/*
>> -	 * Check if someone performed a consuming read to
>> -	 * the buffer. A consuming read invalidates the iterator
>> -	 * and we need to reset the iterator in this case.
>> +	 * Check if someone performed a consuming read to the buffer
>> +	 * or removed some pages from the buffer. In these cases,
>> +	 * iterator was invalidated and we need to reset it.
>>   	 */
>>   	if (unlikely(iter->cache_read != cpu_buffer->read ||
>> -		     iter->cache_reader_page != cpu_buffer->reader_page))
>> +		     iter->cache_reader_page != cpu_buffer->reader_page ||
>> +		     iter->cache_pages_removed != cpu_buffer->pages_removed))
>>   		rb_iter_reset(iter);
>>   
>>    again:
>> @@ -5298,6 +5299,7 @@ rb_reset_cpu(struct ring_buffer_per_cpu *cpu_buffer)
>>   	cpu_buffer->last_overrun = 0;
>>   
>>   	rb_head_page_activate(cpu_buffer);
>> +	cpu_buffer->pages_removed = 0;
>>   }
>>   
>>   /* Must have disabled the cpu buffer then done a synchronize_rcu */
> 
>