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>] [day] [month] [year] [list]
Message-ID: <20180206082608.GA22422@yexl-desktop>
Date:   Tue, 6 Feb 2018 16:26:08 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
Cc:     LKML <linux-kernel@...r.kernel.org>,
        "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>, lkp@...org
Subject: [lkp-robot] [rcu]  6c0a1d639c: BUG:scheduling_while_atomic


FYI, we noticed the following commit (built with gcc-4.9):

commit: 6c0a1d639cb7e989007cc3153b2f4eafb2e5bb7b ("rcu: Parallelize expedited grace-period initialization")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git rcu/dev

in testcase: trinity
with following parameters:

	runtime: 300s

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-i386 -enable-kvm -smp 2 -m 320M

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+-------------------------------------------------------+------------+------------+
|                                                       | 0f0a62adf1 | 6c0a1d639c |
+-------------------------------------------------------+------------+------------+
| boot_successes                                        | 0          | 0          |
| boot_failures                                         | 196        | 67         |
| WARNING:possible_circular_locking_dependency_detected | 196        |            |
| WARNING:at_drivers/pci/pci-sysfs.c:#pci_mmap_resource | 20         |            |
| EIP:pci_mmap_resource                                 | 22         |            |
| invoked_oom-killer:gfp_mask=0x                        | 1          |            |
| Mem-Info                                              | 10         |            |
| EIP:__put_user_4                                      | 1          |            |
| BUG:scheduling_while_atomic                           | 0          | 67         |
| WARNING:at_kernel/locking/lockdep.c:#lock_release     | 0          | 67         |
| EIP:lock_release                                      | 0          | 67         |
| WARNING:at_kernel/locking/lockdep.c:#lock_unpin_lock  | 0          | 67         |
| EIP:lock_unpin_lock                                   | 0          | 67         |
+-------------------------------------------------------+------------+------------+



[    0.066192] BUG: scheduling while atomic: swapper/0/0/0x00000002
[    0.068160] 1 lock held by swapper/0/0:
[    0.070023]  #0:  (rcu_preempt_state.exp_mutex){+.+.}, at: [<c10d920a>] _synchronize_rcu_expedited+0x7aa/0xa10
[    0.073303] Modules linked in:
[    0.074521] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.15.0-rc1-00112-g6c0a1d63 #774
[    0.077215] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[    0.080000] Call Trace:
[    0.080000]  dump_stack+0x76/0xa9
[    0.080000]  __schedule_bug+0x72/0xa0
[    0.080000]  __schedule+0x871/0xb30
[    0.080000]  ? mark_held_locks+0x73/0xa0
[    0.080000]  ? _raw_spin_unlock_irqrestore+0x4d/0x70
[    0.080000]  schedule+0x35/0x80
[    0.080000]  schedule_timeout+0x192/0x490
[    0.080000]  ? collect_expired_timers+0xc0/0xc0
[    0.080000]  rcu_exp_wait_wake+0xaf/0x940
[    0.080000]  ? trace_hardirqs_on+0xb/0x10
[    0.080000]  _synchronize_rcu_expedited+0x931/0xa10
[    0.080000]  ? native_set_pte+0x10/0x10
[    0.080000]  ? native_set_pte_at+0x10/0x10
[    0.080000]  ? __ptep_modify_prot_start+0x10/0x10
[    0.080000]  ? __paravirt_pgd_alloc+0x10/0x10
[    0.080000]  ? rcu_report_exp_cpu_mult+0x70/0x70
[    0.080000]  ? __paravirt_pgd_alloc+0x10/0x10
[    0.080000]  ? rewind_stack_do_exit+0x13/0x13
[    0.080000]  ? rewind_stack_do_exit+0x13/0x13
[    0.080000]  ? rewind_stack_do_exit+0x13/0x13
[    0.080000]  ? end_pv_irq_ops_irq_disable+0x1/0x1
[    0.080000]  ? ___ratelimit+0xb7/0x110
[    0.080000]  ? trace_hardirqs_on+0xb/0x10
[    0.080000]  ? apply_paravirt+0xc7/0x130
[    0.080000]  ? ___ratelimit+0xb7/0x110
[    0.080000]  ? wake_up_klogd+0x8/0x50
[    0.080000]  ? ___might_sleep+0x2f/0x1f0
[    0.080000]  ? acpi_hw_validate_io_request+0xe/0xed
[    0.080000]  ? acpi_os_read_port+0xb/0x60
[    0.080000]  synchronize_rcu_expedited+0x37/0xb0
[    0.080000]  synchronize_rcu+0xb5/0xe0
[    0.080000]  ? acpi_hw_read_multiple+0x1a/0x47
[    0.080000]  ? ___might_sleep+0x2f/0x1f0
[    0.080000]  ? acpi_hw_register_read+0x56/0xbc
[    0.080000]  ? __might_sleep+0x33/0x90
[    0.080000]  ? find_next_bit+0x12/0x20
[    0.080000]  ? cpumask_next+0x15/0x20
[    0.080000]  ? synchronize_sched_expedited+0x3c/0xe0
[    0.080000]  rcu_test_sync_prims+0xd/0x30
[    0.080000]  rcu_scheduler_starting+0x34/0x60
[    0.080000]  rest_init+0xe/0x1f0
[    0.080000]  start_kernel+0x44f/0x457
[    0.080000]  i386_start_kernel+0x8f/0x93
[    0.080000]  startup_32_smp+0x164/0x170
[    0.080044] ------------[ cut here ]------------
[    0.082082] releasing a pinned lock
[    0.083741] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:3780 lock_release+0x45c/0x4b0
[    0.087752] Modules linked in:
[    0.089169] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W        4.15.0-rc1-00112-g6c0a1d63 #774
[    0.090000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[    0.090000] task: c1ba3340 task.stack: c1b98000
[    0.090000] EIP: lock_release+0x45c/0x4b0
[    0.090000] EFLAGS: 00210082 CPU: 0
[    0.090000] EAX: 00000017 EBX: d244b2c0 ECX: c10c08f0 EDX: c10c090c
[    0.090000] ESI: c1ba39b8 EDI: c1ba3340 EBP: c1b99c64 ESP: c1b99c34
[    0.090000]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[    0.090000] CR0: 80050033 CR2: ffffffff CR3: 01e7a000 CR4: 00000690
[    0.090000] Call Trace:
[    0.090000]  ? dequeue_task_idle+0x13/0x40
[    0.090000]  _raw_spin_unlock_irq+0x1b/0x50
[    0.090000]  dequeue_task_idle+0x13/0x40
[    0.090000]  deactivate_task+0xb8/0x160
[    0.090000]  __schedule+0x55c/0xb30
[    0.090000]  ? _raw_spin_unlock_irqrestore+0x4d/0x70
[    0.090000]  schedule+0x35/0x80
[    0.090000]  schedule_timeout+0x192/0x490
[    0.090000]  ? collect_expired_timers+0xc0/0xc0
[    0.090000]  rcu_exp_wait_wake+0xaf/0x940
[    0.090000]  ? trace_hardirqs_on+0xb/0x10
[    0.090000]  _synchronize_rcu_expedited+0x931/0xa10
[    0.090000]  ? native_set_pte+0x10/0x10
[    0.090000]  ? native_set_pte_at+0x10/0x10
[    0.090000]  ? __ptep_modify_prot_start+0x10/0x10
[    0.090000]  ? __paravirt_pgd_alloc+0x10/0x10
[    0.090000]  ? rcu_report_exp_cpu_mult+0x70/0x70
[    0.090000]  ? __paravirt_pgd_alloc+0x10/0x10
[    0.090000]  ? rewind_stack_do_exit+0x13/0x13
[    0.090000]  ? rewind_stack_do_exit+0x13/0x13
[    0.090000]  ? rewind_stack_do_exit+0x13/0x13
[    0.090000]  ? end_pv_irq_ops_irq_disable+0x1/0x1
[    0.090000]  ? ___ratelimit+0xb7/0x110
[    0.090000]  ? trace_hardirqs_on+0xb/0x10
[    0.090000]  ? apply_paravirt+0xc7/0x130
[    0.090000]  ? ___ratelimit+0xb7/0x110
[    0.090000]  ? wake_up_klogd+0x8/0x50
[    0.090000]  ? ___might_sleep+0x2f/0x1f0
[    0.090000]  ? acpi_hw_validate_io_request+0xe/0xed
[    0.090000]  ? acpi_os_read_port+0xb/0x60
[    0.090000]  synchronize_rcu_expedited+0x37/0xb0
[    0.090000]  synchronize_rcu+0xb5/0xe0
[    0.090000]  ? acpi_hw_read_multiple+0x1a/0x47
[    0.090000]  ? ___might_sleep+0x2f/0x1f0
[    0.090000]  ? acpi_hw_register_read+0x56/0xbc
[    0.090000]  ? __might_sleep+0x33/0x90
[    0.090000]  ? find_next_bit+0x12/0x20
[    0.090000]  ? cpumask_next+0x15/0x20
[    0.090000]  ? synchronize_sched_expedited+0x3c/0xe0
[    0.090000]  rcu_test_sync_prims+0xd/0x30
[    0.090000]  rcu_scheduler_starting+0x34/0x60
[    0.090000]  rest_init+0xe/0x1f0
[    0.090000]  start_kernel+0x44f/0x457
[    0.090000]  i386_start_kernel+0x8f/0x93
[    0.090000]  startup_32_smp+0x164/0x170
[    0.090000] Code: c1 ba 3f 00 00 00 b8 08 11 a9 c1 c6 05 6e f3 c5 c1 01 e8 08 b4 ff ff e9 cd fd ff ff 8d 76 00 c7 04 24 9f fc a8 c1 e8 34 5c fa ff <0f> ff e9 6c fc ff ff e8 c2 c4 f4 ff e9 57 fc ff ff 8d 44 03 74
[    0.090000] ---[ end trace 677d86ae136591a1 ]---


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script  # job-script is attached in this email



Thanks,
Xiaolong

View attachment "config-4.15.0-rc1-00112-g6c0a1d63" of type "text/plain" (111138 bytes)

View attachment "job-script" of type "text/plain" (3927 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (14476 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ