Received-SPF: pass (google.com: domain of linux-kernel+bounces-73993-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:4601:e00::3 as permitted sender) client-ip=2604:1380:4601:e00::3;
Date: Tue, 20 Feb 2024 22:15:41 -0500
From: Steven Rostedt <rostedt@goodmis.org>
To: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc: LKML <linux-kernel@vger.kernel.org>, Ingo Molnar <mingo@kernel.org>,
 Peter Zijlstra <peterz@infradead.org>, Masami Hiramatsu
 <mhiramat@kernel.org>, Daniel Bristot de Oliveira <bristot@redhat.com>,
 Vincent Guittot <vincent.guittot@linaro.org>, Juri Lelli
 <juri.lelli@redhat.com>
Subject: Re: [PATCH] sched/clock: Make local_clock() notrace
Message-ID: <20240220221541.263b4946@gandalf.local.home>
In-Reply-To: <20240220202524.2527c110@gandalf.local.home>
References: <20240220202002.38fec245@gandalf.local.home>
	<182553e4-a2e2-46f6-8c50-2de6f8effee7@efficios.com>
	<20240220202524.2527c110@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 20:25:24 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> Yes. Debugging that was how I found it ;-) sort of.
> 
> I went back to another machine which triggered the cmpxchg issue as well,
> but when removing that code and going back to the old code, it then locked
> up completely. That was because the other config had more debugging enabled.
> That debugging lead to finding this.
> 
> I'm now going back to see if I can trigger that again with this update.

Actually, I take that back. I had reverted the patches, but the lockups
happened when I put them back in. The lock ups do not happen when I don't
have the cmpxchg code.

I see now that it goes into an infinite loop if the clock gets traced
(found another clock that has the same issue):

	w = local_read(&tail_page->write);
	[..]
 again:
	info->ts = rb_time_stamp(cpu_buffer->buffer);
	[..]
	if (!local_try_cmpxchg(&tail_page->write, &w, w + info->length))
		goto again;

The rb_time_stamp() causes a trace to happen which will move 'w' and the
try_cmpxchg() is guaranteed to fail. Each time! So the above turns into an
infinite loop.

I finally got the recursion logic to not lock up the machine when a timer
gets traced. And because we still trace interrupt code (specifically
irq_enter_rcu(), which I do still want to trace!) we need the "transition"
bit in the recursion test.

That is, because irq_enter_rcu() is called before the preempt_count gets
set to being an IRQ, it fails the recursion test. To handle this, the
recursion test allows a single iteration (a transition bit) otherwise it
considers it a recursion and drops the event.

But in this case, a single recursion will still cause it to fall into an
infinite loop.

-- Steve