linux-kernel - [lkp-developer] [spinlock_debug] bb161feebc: BUG:spinlock_missed_unlock_deadline_on

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]

Message-ID: <20161219001159.GB1723@yexl-desktop>
Date:   Mon, 19 Dec 2016 08:11:59 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     Sergey Senozhatsky <sergey.senozhatsky@...il.com>
Cc:     linux-kernel@...r.kernel.org,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>, lkp@...org
Subject: [lkp-developer] [spinlock_debug]  bb161feebc:
 BUG:spinlock_missed_unlock_deadline_on_CPU


FYI, we noticed the following commit:

commit: bb161feebcbd8560751784c5acdbdca9609624e5 ("spinlock_debug: report spinlock lockup from unlock")
url: https://github.com/0day-ci/linux/commits/Sergey-Senozhatsky/spinlock_debug-report-spinlock-lockup-from-unlock/20161218-002435


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:


+------------------------------------------------------------------+------------+------------+
|                                                                  | 11f254dbb3 | bb161feebc |
+------------------------------------------------------------------+------------+------------+
| boot_successes                                                   | 20         | 4          |
| boot_failures                                                    | 10         | 24         |
| invoked_oom-killer:gfp_mask=0x                                   | 10         | 7          |
| Mem-Info                                                         | 10         | 7          |
| page_allocation_failure:order:#,mode:#(GFP_KERNEL|__GFP_NORETRY) | 3          | 1          |
| BUG:spinlock_missed_unlock_deadline_on_CPU                       | 0          | 17         |
| calltrace:rcu_torture_stats                                      | 0          | 13         |
| calltrace:SyS_execve                                             | 0          | 1          |
| calltrace:SyS_exit_group                                         | 0          | 1          |
| calltrace:ring_buffer_producer_thread                            | 0          | 1          |
+------------------------------------------------------------------+------------+------------+



[  146.324730] rb_produ-46      0.... 136705568us : ring_buffer_producer_thread: 3690 ns per entry
[  146.343500] rb_produ-46      0.... 136705569us : ring_buffer_producer_thread: Sleeping for 10 secs
[  146.362484] ---------------------------------
[  146.372237] BUG: spinlock missed unlock deadline on CPU#1, rcu_torture_sta/41
[  146.388805]  lock: jiffies_lock+0x14/0x40, .magic: dead4ead, .owner: rcu_torture_sta/41, .owner_cpu: 1
[  146.409995] CPU: 1 PID: 41 Comm: rcu_torture_sta Not tainted 4.9.0-rc8-00175-gbb161fe #2
[  146.429314] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  146.452805]  cfd9fda0 c137d94f d1f1b35c c1871ed4 cfd9fdc8 c1074f3a c17b120c c1871ed4
[  146.479859]  dead4ead d1f1b35c 00000029 00000001 c1871ed4 000f4240 cfd9fdd8 c1074f61
[  146.505565]  c17b12be c1871ed4 cfd9fde4 c107515c c1871ed4 cfd9fdf0 c15c87bb 00000000
[  146.532230] Call Trace:
[  146.538713]  [<c137d94f>] dump_stack+0x72/0xa3
[  146.548623]  [<c1074f3a>] spin_dump+0x75/0x7f
[  146.557793]  [<c1074f61>] spin_bug+0x1d/0x21
[  146.566973]  [<c107515c>] do_raw_spin_unlock+0x74/0x88
[  146.577409]  [<c15c87bb>] _raw_spin_unlock+0x1d/0x30
[  146.587680]  [<c10969f5>] tick_do_update_jiffies64+0xfd/0x11b
[  146.599311]  [<c1096a71>] tick_nohz_handler+0x5e/0xce
[  146.609514]  [<c1027f80>] local_apic_timer_interrupt+0x3c/0x41
[  146.621385]  [<c1028614>] smp_apic_timer_interrupt+0x20/0x2f
[  146.632786]  [<c15c99f2>] apic_timer_interrupt+0x32/0x40
[  146.643638]  [<c10b5ce7>] ? arch_local_irq_restore+0x5/0xb
[  146.654590]  [<c10bc412>] ftrace_dump+0x1bd/0x1c5
[  146.663894]  [<c1083c28>] rcu_torture_stats_print+0x33e/0x350
[  146.675269]  [<c1083c3a>] ? rcu_torture_stats_print+0x350/0x350
[  146.686421]  [<c1083c72>] rcu_torture_stats+0x38/0x59
[  146.696629]  [<c1057f92>] kthread+0x8d/0x92
[  146.705274]  [<c1057f05>] ? kthread_create_on_node+0x1a/0x1a
[  146.716753]  [<c15c8e3b>] ret_from_fork+0x1b/0x30
[  147.447220] serial8250: too much work for irq3
[  150.482619] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x20974986637, max_idle_ns: 440795286310 ns



To reproduce:

        git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/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.9.0-rc8-00175-gbb161fe" of type "text/plain" (93669 bytes)

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

Download attachment "dmesg.xz" of type "application/octet-stream" (13840 bytes)