From nobody Wed Sep 10 02:01:30 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 150FEE7B604 for ; Wed, 4 Oct 2023 12:36:37 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S242386AbjJDMgh (ORCPT ); Wed, 4 Oct 2023 08:36:37 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39466 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S242444AbjJDMfr (ORCPT ); Wed, 4 Oct 2023 08:35:47 -0400 Received: from galois.linutronix.de (Galois.linutronix.de [193.142.43.55]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 2F4E918F for ; Wed, 4 Oct 2023 05:35:41 -0700 (PDT) From: Anna-Maria Behnsen DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linutronix.de; s=2020; t=1696422939; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=M2kC6VaC2c5TI/lPvw0ZZGnu6gr4GCJ5Rai4QVFVtKk=; b=dDW/d964Oe4UG5Cqr6WeC9y735iYKNj6g7g7uIrmhJGiG0tQ95AFO2jqj1Uh/MLsghKLQD YmtbUS5r/w2UGJdFr4B2dK0efzZBLwrQEXVBimSk8jDQjRpD1vZflp6u3RY+kocK9lYPf7 pP9mwAinOOsxfzNIp1DLLiHDJ0n3kU3cOzx5re+PJjBClvRAjGChvpGEF2gX4TwrE06JjE /ARC7hO2qGz1p4FfSZsW1rkiUwtE8UTQIRRF6qfaqxr2/3iEwpppUIQJgBpiCIqVeT7nBk kTMPxHJDalHwZaiNThqetXtWS3M8i5TCOe2i3a7gE3c7xF5lUxf/OjQC5U8Mvw== DKIM-Signature: v=1; a=ed25519-sha256; c=relaxed/relaxed; d=linutronix.de; s=2020e; t=1696422939; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=M2kC6VaC2c5TI/lPvw0ZZGnu6gr4GCJ5Rai4QVFVtKk=; b=GYF2UbPa0oGRUxp/sdBjS1o5Z7Jw503Kod1F+2GOGIh0Fcx4Ko7zHezXHd4Y1HbUdFIb5i YgvML3jlXAq+K4Dg== To: linux-kernel@vger.kernel.org Cc: Peter Zijlstra , John Stultz , Thomas Gleixner , Eric Dumazet , "Rafael J . Wysocki" , Arjan van de Ven , "Paul E . McKenney" , Frederic Weisbecker , Rik van Riel , Steven Rostedt , Sebastian Siewior , Giovanni Gherdovich , Lukasz Luba , "Gautham R . Shenoy" , Srinivas Pandruvada , K Prateek Nayak , Anna-Maria Behnsen Subject: [PATCH v8 24/25] timer_migration: Add tracepoints Date: Wed, 4 Oct 2023 14:34:53 +0200 Message-Id: <20231004123454.15691-25-anna-maria@linutronix.de> In-Reply-To: <20231004123454.15691-1-anna-maria@linutronix.de> References: <20231004123454.15691-1-anna-maria@linutronix.de> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The timer pull logic needs proper debugging aids. Add tracepoints so the hierarchical idle machinery can be diagnosed. Signed-off-by: Anna-Maria Behnsen --- v8: Add wakeup value to tracepoints --- include/trace/events/timer_migration.h | 283 +++++++++++++++++++++++++ kernel/time/timer_migration.c | 24 +++ 2 files changed, 307 insertions(+) create mode 100644 include/trace/events/timer_migration.h diff --git a/include/trace/events/timer_migration.h b/include/trace/events/= timer_migration.h new file mode 100644 index 000000000000..b8232c1a1ebf --- /dev/null +++ b/include/trace/events/timer_migration.h @@ -0,0 +1,283 @@ +/* SPDX-License-Identifier: GPL-2.0-only */ + +#undef TRACE_SYSTEM +#define TRACE_SYSTEM timer_migration + +#if !defined(_TRACE_TIMER_MIGRATION_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_TIMER_MIGRATION_H + +#include + +/* Group events */ +TRACE_EVENT(tmigr_group_set, + + TP_PROTO(struct tmigr_group *group), + + TP_ARGS(group), + + TP_STRUCT__entry( + __field( void *, group ) + __field( unsigned int, lvl ) + __field( unsigned int, numa_node ) + ), + + TP_fast_assign( + __entry->group =3D group; + __entry->lvl =3D group->level; + __entry->numa_node =3D group->numa_node; + ), + + TP_printk("group=3D%p lvl=3D%d numa=3D%d", + __entry->group, __entry->lvl, __entry->numa_node) +); + +TRACE_EVENT(tmigr_connect_child_parent, + + TP_PROTO(struct tmigr_group *child), + + TP_ARGS(child), + + TP_STRUCT__entry( + __field( void *, child ) + __field( void *, parent ) + __field( unsigned int, lvl ) + __field( unsigned int, numa_node ) + __field( unsigned int, num_children ) + __field( u32, childmask ) + ), + + TP_fast_assign( + __entry->child =3D child; + __entry->parent =3D child->parent; + __entry->lvl =3D child->parent->level; + __entry->numa_node =3D child->parent->numa_node; + __entry->numa_node =3D child->parent->num_children; + __entry->childmask =3D child->childmask; + ), + + TP_printk("group=3D%p childmask=3D%0x parent=3D%p lvl=3D%d numa=3D%d num_= children=3D%d", + __entry->child, __entry->childmask, __entry->parent, + __entry->lvl, __entry->numa_node, __entry->num_children) +); + +TRACE_EVENT(tmigr_connect_cpu_parent, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc), + + TP_STRUCT__entry( + __field( void *, parent ) + __field( unsigned int, cpu ) + __field( unsigned int, lvl ) + __field( unsigned int, numa_node ) + __field( unsigned int, num_children ) + __field( u32, childmask ) + ), + + TP_fast_assign( + __entry->parent =3D tmc->tmgroup; + __entry->cpu =3D tmc->cpuevt.cpu; + __entry->lvl =3D tmc->tmgroup->level; + __entry->numa_node =3D tmc->tmgroup->numa_node; + __entry->numa_node =3D tmc->tmgroup->num_children; + __entry->childmask =3D tmc->childmask; + ), + + TP_printk("cpu=3D%d childmask=3D%0x parent=3D%p lvl=3D%d numa=3D%d num_ch= ildren=3D%d", + __entry->cpu, __entry->childmask, __entry->parent, + __entry->lvl, __entry->numa_node, __entry->num_children) +); + +DECLARE_EVENT_CLASS(tmigr_group_and_cpu, + + TP_PROTO(struct tmigr_group *group, union tmigr_state state, u32 childmas= k), + + TP_ARGS(group, state, childmask), + + TP_STRUCT__entry( + __field( void *, group ) + __field( void *, parent ) + __field( unsigned int, lvl ) + __field( unsigned int, numa_node ) + __field( u8, active ) + __field( u8, migrator ) + __field( u32, childmask ) + ), + + TP_fast_assign( + __entry->group =3D group; + __entry->parent =3D group->parent; + __entry->lvl =3D group->level; + __entry->numa_node =3D group->numa_node; + __entry->active =3D state.active; + __entry->migrator =3D state.migrator; + __entry->childmask =3D childmask; + ), + + TP_printk("group=3D%p lvl=3D%d numa=3D%d active=3D%0x migrator=3D%0x " + "parent=3D%p childmask=3D%0x", + __entry->group, __entry->lvl, __entry->numa_node, + __entry->active, __entry->migrator, + __entry->parent, __entry->childmask) +); + +DEFINE_EVENT(tmigr_group_and_cpu, tmigr_group_set_cpu_inactive, + + TP_PROTO(struct tmigr_group *group, union tmigr_state state, u32 childmas= k), + + TP_ARGS(group, state, childmask) +); + +DEFINE_EVENT(tmigr_group_and_cpu, tmigr_group_set_cpu_active, + + TP_PROTO(struct tmigr_group *group, union tmigr_state state, u32 childmas= k), + + TP_ARGS(group, state, childmask) +); + +/* CPU events*/ +DECLARE_EVENT_CLASS(tmigr_cpugroup, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc), + + TP_STRUCT__entry( + __field( void *, parent) + __field( unsigned int, cpu) + __field( u64, wakeup) + ), + + TP_fast_assign( + __entry->cpu =3D tmc->cpuevt.cpu; + __entry->parent =3D tmc->tmgroup; + __entry->wakeup =3D tmc->wakeup; + ), + + TP_printk("cpu=3D%d parent=3D%p wakeup=3D%llu", __entry->cpu, __entry->pa= rent, __entry->wakeup) +); + +DEFINE_EVENT(tmigr_cpugroup, tmigr_cpu_new_timer, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc) +); + +DEFINE_EVENT(tmigr_cpugroup, tmigr_cpu_active, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc) +); + +DEFINE_EVENT(tmigr_cpugroup, tmigr_cpu_online, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc) +); + +DEFINE_EVENT(tmigr_cpugroup, tmigr_cpu_offline, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc) +); + +DEFINE_EVENT(tmigr_cpugroup, tmigr_handle_remote_cpu, + + TP_PROTO(struct tmigr_cpu *tmc), + + TP_ARGS(tmc) +); + +TRACE_EVENT(tmigr_cpu_idle, + + TP_PROTO(struct tmigr_cpu *tmc, u64 nextevt), + + TP_ARGS(tmc, nextevt), + + TP_STRUCT__entry( + __field( void *, parent) + __field( unsigned int, cpu) + __field( u64, nextevt) + __field( u64, wakeup) + ), + + TP_fast_assign( + __entry->cpu =3D tmc->cpuevt.cpu; + __entry->parent =3D tmc->tmgroup; + __entry->nextevt =3D nextevt; + __entry->wakeup =3D tmc->wakeup; + ), + + TP_printk("cpu=3D%d parent=3D%p nextevt=3D%llu wakeup=3D%llu", + __entry->cpu, __entry->parent, __entry->nextevt, __entry->wakeup) +); + +TRACE_EVENT(tmigr_update_events, + + TP_PROTO(struct tmigr_group *child, struct tmigr_group *group, + union tmigr_state childstate, union tmigr_state groupstate, + u64 nextevt), + + TP_ARGS(child, group, childstate, groupstate, nextevt), + + TP_STRUCT__entry( + __field( void *, child ) + __field( void *, group ) + __field( u64, nextevt ) + __field( u64, group_next_expiry ) + __field( unsigned int, group_lvl ) + __field( u8, child_active ) + __field( u8, group_active ) + __field( unsigned int, child_evtcpu ) + __field( u64, child_evt_expiry ) + ), + + TP_fast_assign( + __entry->child =3D child; + __entry->group =3D group; + __entry->nextevt =3D nextevt; + __entry->group_next_expiry =3D group->next_expiry; + __entry->group_lvl =3D group->level; + __entry->child_active =3D childstate.active; + __entry->group_active =3D groupstate.active; + __entry->child_evtcpu =3D child ? child->groupevt.cpu : 0; + __entry->child_evt_expiry =3D child ? child->groupevt.nextevt.expires : = 0; + ), + + TP_printk("child=3D%p group=3D%p group_lvl=3D%d child_active=3D%0x group_= active=3D%0x " + "nextevt=3D%llu next_expiry=3D%llu child_evt_expiry=3D%llu child_evtcp= u=3D%d", + __entry->child, __entry->group, __entry->group_lvl, __entry->child_act= ive, + __entry->group_active, + __entry->nextevt, __entry->group_next_expiry, __entry->child_evt_expir= y, + __entry->child_evtcpu) +); + +TRACE_EVENT(tmigr_handle_remote, + + TP_PROTO(struct tmigr_group *group), + + TP_ARGS(group), + + TP_STRUCT__entry( + __field( void * , group ) + __field( unsigned int , lvl ) + ), + + TP_fast_assign( + __entry->group =3D group; + __entry->lvl =3D group->level; + ), + + TP_printk("group=3D%p lvl=3D%d", + __entry->group, __entry->lvl) +); + +#endif /* _TRACE_TIMER_MIGRATION_H */ + +/* This part must be outside protection */ +#include diff --git a/kernel/time/timer_migration.c b/kernel/time/timer_migration.c index 929b3b94b893..5ac6b4f04c55 100644 --- a/kernel/time/timer_migration.c +++ b/kernel/time/timer_migration.c @@ -14,6 +14,9 @@ #include "timer_migration.h" #include "tick-internal.h" =20 +#define CREATE_TRACE_POINTS +#include + /* * The timer migration mechanism is built on a hierarchy of groups. The * lowest level group contains CPUs, the next level groups of CPU groups @@ -514,6 +517,8 @@ static bool tmigr_active_up(struct tmigr_group *group, */ group->groupevt.ignore =3D true; =20 + trace_tmigr_group_set_cpu_active(group, newstate, childmask); + return walk_done; } =20 @@ -545,6 +550,7 @@ void tmigr_cpu_activate(void) =20 raw_spin_lock(&tmc->lock); tmc->idle =3D false; + trace_tmigr_cpu_active(tmc); __tmigr_cpu_activate(tmc); raw_spin_unlock(&tmc->lock); } @@ -688,6 +694,9 @@ static bool tmigr_update_events(struct tmigr_group *gro= up, data->nextexp =3D tmigr_next_groupevt_expires(group); } =20 + trace_tmigr_update_events(child, group, data->childstate, + data->groupstate, nextexp); + unlock: raw_spin_unlock(&group->lock); =20 @@ -721,6 +730,8 @@ static u64 tmigr_new_timer(struct tmigr_cpu *tmc, u64 n= extexp) if (tmc->remote) return KTIME_MAX; =20 + trace_tmigr_cpu_new_timer(tmc); + tmc->cpuevt.ignore =3D false; data.remote =3D false; =20 @@ -754,6 +765,8 @@ static u64 tmigr_handle_remote_cpu(unsigned int cpu, u6= 4 now, return next; } =20 + trace_tmigr_handle_remote_cpu(tmc); + tmc->remote =3D true; WRITE_ONCE(tmc->wakeup, KTIME_MAX); =20 @@ -838,6 +851,7 @@ static bool tmigr_handle_remote_up(struct tmigr_group *= group, =20 childmask =3D data->childmask; =20 + trace_tmigr_handle_remote(group); again: /* * Handle the group only if @childmask is the migrator or if the @@ -1156,6 +1170,8 @@ static bool tmigr_inactive_up(struct tmigr_group *gro= up, } } =20 + trace_tmigr_group_set_cpu_inactive(group, newstate, childmask); + return walk_done; } =20 @@ -1244,6 +1260,7 @@ u64 tmigr_cpu_deactivate(u64 nextexp) */ WRITE_ONCE(tmc->wakeup, ret); =20 + trace_tmigr_cpu_idle(tmc, nextexp); raw_spin_unlock(&tmc->lock); return ret; } @@ -1352,6 +1369,7 @@ static struct tmigr_group *tmigr_get_group(unsigned i= nt cpu, int node, =20 /* Setup successful. Add it to the hierarchy */ list_add(&group->list, &tmigr_level_list[lvl]); + trace_tmigr_group_set(group); return group; } =20 @@ -1369,6 +1387,8 @@ static void tmigr_connect_child_parent(struct tmigr_g= roup *child, raw_spin_unlock(&parent->lock); raw_spin_unlock_irq(&child->lock); =20 + trace_tmigr_connect_child_parent(child); + /* * To prevent inconsistent states, active children need to be active in * the new parent as well. Inactive children are already marked inactive @@ -1450,6 +1470,8 @@ static int tmigr_setup_groups(unsigned int cpu, unsig= ned int node) =20 raw_spin_unlock_irq(&group->lock); =20 + trace_tmigr_connect_cpu_parent(tmc); + /* There are no children that need to be connected */ continue; } else { @@ -1518,6 +1540,7 @@ static int tmigr_cpu_online(unsigned int cpu) WRITE_ONCE(tmc->wakeup, KTIME_MAX); } raw_spin_lock_irq(&tmc->lock); + trace_tmigr_cpu_online(tmc); __tmigr_cpu_activate(tmc); tmc->online =3D true; raw_spin_unlock_irq(&tmc->lock); @@ -1537,6 +1560,7 @@ static int tmigr_cpu_offline(unsigned int cpu) * offline; Therefore nextevt value is set to KTIME_MAX */ __tmigr_cpu_deactivate(tmc, KTIME_MAX); + trace_tmigr_cpu_offline(tmc); raw_spin_unlock_irq(&tmc->lock); =20 return 0; --=20 2.39.2