Message-ID: <CAD8CoPDR=jn4-kE2r=RX0FPk_9LhXps=ZkdBqWDb7Vy05ur3Pg@mail.gmail.com>
Date:   Wed, 2 Aug 2023 11:03:42 +0800
From:   Ze Gao <zegao2021@...il.com>
To:     Peter Zijlstra <peterz@...radead.org>
Cc:     Adrian Hunter <adrian.hunter@...el.com>,
        Alexander Shishkin <alexander.shishkin@...ux.intel.com>,
        Arnaldo Carvalho de Melo <acme@...nel.org>,
        Ian Rogers <irogers@...gle.com>,
        Ingo Molnar <mingo@...hat.com>, Jiri Olsa <jolsa@...nel.org>,
        Mark Rutland <mark.rutland@....com>,
        Masami Hiramatsu <mhiramat@...nel.org>,
        Namhyung Kim <namhyung@...nel.org>,
        Steven Rostedt <rostedt@...dmis.org>,
        linux-kernel@...r.kernel.org, linux-perf-users@...r.kernel.org,
        linux-trace-kernel@...r.kernel.org,
        linux-trace-devel@...r.kernel.org, Ze Gao <zegao@...cent.com>
Subject: Re: [RFC PATCH v3 3/6] sched, tracing: add to report task state in
 symbolic chars

On Tue, Aug 1, 2023 at 9:42 PM Peter Zijlstra <peterz@...radead.org> wrote:
>
> On Tue, Aug 01, 2023 at 09:03:51PM +0800, Ze Gao wrote:
>
> > It's just the design that exporting internal details is fundamentally wrong.
>
> This is tracing... it wasn't supposed to be ABI (although it somehow

Sorry, I'm confused. And it sounds contradicting here
because you said this change is abi break before.

> ended up being one). But even then, things like PF_foo get exposed in
> procfs but even that we change.
>
> The whole point of tracing is to see internals in order to figure out
> wth is going wrong.

Fair point, but I think tracepoints are somewhat different from
kprobes/raw_tracepoints due to their stable nature. And I think
at least more and more observability tools use them in this way.

With all due respect, If it was for kernel developers only, what's the
point of leaking this since now we have raw tracepoints support?
Does that mean all tracepoints are useless now? Apparently the
answer is no. So I'm not convinced by this "for internal inspecting"
defense to not ignore what the problem is.

Honestly, I would've never thought to change this if I I got the correct
meaning for values I captured like 0x80/0x100  when I tried to look it up
in include/linux/sched.h the first time. But it really annoyed me to
figure out what it is only after I dived into the kernel and collected all
the pieces.  And you know what, when I turned to the famous in-tree perf
for possible help, only to find out it's horribly broken and still uses an
outdated state char array to interpret this weird raw value.

Anyway, we have to accept the fact that prev_state leaves a huge burden
on its users to make things right.  And I'm open and glad to see any
solutions (possibly better than this one) or efforts or suggestions to improve
this.

Regards,
Ze

> > And even worse,  I did not see any userspace tool is aware of masqueraded
> > states like TASK_REPORT_IDLE and TASK_REPORT_MAX and let alone
> > parse it correctly.
>
> That's probably because I never use tools, I just look at the raw trace
> output -- sometimes an impromptu awk script. I'm pretty sure I ran with
> something like the below when I did the freezer rewrite -- or perhaps I
> just stuck in trace_printk() and didn't even bother with the
> tracepoints, I can't remember.
>
> > > Why do we need this character anyway, why not just print the state in
> > > hex and leave it at that? These single character state things are a
> > > relic, please just let them die.
> >
> > I believe hex is ok only after having the reported task state mapping
> > appear in the uapi headers, otherwise it's still useless to userspace
> > especially for value like TASK_REPORT_IDLE and TASK_REPORT_MAX, which
> > need to dig into the kernel to see what the hell is going on here.
> >
> > Thoughts?
>
> If you're tracing the kernel, you had better know what the kernel is
> doing, otherwise you get to keep the pieces.
>
> Anyway, if you're doing BPF then why do you care about the trace event
> at all, just attach to the raw tracepoint and consume @preemt, @prev,
> @next and @prev_state.
>
> ---
> diff --git a/include/trace/events/sched.h b/include/trace/events/sched.h
> index fbb99a61f714..cb0c1251729e 100644
> --- a/include/trace/events/sched.h
> +++ b/include/trace/events/sched.h
> @@ -186,36 +186,6 @@ DEFINE_EVENT(sched_wakeup_template, sched_wakeup_new,
>              TP_PROTO(struct task_struct *p),
>              TP_ARGS(p));
>
> -#ifdef CREATE_TRACE_POINTS
> -static inline long __trace_sched_switch_state(bool preempt,
> -                                             unsigned int prev_state,
> -                                             struct task_struct *p)
> -{
> -       unsigned int state;
> -
> -#ifdef CONFIG_SCHED_DEBUG
> -       BUG_ON(p != current);
> -#endif /* CONFIG_SCHED_DEBUG */
> -
> -       /*
> -        * Preemption ignores task state, therefore preempted tasks are always
> -        * RUNNING (we will not have dequeued if state != RUNNING).
> -        */
> -       if (preempt)
> -               return TASK_REPORT_MAX;
> -
> -       /*
> -        * task_state_index() uses fls() and returns a value from 0-8 range.
> -        * Decrement it by 1 (except TASK_RUNNING state i.e 0) before using
> -        * it for left shift operation to get the correct task->state
> -        * mapping.
> -        */
> -       state = __task_state_index(prev_state, p->exit_state);
> -
> -       return state ? (1 << (state - 1)) : state;
> -}
> -#endif /* CREATE_TRACE_POINTS */
> -
>  /*
>   * Tracepoint for task switches, performed by the scheduler:
>   */
> @@ -242,29 +212,16 @@ TRACE_EVENT(sched_switch,
>                 memcpy(__entry->next_comm, next->comm, TASK_COMM_LEN);
>                 __entry->prev_pid       = prev->pid;
>                 __entry->prev_prio      = prev->prio;
> -               __entry->prev_state     = __trace_sched_switch_state(preempt, prev_state, prev);
> +               __entry->prev_state     = prev_state | (preempt * TASK_STATE_MAX);
>                 memcpy(__entry->prev_comm, prev->comm, TASK_COMM_LEN);
>                 __entry->next_pid       = next->pid;
>                 __entry->next_prio      = next->prio;
>                 /* XXX SCHED_DEADLINE */
>         ),
>
> -       TP_printk("prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==> next_comm=%s next_pid=%d next_prio=%d",
> +       TP_printk("prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%x ==> next_comm=%s next_pid=%d next_prio=%d",
>                 __entry->prev_comm, __entry->prev_pid, __entry->prev_prio,
> -
> -               (__entry->prev_state & (TASK_REPORT_MAX - 1)) ?
> -                 __print_flags(__entry->prev_state & (TASK_REPORT_MAX - 1), "|",
> -                               { TASK_INTERRUPTIBLE, "S" },
> -                               { TASK_UNINTERRUPTIBLE, "D" },
> -                               { __TASK_STOPPED, "T" },
> -                               { __TASK_TRACED, "t" },
> -                               { EXIT_DEAD, "X" },
> -                               { EXIT_ZOMBIE, "Z" },
> -                               { TASK_PARKED, "P" },
> -                               { TASK_DEAD, "I" }) :
> -                 "R",
> -
> -               __entry->prev_state & TASK_REPORT_MAX ? "+" : "",
> +               __entry->prev_state,
>                 __entry->next_comm, __entry->next_pid, __entry->next_prio)
>  );
>

Powered by blists - more mailing lists