linux-kernel - [lkp-robot] [rcu] 5bb856a179: WARNING:at_kernel/workqueue.c:#flush

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]
Date:   Tue, 6 Feb 2018 16:27:24 +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]  5bb856a179:
 WARNING:at_kernel/workqueue.c:#flush_work


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

commit: 5bb856a17977672f2142d06e68ac60e746e7bca2 ("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):


+-------------------------------------------------------+------------+------------+
|                                                       | 5314d220f6 | 5bb856a179 |
+-------------------------------------------------------+------------+------------+
| boot_successes                                        | 0          | 0          |
| boot_failures                                         | 16         | 60         |
| WARNING:possible_circular_locking_dependency_detected | 16         |            |
| genirq:Flags_mismatch_irq##(ttyS0)vs.#(sir_ir)        | 16         |            |
| INFO:rcu_preempt_self-detected_stall_on_CPU           | 10         |            |
| EIP:__do_softirq                                      | 10         |            |
| EIP:_raw_spin_unlock_irqrestore                       | 10         |            |
| WARNING:at_kernel/workqueue.c:#flush_work             | 0          | 60         |
| EIP:flush_work                                        | 0          | 60         |
| BUG:scheduling_while_atomic                           | 0          | 60         |
| WARNING:at_kernel/locking/lockdep.c:#lock_release     | 0          | 60         |
| EIP:lock_release                                      | 0          | 60         |
| WARNING:at_kernel/locking/lockdep.c:#lock_unpin_lock  | 0          | 60         |
| EIP:lock_unpin_lock                                   | 0          | 60         |
| WARNING:CPU:#PID:#at_kernel/                          | 0          | 1          |
+-------------------------------------------------------+------------+------------+



[    0.018242] WARNING: CPU: 0 PID: 0 at kernel/workqueue.c:2866 flush_work+0x27/0x260
[    0.019000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.15.0-rc1-00112-g5bb856a #125
[    0.019000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[    0.019000] task: cb412dc0 task.stack: cb408000
[    0.019000] EIP: flush_work+0x27/0x260
[    0.019000] EFLAGS: 00210246 CPU: 0
[    0.019000] EAX: 00000000 EBX: cb43fac0 ECX: 00000001 EDX: 00000001
[    0.019000] ESI: cb43fa9c EDI: cb43fd00 EBP: cb409e10 ESP: cb409d5c
[    0.019000]  DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[    0.019000] CR0: 80050033 CR2: ffffffff CR3: 0b62d000 CR4: 00000690
[    0.019000] Call Trace:
[    0.019000]  ? __queue_work+0x423/0x450
[    0.019000]  ? mark_held_locks+0x61/0x90
[    0.019000]  ? queue_work_on+0x65/0x80
[    0.019000]  ? trace_hardirqs_on+0xb/0x10
[    0.019000]  sync_rcu_exp_select_cpus+0x201/0x230
[    0.019000]  ? _synchronize_rcu_expedited+0x316/0x340
[    0.019000]  ? rcu_report_exp_cpu_mult+0x60/0x60
[    0.019000]  _synchronize_rcu_expedited+0x210/0x340
[    0.019000]  ? apply_paravirt+0xc5/0x108
[    0.019000]  ? acpi_hw_validate_io_request+0xe/0x10d
[    0.019000]  ? acpi_os_read_port+0xc/0x60
[    0.019000]  ? acpi_hw_read_port+0x44/0xa8
[    0.019000]  ? acpi_hw_read+0x101/0x16b
[    0.019000]  synchronize_rcu_expedited+0x8e/0x90
[    0.019000]  synchronize_rcu+0x97/0xc0
[    0.019000]  ? acpi_hw_read_multiple+0x1b/0x54
[    0.019000]  ? ___might_sleep+0x5d/0x1e0
[    0.019000]  ? acpi_hw_register_read+0x56/0xbc
[    0.019000]  ? __might_sleep+0x74/0x80
[    0.019000]  ? acpi_hw_get_mode+0x2f/0x42
[    0.019000]  ? preempt_count_sub+0xa/0x60
[    0.019000]  ? synchronize_sched_expedited+0xa5/0xc0
[    0.019000]  rcu_test_sync_prims+0xd/0x30
[    0.019000]  rcu_scheduler_starting+0x27/0x30
[    0.019000]  rest_init+0xe/0x1d0
[    0.019000]  start_kernel+0x4b4/0x4cc
[    0.019000]  i386_start_kernel+0xca/0xe3
[    0.019000]  startup_32_smp+0x164/0x168
[    0.019000] Code: 7b ff ff ff 55 89 e5 57 56 53 81 ec a8 00 00 00 e8 f3 f9 fc ff 89 c6 65 a1 14 00 00 00 89 45 f0 31 c0 80 3d a8 d2 63 cb 00 75 09 <0f> ff e9 02 02 00 00 66 90 31 c9 ba f4 0a 00 00 b8 bc c6 32 cb
[    0.019000] ---[ end trace ec20ab83de8b0a87 ]---


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-g5bb856a" of type "text/plain" (99622 bytes)

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

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