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
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list] 
Date:	Thu, 23 Oct 2014 11:32:32 -0700
From:	"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
To:	Dave Jones <davej@...hat.com>,
	Linux Kernel <linux-kernel@...r.kernel.org>, htejun@...il.com
Cc:	oleg@...hat.com
Subject: Re: rcu_preempt detected stalls.

On Mon, Oct 13, 2014 at 01:35:04PM -0400, Dave Jones wrote:
> Today in "rcu stall while fuzzing" news:
> 
> INFO: rcu_preempt detected stalls on CPUs/tasks:
> 	Tasks blocked on level-0 rcu_node (CPUs 0-3): P766 P646
> 	Tasks blocked on level-0 rcu_node (CPUs 0-3): P766 P646
> 	(detected by 0, t=6502 jiffies, g=75434, c=75433, q=0)
> trinity-c342    R  running task    13384   766  32295 0x00000000
>  ffff880068943d58 0000000000000002 0000000000000002 ffff880193c8c680
>  00000000001d4100 0000000000000000 ffff880068943fd8 00000000001d4100
>  ffff88024302c680 ffff880193c8c680 ffff880068943fd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff880d9424>] ? lock_acquire+0xd4/0x2b0
>  [<ffffffff8808d495>] ? kill_pid_info+0x5/0x130
>  [<ffffffff8808d4d5>] kill_pid_info+0x45/0x130
>  [<ffffffff8808d495>] ? kill_pid_info+0x5/0x130
>  [<ffffffff8808d6d2>] SYSC_kill+0xf2/0x2f0
>  [<ffffffff8808d67b>] ? SYSC_kill+0x9b/0x2f0
>  [<ffffffff8819c2b7>] ? context_tracking_user_exit+0x57/0x280
>  [<ffffffff880136bd>] ? syscall_trace_enter+0x13d/0x310
>  [<ffffffff8808fd9e>] SyS_kill+0xe/0x10
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2

Well, there is a loop in kill_pid_info().  I am surprised that it
would loop indefinitely, but if it did, you would certainly get
RCU CPU stalls.  Please see patch below, adding Oleg for his thoughts.

> trinity-c225    R  running task    13448   646  32295 0x00000000
>  ffff880161ccfb28 0000000000000002 ffff880161ccfe10 ffff88000bf85e00
>  00000000001d4100 0000000000000003 ffff880161ccffd8 00000000001d4100
>  ffff880030124680 ffff88000bf85e00 ffff880161ccffd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff88233d41>] ? __d_lookup_rcu+0xd1/0x1e0
>  [<ffffffff88233dd6>] ? __d_lookup_rcu+0x166/0x1e0
>  [<ffffffff88222f9f>] lookup_fast+0x4f/0x3d0
>  [<ffffffff88224857>] link_path_walk+0x1a7/0x8a0
>  [<ffffffff88224f95>] ? path_lookupat+0x45/0x7b0
>  [<ffffffff88224fb7>] path_lookupat+0x67/0x7b0
>  [<ffffffff880d385d>] ? trace_hardirqs_off+0xd/0x10
>  [<ffffffff8883dda4>] ? retint_restore_args+0xe/0xe
>  [<ffffffff8822572b>] filename_lookup+0x2b/0xc0
>  [<ffffffff88229c77>] user_path_at_empty+0x67/0xc0
>  [<ffffffff880d3dbe>] ? put_lock_stats.isra.27+0xe/0x30
>  [<ffffffff880d42a6>] ? lock_release_holdtime.part.28+0xe6/0x160
>  [<ffffffff880b15ad>] ? get_parent_ip+0xd/0x50
>  [<ffffffff88229ce1>] user_path_at+0x11/0x20
>  [<ffffffff8824fac1>] do_utimes+0xd1/0x180
>  [<ffffffff8824fbef>] SyS_utime+0x7f/0xc0
>  [<ffffffff8883d345>] ? tracesys+0x7e/0xe2
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2

This one will require more looking.  But did you do something like
create a pair of mutually recursive symlinks or something?  ;-)

							Thanx, Paul

> trinity-c342    R  running task    13384   766  32295 0x00000000
>  ffff880068943d58 0000000000000002 0000000000000002 ffff880193c8c680
>  00000000001d4100 0000000000000000 ffff880068943fd8 00000000001d4100
>  ffff88024302c680 ffff880193c8c680 ffff880068943fd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff880d9424>] ? lock_acquire+0xd4/0x2b0
>  [<ffffffff8808d495>] ? kill_pid_info+0x5/0x130
>  [<ffffffff8808d4d5>] kill_pid_info+0x45/0x130
>  [<ffffffff8808d495>] ? kill_pid_info+0x5/0x130
>  [<ffffffff8808d6d2>] SYSC_kill+0xf2/0x2f0
>  [<ffffffff8808d67b>] ? SYSC_kill+0x9b/0x2f0
>  [<ffffffff8819c2b7>] ? context_tracking_user_exit+0x57/0x280
>  [<ffffffff880136bd>] ? syscall_trace_enter+0x13d/0x310
>  [<ffffffff8808fd9e>] SyS_kill+0xe/0x10
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2
> trinity-c225    R  running task    13448   646  32295 0x00000000
>  ffff880161ccfb28 0000000000000002 ffff880161ccfe10 ffff88000bf85e00
>  00000000001d4100 0000000000000003 ffff880161ccffd8 00000000001d4100
>  ffff880030124680 ffff88000bf85e00 ffff880161ccffd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff88233d41>] ? __d_lookup_rcu+0xd1/0x1e0
>  [<ffffffff88233dd6>] ? __d_lookup_rcu+0x166/0x1e0
>  [<ffffffff88222f9f>] lookup_fast+0x4f/0x3d0
>  [<ffffffff88224857>] link_path_walk+0x1a7/0x8a0
>  [<ffffffff88224f95>] ? path_lookupat+0x45/0x7b0
>  [<ffffffff88224fb7>] path_lookupat+0x67/0x7b0
>  [<ffffffff880d385d>] ? trace_hardirqs_off+0xd/0x10
>  [<ffffffff8883dda4>] ? retint_restore_args+0xe/0xe
>  [<ffffffff8822572b>] filename_lookup+0x2b/0xc0
>  [<ffffffff88229c77>] user_path_at_empty+0x67/0xc0
>  [<ffffffff880d3dbe>] ? put_lock_stats.isra.27+0xe/0x30
>  [<ffffffff880d42a6>] ? lock_release_holdtime.part.28+0xe6/0x160
>  [<ffffffff880b15ad>] ? get_parent_ip+0xd/0x50
>  [<ffffffff88229ce1>] user_path_at+0x11/0x20
>  [<ffffffff8824fac1>] do_utimes+0xd1/0x180
>  [<ffffffff8824fbef>] SyS_utime+0x7f/0xc0
>  [<ffffffff8883d345>] ? tracesys+0x7e/0xe2
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2
> INFO: rcu_preempt detected stalls on CPUs/tasks:
> 	Tasks blocked on level-0 rcu_node (CPUs 0-3): P766 P646
> 	Tasks blocked on level-0 rcu_node (CPUs 0-3): P766 P646
> 	(detected by 3, t=26007 jiffies, g=75434, c=75433, q=0)
> trinity-c342    R  running task    13384   766  32295 0x00000000
>  ffff880068943d98 0000000000000002 0000000000000000 ffff880193c8c680
>  00000000001d4100 0000000000000000 ffff880068943fd8 00000000001d4100
>  ffff88000188af00 ffff880193c8c680 ffff880068943fd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff8809f767>] ? pid_task+0x47/0xa0
>  [<ffffffff8809f73d>] ? pid_task+0x1d/0xa0
>  [<ffffffff8808d4f1>] kill_pid_info+0x61/0x130
>  [<ffffffff8808d495>] ? kill_pid_info+0x5/0x130
>  [<ffffffff8808d6d2>] SYSC_kill+0xf2/0x2f0
>  [<ffffffff8808d67b>] ? SYSC_kill+0x9b/0x2f0
>  [<ffffffff8819c2b7>] ? context_tracking_user_exit+0x57/0x280
>  [<ffffffff880136bd>] ? syscall_trace_enter+0x13d/0x310
>  [<ffffffff8808fd9e>] SyS_kill+0xe/0x10
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2
> trinity-c225    R  running task    13448   646  32295 0x00000000
>  ffff880161ccfb78 0000000000000002 ffffffff88c993ed ffff88000bf85e00
>  00000000001d4100 0000000000000003 ffff880161ccffd8 00000000001d4100
>  ffff88005ea89780 ffff88000bf85e00 ffff880161ccffd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff8822303a>] ? lookup_fast+0xea/0x3d0
>  [<ffffffff88223025>] ? lookup_fast+0xd5/0x3d0
>  [<ffffffff88224857>] link_path_walk+0x1a7/0x8a0
>  [<ffffffff88224f95>] ? path_lookupat+0x45/0x7b0
>  [<ffffffff88224fb7>] path_lookupat+0x67/0x7b0
>  [<ffffffff880d385d>] ? trace_hardirqs_off+0xd/0x10
>  [<ffffffff8883dda4>] ? retint_restore_args+0xe/0xe
>  [<ffffffff8822572b>] filename_lookup+0x2b/0xc0
>  [<ffffffff88229c77>] user_path_at_empty+0x67/0xc0
>  [<ffffffff880d3dbe>] ? put_lock_stats.isra.27+0xe/0x30
>  [<ffffffff880d42a6>] ? lock_release_holdtime.part.28+0xe6/0x160
>  [<ffffffff880b15ad>] ? get_parent_ip+0xd/0x50
>  [<ffffffff88229ce1>] user_path_at+0x11/0x20
>  [<ffffffff8824fac1>] do_utimes+0xd1/0x180
>  [<ffffffff8824fbef>] SyS_utime+0x7f/0xc0
>  [<ffffffff8883d345>] ? tracesys+0x7e/0xe2
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2
> trinity-c342    R  running task    13384   766  32295 0x00000000
>  ffff880068943d98 0000000000000002 0000000000000000 ffff880193c8c680
>  00000000001d4100 0000000000000000 ffff880068943fd8 00000000001d4100
>  ffff88000188af00 ffff880193c8c680 ffff880068943fd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff8809f767>] ? pid_task+0x47/0xa0
>  [<ffffffff8809f73d>] ? pid_task+0x1d/0xa0
>  [<ffffffff8808d4f1>] kill_pid_info+0x61/0x130
>  [<ffffffff8808d495>] ? kill_pid_info+0x5/0x130
>  [<ffffffff8808d6d2>] SYSC_kill+0xf2/0x2f0
>  [<ffffffff8808d67b>] ? SYSC_kill+0x9b/0x2f0
>  [<ffffffff8819c2b7>] ? context_tracking_user_exit+0x57/0x280
>  [<ffffffff880136bd>] ? syscall_trace_enter+0x13d/0x310
>  [<ffffffff8808fd9e>] SyS_kill+0xe/0x10
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2
> trinity-c225    R  running task    13448   646  32295 0x00000000
>  ffff880161ccfb78 0000000000000002 ffffffff88c993ed ffff88000bf85e00
>  00000000001d4100 0000000000000003 ffff880161ccffd8 00000000001d4100
>  ffff88005ea89780 ffff88000bf85e00 ffff880161ccffd8 0000000000000000
> Call Trace:
>  [<ffffffff888368e2>] preempt_schedule_irq+0x52/0xb0
>  [<ffffffff8883df10>] retint_kernel+0x20/0x30
>  [<ffffffff8822303a>] ? lookup_fast+0xea/0x3d0
>  [<ffffffff88223025>] ? lookup_fast+0xd5/0x3d0
>  [<ffffffff88224857>] link_path_walk+0x1a7/0x8a0
>  [<ffffffff88224f95>] ? path_lookupat+0x45/0x7b0
>  [<ffffffff88224fb7>] path_lookupat+0x67/0x7b0
>  [<ffffffff880d385d>] ? trace_hardirqs_off+0xd/0x10
>  [<ffffffff8883dda4>] ? retint_restore_args+0xe/0xe
>  [<ffffffff8822572b>] filename_lookup+0x2b/0xc0
>  [<ffffffff88229c77>] user_path_at_empty+0x67/0xc0
>  [<ffffffff880d3dbe>] ? put_lock_stats.isra.27+0xe/0x30
>  [<ffffffff880d42a6>] ? lock_release_holdtime.part.28+0xe6/0x160
>  [<ffffffff880b15ad>] ? get_parent_ip+0xd/0x50
>  [<ffffffff88229ce1>] user_path_at+0x11/0x20
>  [<ffffffff8824fac1>] do_utimes+0xd1/0x180
>  [<ffffffff8824fbef>] SyS_utime+0x7f/0xc0
>  [<ffffffff8883d345>] ? tracesys+0x7e/0xe2
>  [<ffffffff8883d3a4>] tracesys+0xdd/0xe2
> 
> This is on Linus' current tree, with the new CONFIG_TASKS_RCU unset.

------------------------------------------------------------------------

diff --git a/kernel/signal.c b/kernel/signal.c
index 8f0876f9f6dd..ef6525d0ca73 100644
--- a/kernel/signal.c
+++ b/kernel/signal.c
@@ -1331,8 +1331,8 @@ int kill_pid_info(int sig, struct siginfo *info, struct pid *pid)
 	int error = -ESRCH;
 	struct task_struct *p;
 
-	rcu_read_lock();
 retry:
+	rcu_read_lock();
 	p = pid_task(pid, PIDTYPE_PID);
 	if (p) {
 		error = group_send_sig_info(sig, info, p);
@@ -1343,6 +1343,7 @@ retry:
 			 * if we race with de_thread() it will find the
 			 * new leader.
 			 */
+			rcu_read_unlock();
 			goto retry;
 	}
 	rcu_read_unlock();

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ