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-next>] [day] [month] [year] [list]
Date:	Thu, 17 Apr 2014 13:36:33 +0800
From:	Jet Chen <jet.chen@...el.com>
To:	"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
CC:	LKML <linux-kernel@...r.kernel.org>,
	Fengguang Wu <fengguang.wu@...el.com>
Subject: [ sched,rcu] BUG: using __this_cpu_add_return() in preemptible [00000000]
 code: swapper/0/1

Hi Paul,

I got the below dmesg and the first bad commit is

git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git dev.2014.04.14a
commit b84c4e08143c98dad4b4d139f08db0b98b0d3ec4
Author:     Paul E. McKenney <paulmck@...ux.vnet.ibm.com>
AuthorDate: Sun Mar 16 21:36:25 2014 -0700
Commit:     Paul E. McKenney <paulmck@...ux.vnet.ibm.com>
CommitDate: Mon Apr 14 11:09:19 2014 -0700

      sched,rcu: Make cond_resched() report RCU quiescent states
          Given a CPU running a loop containing cond_resched(), with no
      other tasks runnable on that CPU, RCU will eventually report RCU
      CPU stall warnings due to lack of quiescent states.  Fortunately,
      every call to cond_resched() is a perfectly good quiescent state.
      Unfortunately, invoking rcu_note_context_switch() is a bit heavyweight
      for cond_resched(), especially given the need to disable preemption,
      and, for RCU-preempt, interrupts as well.
          This commit therefore maintains a per-CPU counter that causes
      cond_resched(), cond_resched_lock(), and cond_resched_softirq() to call
      rcu_note_context_switch(), but only about once per 256 invocations.
      This ratio was chosen in keeping with the relative time constants of
      RCU grace periods.
          Signed-off-by: Paul E. McKenney <paulmck@...ux.vnet.ibm.com>

+-----------------------------------------------------------------+------------+------------+
|                                                                 | ad86a04266 | b84c4e0814 |
+-----------------------------------------------------------------+------------+------------+
| boot_successes                                                  | 295        | 0          |
| boot_failures                                                   | 22         | 20         |
| BUG:kernel_boot_hang                                            | 21         |            |
| BUG:kernel_test_crashed                                         | 1          |            |
| BUG:using__this_cpu_add_return()in_preemptible_code:swapper     | 0          | 20         |
| backtrace:do_execve                                             | 0          | 20         |
| backtrace:run_init_process                                      | 0          | 20         |
| BUG:using__this_cpu_add_return()in_preemptible_code:trinity     | 0          | 7          |
| BUG:using__this_cpu_add_return()in_preemptible_code:rcu_preempt | 0          | 4          |
| backtrace:_cond_resched                                         | 0          | 4          |
| BUG:using__this_cpu_add_return()in_preemptible_code:init        | 0          | 4          |
| backtrace:core_sys_select                                       | 0          | 4          |
| backtrace:SyS_select                                            | 0          | 4          |
| BUG:using__this_cpu_add_return()in_preemptible_code:rc          | 0          | 0          |
| backtrace:do_fork                                               | 0          | 0          |
| backtrace:SyS_clone                                             | 0          | 0          |
| backtrace:SyS_execve                                            | 0          | 0          |
+-----------------------------------------------------------------+------------+------------+

[    2.672306] Write protecting the kernel read-only data: 16384k
[    2.677353] Freeing unused kernel memory: 964K (ffff880001b0f000 - ffff880001c00000)
[    2.681745] Freeing unused kernel memory: 748K (ffff880001f45000 - ffff880002000000)
[    2.683179] BUG: using __this_cpu_add_return() in preemptible [00000000] code: swapper/0/1
[    2.684683] caller is __this_cpu_preempt_check+0x1a/0x23
[    2.685590] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 3.15.0-rc1-00039-gb84c4e0 #14
[    2.687134] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[    2.688068]  0000000000000000 ffff880011471ca0 ffffffff81af1772 0000000000000001
[    2.689738]  ffff880011471cc8 ffffffff81422eb9 ffff880011471da0 ffff880012e7fb00
[    2.691394]  ffffffff81c173a0 ffff880011471cd8 ffffffff81422ef2 ffff880011471ce8
[    2.693062] Call Trace:
[    2.693689]  [<ffffffff81af1772>] dump_stack+0xb0/0x10d
[    2.694567]  [<ffffffff81422eb9>] check_preemption_disabled+0x18b/0x1aa
[    2.695581]  [<ffffffff81422ef2>] __this_cpu_preempt_check+0x1a/0x23
[    2.696601]  [<ffffffff81099b5b>] rcu_should_resched+0x17/0x38
[    2.697565]  [<ffffffff8109a3b0>] rcu_cond_resched+0x10/0x30
[    2.698488]  [<ffffffff81afab41>] _cond_resched+0x10/0x3f
[    2.699389]  [<ffffffff8119735b>] path_openat+0x431/0x75c
[    2.700287]  [<ffffffff81198e8c>] do_filp_open+0x3c/0xa6
[    2.701190]  [<ffffffff813a66bf>] ? aa_dup_task_context+0x3e/0x48
[    2.702159]  [<ffffffff813ad3bd>] ? apparmor_cred_prepare+0x3f/0x5b
[    2.703147]  [<ffffffff8139a495>] ? security_prepare_creds+0x18/0x21
[    2.704139]  [<ffffffff8118d58f>] do_open_exec+0x28/0x1ad
[    2.705039]  [<ffffffff8118df6c>] do_execve_common.isra.30+0x289/0x804
[    2.711803]  [<ffffffff8109d7c6>] ? preempt_count_add+0xcd/0xe7
[    2.712866]  [<ffffffff81193630>] ? getname_kernel+0x46/0x9c
[    2.713843]  [<ffffffff81ae0fb6>] ? rest_init+0xca/0xca
[    2.714809]  [<ffffffff8118e501>] do_execve+0x1a/0x23
[    2.715751]  [<ffffffff81000232>] run_init_process+0x34/0x3d
[    2.716745]  [<ffffffff81ae101f>] kernel_init+0x69/0x175
[    2.717713]  [<ffffffff81b0010c>] ret_from_fork+0x7c/0xb0
[    2.718643]  [<ffffffff81ae0fb6>] ? rest_init+0xca/0xca

Attached dmesg for the parent commit, too, to help confirm whether it is a noise error.

git bisect start e85454f12dcf05f366b5f4f41e27637dbd4d9cfe c9eaa447e77efe77b7fa4c953bd62de8297fd6c5 --
git bisect good b888dc84d249e4fecd35f1038cc1e27ce924456f  # 20:57     20+      0  Merge 'socfpga-nex/for-next' into devel-hourly-2014041512
git bisect good 266a677952566287e6c25e497da29d3d780ad0d3  # 20:57     20+      0  Merge 'asoc/topic/davinci' into devel-hourly-2014041512
git bisect  bad 50ac0be0d367abf72f540045a674ba07a785b37c  # 20:57      0-     20  Merge 'kees/nak_devtmpfs-safe' into devel-hourly-2014041512
git bisect good db710d86df4bb5e92eaa2589e9b10f9ad21d0705  # 20:57     20+      0  Merge 'stericsson/ux500-core' into devel-hourly-2014041512
git bisect  bad 8bffb3ac073ee45338694a7d580dbf587e54f0dc  # 20:57      0-     20  Merge 'kees/nak_fw-relative' into devel-hourly-2014041512
git bisect  bad fdd31f30392753e38d407fd05b8a17b09f5863c9  # 20:58      0-     20  Merge 'dynticks/core/threadgroup' into devel-hourly-2014041512
git bisect  bad 7a3e2d770aca838245decbe7a69c104331732ef8  # 20:58      0-     20  Merge 'rcu/dev.2014.04.14a' into devel-hourly-2014041512
git bisect good 44979a316b57116968bcd960f914d2410aa75910  # 20:58     20+      0  rcu: Update cpu_needs_another_gp() for futures from non-NOCB CPUs
git bisect  bad 10cb7ccef834ae3afab56f201b67d7077767481c  # 20:58      0-     20  rcu: Merge rcu_sched_force_quiescent_state() with rcu_force_quiescent_state()
git bisect  bad f0d4293e29bfa15ada0563d510175d5a25453a8a  # 20:58      0-     20  rcutorture: Make rcu_torture_reader() use cond_resched()
git bisect good e0e7c2ec22bf52c54e1cc49954bcc82eb2968c62  # 20:58     20+      0  rcu: Export RCU grace-period kthread wait state to rcutorture
git bisect good ad86a04266f9b49730424023f6b66fe45b66e509  # 21:00     20+      1  rcu: Protect uses of ->jiffies_stall with ACCESS_ONCE()
git bisect  bad b84c4e08143c98dad4b4d139f08db0b98b0d3ec4  # 21:00      0-     20  sched,rcu: Make cond_resched() report RCU quiescent states
# first bad commit: [b84c4e08143c98dad4b4d139f08db0b98b0d3ec4] sched,rcu: Make cond_resched() report RCU quiescent states
git bisect good ad86a04266f9b49730424023f6b66fe45b66e509  # 21:03     60+      1  rcu: Protect uses of ->jiffies_stall with ACCESS_ONCE()
git bisect  bad e85454f12dcf05f366b5f4f41e27637dbd4d9cfe  # 21:03      0-     23  0day head guard for 'devel-hourly-2014041512'
git bisect good 10ec34fcb100412ab186c141a9c3557d1270effd  # 21:33     60+      0  Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
git bisect good 2db08cc65391d73dc8cbcaefdb55c42a774d9e1a  # 22:34     60+      9  Add linux-next specific files for 20140416


This script may reproduce the error.

-----------------------------------------------------------------------------
#!/bin/bash

kernel=$1

kvm=(
	qemu-system-x86_64 -cpu kvm64 -enable-kvm 	-kernel $kernel
	-smp 2
	-m 256M
	-net nic,vlan=0,macaddr=00:00:00:00:00:00,model=virtio
	-net user,vlan=0
	-net nic,vlan=1,model=e1000
	-net user,vlan=1
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-serial stdio
	-display none
	-monitor null
)

append=(
	debug
	sched_debug
	apic=debug
	ignore_loglevel
	sysrq_always_enabled
	panic=10
	prompt_ramdisk=0
	earlyprintk=ttyS0,115200
	console=ttyS0,115200
	console=tty0
	vga=normal
	root=/dev/ram0
	rw
)

"${kvm[@]}" --append "${append[*]}"
-----------------------------------------------------------------------------

Thanks,
Jet



View attachment "dmesg-quantal-f2-63:20140415170520:x86_64-randconfig-i0-04151432:3.15.0-rc1-00039-gb84c4e0:14" of type "text/plain" (63915 bytes)

View attachment "dmesg-quantal-brickland3-123:20140416220201:x86_64-randconfig-i0-04151432:3.15.0-rc1-00038-gad86a04:13" of type "text/plain" (47667 bytes)

Download attachment "x86_64-randconfig-i0-04151432-e85454f12dcf05f366b5f4f41e27637dbd4d9cfe-BUG:-using----in-preemptible----code:-52568.log" of type "application/octet-stream" (59114 bytes)

View attachment "config-3.15.0-rc1-00039-gb84c4e0" of type "text/plain" (88843 bytes)

View attachment "Attached Message Part" of type "text/plain" (87 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ