linux-kernel - [lkp-robot] [rcu] 6ec8474821: WARNING:at_kernel/softirq.c:#__local_bh_enable

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:   Tue, 8 May 2018 13:09:36 +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]  6ec8474821:
 WARNING:at_kernel/softirq.c:#__local_bh_enable_ip


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

commit: 6ec84748215d9b0c91dba0b8674540e493ce2dcf ("rcu: Make simple callback acceleration refer to rdp->gp_seq_needed")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2018.05.01a

in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -m 420M

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


+---------------------------------------------------+------------+------------+
|                                                   | 7b05a33e23 | 6ec8474821 |
+---------------------------------------------------+------------+------------+
| boot_successes                                    | 1097       | 186        |
| boot_failures                                     | 42         | 34         |
| BUG:kernel_reboot-without-warning_in_test_stage   | 7          |            |
| BUG:kernel_hang_in_test_stage                     | 17         |            |
| IP-Config:Auto-configuration_of_network_failed    | 18         | 22         |
| WARNING:at_kernel/softirq.c:#__local_bh_enable_ip | 0          | 34         |
| RIP:__local_bh_enable_ip                          | 0          | 34         |
| RIP:rcu_gp_kthread                                | 0          | 4          |
| RIP:_raw_spin_unlock_irq                          | 0          | 25         |
| RIP:_raw_spin_lock_irq                            | 0          | 1          |
| RIP:lock_is_held_type                             | 0          | 1          |
| RIP:rcu_dynticks_curr_cpu_in_eqs                  | 0          | 1          |
+---------------------------------------------------+------------+------------+



[   12.277264] WARNING: CPU: 0 PID: 10 at kernel/softirq.c:161 __local_bh_enable_ip+0x5c/0xc4
[   12.280239] Modules linked in:
[   12.281495] CPU: 0 PID: 10 Comm: rcu_sched Not tainted 4.17.0-rc1-00087-g6ec8474 #126
[   12.284043] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[   12.286752] RIP: 0010:__local_bh_enable_ip+0x5c/0xc4
[   12.288514] RSP: 0000:ffff8d3a59c03e98 EFLAGS: 00010086
[   12.290002] RAX: 0000000000000000 RBX: 0000000000000201 RCX: 0000000000000007
[   12.291862] RDX: 0000000000000000 RSI: ffff8d3a59dd5840 RDI: ffff8d3a59dd5840
[   12.294071] RBP: ffffffff90121558 R08: 00000000aefba407 R09: 0000000000000004
[   12.295877] R10: ffff8d3a580c0040 R11: 0000000000000001 R12: ffffffff9011fbb0
[   12.297673] R13: 000000000000000a R14: ffffffff91a82480 R15: ffff8d3a59de2f00
[   12.299577] FS:  0000000000000000(0000) GS:ffff8d3a59c00000(0000) knlGS:0000000000000000
[   12.302107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   12.303787] CR2: 000000000808f132 CR3: 0000000014740000 CR4: 00000000000006f0
[   12.305657] Call Trace:
[   12.306655]  <IRQ>
[   12.307753]  rcu_do_batch+0x71d/0x9cf
[   12.308979]  ? note_gp_changes+0x6d/0xaf
[   12.310446]  rcu_process_callbacks+0x445/0x575
[   12.311979]  __do_softirq+0x1fe/0x416
[   12.313211]  irq_exit+0x59/0xa8
[   12.314652]  smp_apic_timer_interrupt+0x285/0x290
[   12.316044]  apic_timer_interrupt+0xf/0x20
[   12.317368]  </IRQ>
[   12.318299] RIP: 0010:lock_is_held_type+0x4b/0x56
[   12.319727] RSP: 0000:ffffb2344011be78 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[   12.322324] RAX: 0000000000000000 RBX: ffff8d3a580c0040 RCX: 0000000000000001
[   12.324382] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: 0000000000000246
[   12.326314] RBP: ffff8d3a59de2f00 R08: 00000000aefba407 R09: 0000000000000004
[   12.328220] R10: ffff8d3a580c0040 R11: 0000000000000001 R12: 0000000000005494
[   12.330233] R13: 0000000000005401 R14: 0000000000000246 R15: ffffffff91a82900
[   12.332240]  rcu_read_lock_sched_held+0x51/0x57
[   12.333721]  rcu_gp_kthread+0x11b/0x13b7
[   12.335271]  ? rcu_sched_get_gp_seq+0x11/0x11
[   12.336784]  kthread+0x124/0x12c
[   12.338005]  ? kthread_create_on_node+0x62/0x62
[   12.339539]  ret_from_fork+0x3a/0x50
[   12.340915] Code: 08 00 00 00 75 27 83 b8 50 08 00 00 00 75 1e 80 3d 8c 9b b3 01 00 75 15 48 c7 c7 74 b3 80 91 c6 05 7c 9b b3 01 01 e8 1b 94 ff ff <0f> 0b fa 66 0f 1f 44 00 00 e8 e1 83 04 00 65 8b 05 12 4d f6 6f 
[   12.346330] irq event stamp: 150667
[   12.347696] hardirqs last  enabled at (150666): [<ffffffff901228f6>] note_gp_changes+0x6d/0xaf
[   12.350360] hardirqs last disabled at (150667): [<ffffffff90122dab>] rcu_process_callbacks+0x257/0x575
[   12.353207] softirqs last  enabled at (148284): [<ffffffff912003da>] __do_softirq+0x3da/0x416
[   12.357175] softirqs last disabled at (150649): [<ffffffff900b0307>] irq_exit+0x59/0xa8
[   12.359963] ---[ end trace 72bef54097ed5232 ]---


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.17.0-rc1-00087-g6ec8474" of type "text/plain" (117851 bytes)

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

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