Received-SPF: pass (google.com: domain of linux-kernel+bounces-73739-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:45d1:ec00::1 as permitted sender) client-ip=2604:1380:45d1:ec00::1;
Date: Tue, 20 Feb 2024 16:53:06 -0500
From: Steven Rostedt <rostedt@goodmis.org>
To: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: LKML <linux-kernel@vger.kernel.org>, Linux Trace Kernel
 <linux-trace-kernel@vger.kernel.org>, Masami Hiramatsu
 <mhiramat@kernel.org>, Mark Rutland <mark.rutland@arm.com>
Subject: Re: [PATCH v3] ring-buffer: Simplify reservation with try_cmpxchg()
 loop
Message-ID: <20240220165306.68ecbe9d@gandalf.local.home>
In-Reply-To: <20240220104023.2182b5c3@gandalf.local.home>
References: <20240219182032.2605d0a3@gandalf.local.home>
	<20240220091922.45848d9a@gandalf.local.home>
	<168765ff-98ea-42a1-82f7-56178bfcf7ec@efficios.com>
	<20240220104023.2182b5c3@gandalf.local.home>
Precedence: bulk
MIME-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit

On Tue, 20 Feb 2024 10:40:23 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> > Try resetting the info->add_timestamp flags to add_ts_default on goto again
> > within __rb_reserve_next().
> >  
> 
> I was looking at that too, but I don't know how it will make a difference.
> 
> Note, the test that fails is in my test suite, and takes about a half hour
> to get there. Running that suite takes up resources (it's my main test
> suite for all changes). I'm currently testing other patches so I either
> need to figure it out through inspection, or this will need to wait a while.

I did a bit of debugging and it's just getting weird. It triggers when I
run with the "perf" clock, which is the local_clock() (and this has
CONFIG_HAVE_UNSTABLE_SCHED_CLOCK=y which does some strange paths for
local_clock()).

It appears that on function_graph tracing with perf clock, it fails the
local_cmpxchg a lot! And for some reason, this is causing it to fail the
overflow more often. Well, if it pushes the header page forward too, it
will also cause that to go back and add to the counter.

I tried moving the "again:" to the beginning of the function (after
resetting the add_timestamp flags and length) so that it gets a new
tail_page each time, but that doesn't appear to make a difference either.

It looks like that retry loop in some configs causes it to fail allocation
on the subbuffer over a 1000 times!

Looks like this changes expectations a bit, and will need more design
changes to make it work.

-- Steve