| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Tue, 26 Apr 2022 06:48:44 -0700
From: "Paul E. McKenney" <paulmck@...nel.org>
To: "Zhang, Qiang1" <qiang1.zhang@...el.com>
Cc: "frederic@...nel.org" <frederic@...nel.org>,
"rcu@...r.kernel.org" <rcu@...r.kernel.org>,
"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH v4] rcu: Dump all rcuc kthreads status for CPUs that not
report quiescent state
On Tue, Apr 26, 2022 at 06:44:46AM +0000, Zhang, Qiang1 wrote:
>
> On Mon, Apr 25, 2022 at 09:04:04AM +0800, Zqiang wrote:
> > If the rcutree.use_softirq is configured, when RCU Stall event
> > happened, dump status of all rcuc kthreads who due to starvation
> > prevented grace period ends on CPUs that not report quiescent state.
> >
> > Signed-off-by: Zqiang <qiang1.zhang@...el.com>
> > ---
> > v1->v2:
> > rework rcuc_kthread_dump function
> > v2->v3:
> > merge this rcuc-stalled information into print_cpu_stall_info()
> > v3->v4:
> > print rcuc info only when rcuc kthread is starved
> >
> > kernel/rcu/tree_stall.h | 49
> > ++++++++++++++++++-----------------------
> > 1 file changed, 21 insertions(+), 28 deletions(-)
>
> >I have queued this for testing and further review, thank you!
> >
> >I did the usual wordsmithing, plus I got rid of a couple of space characters that are extraneous in the common case (one of yours and one pre-existing instance).
> >
> >Could you please generate an actual stall of this type? You might need to add a delay to the rcuc code, but other than that, please see the rcutorture blog series [1] and in particular the post on forcing stall warnings [2].
> >
> > Thanx, Paul
> >
> >[1] https://paulmck.livejournal.com/61432.html
> >[2] https://paulmck.livejournal.com/58077.html
>
> I followed the instructions, add " rcutorture.stall_cpu=22 rcutorture.fwd_progress=0" and
> " rcutree.use_softirq=0"to bootargs, can trigger RCU CPU stall warning:
>
> root@...ux86-64:/# dmesg
> [ 37.556435] rcu: INFO: rcu_preempt self-detected stall on CPU
> [ 37.556437] rcu: 3-....: (1 GPs behind) idle=269/1/0x4000000000000000 softirq=0/0 fqs=5631 rcuc=26004 jiffies(starved)
> [ 37.556440] (t=26000 jiffies g=3589 q=35403)
> [ 37.556441] NMI backtrace for cpu 3
> [ 37.556442] CPU: 3 PID: 117 Comm: rcu_torture_sta Tainted: G L 5.17.0-yoctodev-standard #16 7fe7533e7466875b0801ac148f921afcf57d38bc
> [ 37.556443] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
> [ 37.556444] Call Trace:
> [ 37.556445] <IRQ>
> [ 37.556446] dump_stack_lvl+0x5b/0x82
> [ 37.556449] dump_stack+0x10/0x12
> [ 37.556451] nmi_cpu_backtrace.cold+0x32/0x8a
> [ 37.556452] ? lapic_can_unplug_cpu+0x80/0x80
> [ 37.556454] nmi_trigger_cpumask_backtrace+0xce/0xe0
> [ 37.556456] arch_trigger_cpumask_backtrace+0x19/0x20
> [ 37.556458] rcu_dump_cpu_stacks+0xcd/0x140
> [ 37.556460] rcu_sched_clock_irq.cold+0x7a/0x3ba
> [ 37.556463] ? debug_smp_processor_id+0x17/0x20
> [ 37.556466] update_process_times+0x9b/0xd0
> [ 37.556467] tick_sched_handle.isra.0+0x25/0x50
> [ 37.556469] tick_sched_timer+0x79/0x90
> [ 37.556470] ? tick_sched_do_timer+0x60/0x60
> [ 37.556471] __hrtimer_run_queues+0x1d1/0x4c0
> [ 37.556473] hrtimer_interrupt+0x114/0x230
> [ 37.556475] ? rcu_read_lock_held_common+0x12/0x50
> [ 37.556489] __sysvec_apic_timer_interrupt+0xa4/0x280
> [ 37.556491] sysvec_apic_timer_interrupt+0x95/0xc0
> [ 37.556492] </IRQ>
Excellent, thank you!!!
Now could you please do the same thing for a use_softirq kernel to
verify that it prints correctly when that message is not supposed
to be shown?
Thanx, Paul
> Thanks
> Zqiang
>
> >
> ------------------------------------------------------------------------
>
> commit 66226e2acda8b31b60137b1ae71244df68541a01
> Author: Zqiang <qiang1.zhang@...el.com>
> Date: Mon Apr 25 09:04:04 2022 +0800
>
> rcu: Dump all rcuc kthreads status for CPUs that not report quiescent state
>
> If the rcutree.use_softirq kernel boot parameter is disabled, then it is
> possible that a RCU CPU stall is due to the rcuc kthreads being starved of
> CPU time. There is currently no easy way to infer this from the RCU CPU
> stall warning output. This commit therefore adds a string of the form "
> rcuc=%ld jiffies(starved)" to a given CPU's output if the corresponding
> rcuc kthread has been starved for more than two seconds.
>
> [ paulmck: Eliminate extraneous space characters. ]
>
> Signed-off-by: Zqiang <qiang1.zhang@...el.com>
> Signed-off-by: Paul E. McKenney <paulmck@...nel.org>
>
> diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h index d7956c03edbd4..0a25a4ea6eef8 100644
> --- a/kernel/rcu/tree_stall.h
> +++ b/kernel/rcu/tree_stall.h
> @@ -407,7 +407,19 @@ static bool rcu_is_gp_kthread_starving(unsigned long *jp)
>
> static bool rcu_is_rcuc_kthread_starving(struct rcu_data *rdp, unsigned long *jp) {
> - unsigned long j = jiffies - READ_ONCE(rdp->rcuc_activity);
> + int cpu;
> + struct task_struct *rcuc;
> + unsigned long j;
> +
> + rcuc = rdp->rcu_cpu_kthread_task;
> + if (!rcuc)
> + return false;
> +
> + cpu = task_cpu(rcuc);
> + if (cpu_is_offline(cpu) || idle_cpu(cpu))
> + return false;
> +
> + j = jiffies - READ_ONCE(rdp->rcuc_activity);
>
> if (jp)
> *jp = j;
> @@ -432,6 +444,9 @@ static void print_cpu_stall_info(int cpu)
> struct rcu_data *rdp = per_cpu_ptr(&rcu_data, cpu);
> char *ticks_title;
> unsigned long ticks_value;
> + bool rcuc_starved;
> + unsigned long j;
> + char buf[32];
>
> /*
> * We could be printing a lot while holding a spinlock. Avoid @@ -449,7 +464,10 @@ static void print_cpu_stall_info(int cpu)
> delta = rcu_seq_ctr(rdp->mynode->gp_seq - rdp->rcu_iw_gp_seq);
> falsepositive = rcu_is_gp_kthread_starving(NULL) &&
> rcu_dynticks_in_eqs(rcu_dynticks_snap(rdp));
> - pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u fqs=%ld %s\n",
> + rcuc_starved = rcu_is_rcuc_kthread_starving(rdp, &j);
> + if (rcuc_starved)
> + sprintf(buf, " rcuc=%ld jiffies(starved)", j);
> + pr_err("\t%d-%c%c%c%c: (%lu %s) idle=%03x/%ld/%#lx softirq=%u/%u
> +fqs=%ld%s%s\n",
> cpu,
> "O."[!!cpu_online(cpu)],
> "o."[!!(rdp->grpmask & rdp->mynode->qsmaskinit)], @@ -462,32 +480,10 @@ static void print_cpu_stall_info(int cpu)
> rdp->dynticks_nesting, rdp->dynticks_nmi_nesting,
> rdp->softirq_snap, kstat_softirqs_cpu(RCU_SOFTIRQ, cpu),
> data_race(rcu_state.n_force_qs) - rcu_state.n_force_qs_gpstart,
> + rcuc_starved ? buf : "",
> falsepositive ? " (false positive?)" : ""); }
>
> -static void rcuc_kthread_dump(struct rcu_data *rdp) -{
> - int cpu;
> - unsigned long j;
> - struct task_struct *rcuc;
> -
> - rcuc = rdp->rcu_cpu_kthread_task;
> - if (!rcuc)
> - return;
> -
> - cpu = task_cpu(rcuc);
> - if (cpu_is_offline(cpu) || idle_cpu(cpu))
> - return;
> -
> - if (!rcu_is_rcuc_kthread_starving(rdp, &j))
> - return;
> -
> - pr_err("%s kthread starved for %ld jiffies\n", rcuc->comm, j);
> - sched_show_task(rcuc);
> - if (!trigger_single_cpu_backtrace(cpu))
> - dump_cpu_task(cpu);
> -}
> -
> /* Complain about starvation of grace-period kthread. */ static void rcu_check_gp_kthread_starvation(void)
> {
> @@ -659,9 +655,6 @@ static void print_cpu_stall(unsigned long gps)
> rcu_check_gp_kthread_expired_fqs_timer();
> rcu_check_gp_kthread_starvation();
>
> - if (!use_softirq)
> - rcuc_kthread_dump(rdp);
> -
> rcu_dump_cpu_stacks();
>
> raw_spin_lock_irqsave_rcu_node(rnp, flags);
Powered by blists - more mailing lists