From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from smtp.kernel.org (aws-us-west-2-korg-mail-alma10-1.taild15c8.ts.net [100.103.45.18]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 6E23431714A; Thu, 15 Oct 2026 13:34:05 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=100.103.45.18 ARC-Seal:i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1792071247; cv=none; b=YkjMb2uY2jLTvIv6fBO1U5wsx/GlSogRq9zrq+2gxqAIxgW4sh3uye5ptUUaisVKu6f23zVe/DNKY7OjqUFLYLZbx6F+niniJKAsMuEco9pRceaBg2rmMcwAoLNU5vbtKjRMVqntXPXgk2hrblmaD8jtr3qZBlcvkh36yaAlO74= ARC-Message-Signature:i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1792071247; c=relaxed/simple; bh=Z2n3vR/zVQrBftE6yUZHISCj5KfiuNeU/YTQfNBDXks=; h=Message-ID:Date:From:To:Cc:Subject:References:MIME-Version: Content-Type; b=ojCYBq1HAuv5EaJn1LT4zM0TbNSEvJu2cP8UO4QHa5vcAxirRhzpOzFXueb5JljDxfDT5+zxXZDg4ANdWveJg0QKSKVXFhAokEpOGxXua7ahs3VPUyRmdHDUHo94Sfz50cPgDLxDtift9TN8Lnfsr8AE/9oI5S8TzlKAE+4X67M= ARC-Authentication-Results:i=1; smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b=F/yFDorG; arc=none smtp.client-ip=100.103.45.18 Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b="F/yFDorG" Received: by smtp.kernel.org (Postfix) with ESMTPSA id 07A011F000C4; Thu, 15 Oct 2026 13:34:05 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=kernel.org; s=k20260515; t=1792071245; bh=OxKnwAhkfgtLZ2vkrQPUgMp2uW3yD76d0N5giMxcywQ=; h=Date:From:To:Cc:Subject:References; b=F/yFDorGTCYsLPcYPrzU9S0Gr2NGUNV6dasXFOkbwUSKL5mWsCDfRQxz9cbvISffv oZFZx18rGwbfEPBVSHIphoHjN5CDH0jjtH1V+sP1sF39TQRvCYIFQUcB7gunkShPWa crKFdS7IE/WRX0Jy02536PrTj5rsMdTHxAlDQ0rh9BAWbTbTHklSM+N7bhBUzPBQ26 9jvntqpxKUnmmtVvAMro1teNUxgcxVKgQeGwtpFeyMmmt+Fqlkl2ZoRxenuf68QIty Jv0Nzh3ZN0WgAV0EvE+pXIOYI4q4ZLXHrOKCtNFx0b7rFVA8GtSKYjGhdSfmFOONZQ sr5n6N0gRl7zw== Received: from rostedt by gandalf with local (Exim 4.100.1) (envelope-from ) id 1xHLau-00000000MfY-1OH0; Thu, 15 Oct 2026 09:34:04 -0400 Message-ID: <20261015133404.170463200@kernel.org> User-Agent: quilt/0.69 Date: Thu, 15 Oct 2026 09:33:21 -0400 From: Steven Rostedt To: linux-kernel@vger.kernel.org Cc: Masami Hiramatsu , Mark Rutland , Mathieu Desnoyers , Andrew Morton , stable@vger.kernel.org, Tengda Wu Subject: [for-linus][PATCH 11/16] tracing: Fix hist trigger timestamps for buffered events References: <20261015133310.731003448@kernel.org> Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 From: Tengda Wu Syzkaller triggered a WARN_ON_ONCE(!nest) warning: WARNING: kernel/trace/ring_buffer.c:821 at ring_buffer_event_time_stamp Call trace: ring_buffer_event_time_stamp hist_field_timestamp hist_fn_call event_hist_trigger event_triggers_call __event_trigger_test_discard trace_event_buffer_commit do_trace_event_raw_event_sched_switch trace_event_raw_event_sched_switch The warning is probabilistically reproducible and is related to syzkaller executing the following commands: echo 'prev_pid == 999999' > events/sched/sched_switch/filter echo 'hist:keys=common_timestamp' > events/sched/sched_switch/trigger The specific triggering process is as follows: CPU 0 CPU 1 (context switching) (echo 'hist:keys=common_timestamp' > \ events/sched/sched_switch/trigger) do_trace_event_raw_event_##call trace_event_buffer_lock_reserve if (!tr->no_filter_buffering_ref && trace_file->flags & EVENT_FILE_FL_FILTERED) return entry; // return directly event_hist_trigger_parse hist_register_trigger tracing_set_filter_buffering(file->tr, true); tr->no_filter_buffering_ref++; __trace_buffer_lock_reserve rb_start_commit local_inc(&cpu_buffer->committing); // skipped and not executed trace_event_buffer_commit __event_trigger_test_discard event_triggers_call event_hist_trigger hist_fn_call hist_field_timestamp ring_buffer_event_time_stamp nest = local_read(&cpu_buffer->committing); WARN_ON_ONCE(!nest) // trigger warning The root cause is that when an event file has a filter attached and the hist trigger has not yet been attached, trace_event_buffer_lock_reserve() writes the event into the per-CPU trace_buffered_event temp buffer instead of reserving it in the ring buffer, so cpu_buffer->committing is not incremented. When the event is later processed at commit time by a hist trigger, hist_field_timestamp() -> ring_buffer_event_time_stamp() sees a zero committing count, triggering WARN_ON_ONCE(!nest). tracing_event_time_stamp() was added by commit d8279bfc5e959 ("tracing: Add tracing_event_time_stamp() API") for exactly this case: if the event is the per-CPU trace_buffered_event, it returns the current ring buffer timestamp. But it never gained a caller. Use it in hist_field_timestamp(), so that a hist trigger that races onto a buffered event records the current time, which is only marginally later than when the event was recorded, instead of warning and recording a bogus timestamp. Cc: stable@vger.kernel.org Link: https://patch.msgid.link/20260929104015.1689921-1-wutengda@huaweicloud.com Fixes: b94bc80df648 ("tracing: Use a no_filter_buffering_ref to stop using the filter buffer") Signed-off-by: Tengda Wu Signed-off-by: Steven Rostedt --- kernel/trace/trace_events_hist.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 71d7f43a7964..571a57e0f369 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -873,7 +873,7 @@ static u64 hist_field_timestamp(struct hist_field *hist_field, struct hist_trigger_data *hist_data = hist_field->hist_data; struct trace_array *tr = hist_data->event_file->tr; - u64 ts = ring_buffer_event_time_stamp(buffer, rbe); + u64 ts = tracing_event_time_stamp(buffer, rbe); if (hist_data->attrs->ts_in_usecs && trace_clock_in_ns(tr)) ts = ns2usecs(ts); -- 2.53.0