2022-04-14 11:38:55

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [PATCH] irq_work: Add event-tracing points for irq_work

On Thu, Apr 14, 2022 at 02:38:29PM +0800, Zqiang wrote:
> Add irq_work_queue_on tracepoints allow tracing when and how
> a irq-work is queued, irq_work_execute_start/end tracepoints
> allow know when a irq-work is executed and the executed time.

Yeah, but why?

> diff --git a/kernel/irq_work.c b/kernel/irq_work.c
> index 7afa40fe5cc4..edad992556d0 100644
> --- a/kernel/irq_work.c
> +++ b/kernel/irq_work.c
> @@ -22,6 +22,9 @@
> #include <asm/processor.h>
> #include <linux/kasan.h>
>
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/irq_work.h>
> +
> static DEFINE_PER_CPU(struct llist_head, raised_list);
> static DEFINE_PER_CPU(struct llist_head, lazy_list);
> static DEFINE_PER_CPU(struct task_struct *, irq_workd);
> @@ -81,7 +84,9 @@ static void __irq_work_queue_local(struct irq_work *work)
> bool rt_lazy_work = false;
> bool lazy_work = false;
> int work_flags;
> + int cpu = smp_processor_id();
>
> + trace_irq_work_queue_on(cpu, work);

That's not very nice, you made this function more expensive for no
reason. And you violated coding style while doing it :/

> work_flags = atomic_read(&work->node.a_flags);
> if (work_flags & IRQ_WORK_LAZY)
> lazy_work = true;
> @@ -143,7 +148,7 @@ bool irq_work_queue_on(struct irq_work *work, int cpu)
> if (cpu != smp_processor_id()) {
> /* Arch remote IPI send/receive backend aren't NMI safe */
> WARN_ON_ONCE(in_nmi());
> -
> + trace_irq_work_queue_on(cpu, work);
> /*
> * On PREEMPT_RT the items which are not marked as
> * IRQ_WORK_HARD_IRQ are added to the lazy list and a HARD work
> @@ -208,7 +213,9 @@ void irq_work_single(void *arg)
> smp_mb();
>
> lockdep_irq_work_enter(flags);
> + trace_irq_work_execute_start(work);
> work->func(work);
> + trace_irq_work_execute_end(work);
> lockdep_irq_work_exit(flags);
>
> /*



2022-04-15 23:45:45

by Zqiang

[permalink] [raw]
Subject: RE: [PATCH] irq_work: Add event-tracing points for irq_work

On Thu, Apr 14, 2022 at 02:38:29PM +0800, Zqiang wrote:
> Add irq_work_queue_on tracepoints allow tracing when and how a
> irq-work is queued, irq_work_execute_start/end tracepoints allow know
> when a irq-work is executed and the executed time.

Yeah, but why?

Tracing stacktrace help find where a irq-work is queued, and view whether a irq-work
be executed in irq context or task context, if in task context, is it because there are lots of
lazy irq-works executed in irq_work rt kthreads, cause other fair task can not get CPU,
for example, there is a problem in RCU which I find in testing
Enable RCU_STRICT_GRACE_PERIOD in preempt-rt, the system booting occur hang,
through add irq-work tracepoints find a lot of irq-work (rcu_preempt_deferred_qs_handler)
be executed in rt-fifo irq_work kthreads, init kthreads unable to obtain CPUs, cause hang.


> diff --git a/kernel/irq_work.c b/kernel/irq_work.c index
> 7afa40fe5cc4..edad992556d0 100644
> --- a/kernel/irq_work.c
> +++ b/kernel/irq_work.c
> @@ -22,6 +22,9 @@
> #include <asm/processor.h>
> #include <linux/kasan.h>
>
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/irq_work.h>
> +
> static DEFINE_PER_CPU(struct llist_head, raised_list); static
> DEFINE_PER_CPU(struct llist_head, lazy_list); static
> DEFINE_PER_CPU(struct task_struct *, irq_workd); @@ -81,7 +84,9 @@
> static void __irq_work_queue_local(struct irq_work *work)
> bool rt_lazy_work = false;
> bool lazy_work = false;
> int work_flags;
> + int cpu = smp_processor_id();
>
> + trace_irq_work_queue_on(cpu, work);

That's not very nice, you made this function more expensive for no reason. And you violated coding style while doing it :/

You mean the trace_irq_work_queue_on() tracepoints should not be added in this place ? or
replace this tracepoint with trace_irq_work_queue_on(raw_smp_processor_id(), work) ?

Thanks,
Zqiang

> work_flags = atomic_read(&work->node.a_flags);
> if (work_flags & IRQ_WORK_LAZY)
> lazy_work = true;
> @@ -143,7 +148,7 @@ bool irq_work_queue_on(struct irq_work *work, int cpu)
> if (cpu != smp_processor_id()) {
> /* Arch remote IPI send/receive backend aren't NMI safe */
> WARN_ON_ONCE(in_nmi());
> -
> + trace_irq_work_queue_on(cpu, work);
> /*
> * On PREEMPT_RT the items which are not marked as
> * IRQ_WORK_HARD_IRQ are added to the lazy list and a HARD work @@
> -208,7 +213,9 @@ void irq_work_single(void *arg)
> smp_mb();
>
> lockdep_irq_work_enter(flags);
> + trace_irq_work_execute_start(work);
> work->func(work);
> + trace_irq_work_execute_end(work);
> lockdep_irq_work_exit(flags);
>
> /*