[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180705080227.GH23907@yexl-desktop>
Date: Thu, 5 Jul 2018 16:02:27 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Matt Fleming <matt@...eblueprint.co.uk>
Cc: Peter Zijlstra <peterz@...radead.org>,
linux-kernel@...r.kernel.org,
Matt Fleming <matt@...eblueprint.co.uk>,
Ingo Molnar <mingo@...nel.org>,
Mike Galbraith <umgwanakikbuti@...il.com>, lkp@...org
Subject: [lkp-robot] [sched/fair] fbd5188493: WARNING:inconsistent_lock_state
FYI, we noticed the following commit (built with gcc-7):
commit: fbd51884933192c9cada60628892024495942482 ("[PATCH] sched/fair: Avoid divide by zero when rebalancing domains")
url: https://github.com/0day-ci/linux/commits/Matt-Fleming/sched-fair-Avoid-divide-by-zero-when-rebalancing-domains/20180705-024633
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-x86_64 -enable-kvm -cpu host -smp 2 -m 1G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------------+------------+------------+
| | f83ee19be4 | fbd5188493 |
+-------------------------------------------------------+------------+------------+
| boot_successes | 9 | 4 |
| boot_failures | 4 | 8 |
| kernel_BUG_at_lib/list_debug.c | 4 | 5 |
| invalid_opcode:#[##] | 4 | 5 |
| RIP:__list_add_valid | 4 | 5 |
| RIP:separate_adjacent_colors | 3 | |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 4 | 5 |
| RIP:rb_next | 1 | |
| WARNING:inconsistent_lock_state | 0 | 8 |
| inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage | 0 | 8 |
| RIP:smp_call_function_single | 0 | 5 |
| BUG:kernel_hang_in_boot_stage | 0 | 1 |
+-------------------------------------------------------+------------+------------+
[ 0.335612] WARNING: inconsistent lock state
[ 0.336473] pnp: PnP ACPI init
[ 0.337205] 4.18.0-rc3-00016-gfbd5188 #1 Not tainted
[ 0.337206] --------------------------------
[ 0.337208] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[ 0.337211] kworker/u4:0/7 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 0.337212] (____ptrval____) (&rq->lock){?.-.}, at: pick_next_task_fair+0x402/0xb20
[ 0.337226] {IN-HARDIRQ-W} state was registered at:
[ 0.338351] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active)
[ 0.338559] lock_acquire+0x59/0x7c
[ 0.338559] _raw_spin_lock+0x2a/0x40
[ 0.338559] scheduler_tick+0x4c/0xf0
[ 0.338559] update_process_times+0x42/0x50
[ 0.338559] tick_periodic+0x9d/0xa0
[ 0.338559] tick_handle_periodic+0x20/0x70
[ 0.338559] timer_interrupt+0x10/0x20
[ 0.338559] __handle_irq_event_percpu+0x35/0xf0
[ 0.338559] handle_irq_event_percpu+0x2d/0x70
[ 0.338559] handle_irq_event+0x34/0x60
[ 0.338559] handle_level_irq+0xb9/0x110
[ 0.338559] handle_irq+0x18/0x20
[ 0.338559] do_IRQ+0x7b/0x100
[ 0.338559] ret_from_intr+0x0/0x2f
[ 0.338559] native_restore_fl+0x6/0x10
[ 0.338559] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 0.338559] __setup_irq+0x440/0x660
[ 0.338559] setup_irq+0x51/0x80
[ 0.338559] hpet_time_init+0x20/0x32
[ 0.338559] x86_late_time_init+0xa/0x17
[ 0.338559] start_kernel+0x458/0x4d8
[ 0.338559] x86_64_start_reservations+0x2a/0x2c
[ 0.338559] x86_64_start_kernel+0x77/0x7a
[ 0.338559] secondary_startup_64+0xa5/0xb0
[ 0.338559] irq event stamp: 39
[ 0.338559] hardirqs last enabled at (39): [<ffffffff81cf3a97>] _raw_spin_unlock_irq+0x27/0x40
[ 0.338559] hardirqs last disabled at (38): [<ffffffff81ced501>] __schedule+0x181/0x7b0
[ 0.338559] softirqs last enabled at (0): [<ffffffff810ba5c7>] copy_process+0x467/0x1ac0
[ 0.340695] pnp 00:01: Plug and Play ACPI device, IDs PNP0303 (active)
[ 0.338559] softirqs last disabled at (0): [<0000000000000000>] (null)
[ 0.338559]
[ 0.338559] other info that might help us debug this:
[ 0.342629] pnp 00:02: Plug and Play ACPI device, IDs PNP0f13 (active)
[ 0.338559] Possible unsafe locking scenario:
[ 0.338559]
[ 0.338559] CPU0
[ 0.338559] ----
[ 0.338559] lock(&rq->lock);
[ 0.338559] <Interrupt>
[ 0.338559] lock(&rq->lock);
[ 0.338559]
[ 0.338559] *** DEADLOCK ***
[ 0.338559]
[ 0.338559] no locks held by kworker/u4:0/7.
[ 0.338559]
[ 0.338559] stack backtrace:
[ 0.338559] CPU: 1 PID: 7 Comm: kworker/u4:0 Not tainted 4.18.0-rc3-00016-gfbd5188 #1
[ 0.338559] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 0.338559] Call Trace:
[ 0.345537] pnp 00:03: [dma 2]
[ 0.338559] dump_stack+0x8e/0xd5
[ 0.348212] pnp 00:03: Plug and Play ACPI device, IDs PNP0700 (active)
[ 0.338559] print_usage_bug+0x26a/0x280
[ 0.338559] mark_lock+0x361/0x5a0
[ 0.338559] ? check_usage_forwards+0x120/0x120
[ 0.338559] __lock_acquire+0x35c/0x17c0
[ 0.338559] ? __lock_acquire+0x27d/0x17c0
[ 0.338559] ? _nohz_idle_balance+0xa4/0x4f0
[ 0.338559] ? sched_clock_local+0x17/0x90
[ 0.338559] ? trace_hardirqs_on_caller+0x178/0x1a0
[ 0.338559] lock_acquire+0x59/0x7c
[ 0.338559] ? lock_acquire+0x59/0x7c
[ 0.338559] ? pick_next_task_fair+0x402/0xb20
[ 0.338559] _raw_spin_lock+0x2a/0x40
[ 0.338559] ? pick_next_task_fair+0x402/0xb20
[ 0.338559] pick_next_task_fair+0x402/0xb20
[ 0.338559] ? dequeue_task_fair+0x4f5/0x680
[ 0.338559] ? __lock_is_held+0x4b/0x90
[ 0.338559] __schedule+0x3e3/0x7b0
[ 0.338559] schedule+0x1f/0x40
[ 0.338559] worker_thread+0x2f4/0x3b0
[ 0.338559] ? __kthread_parkme+0x4d/0x90
[ 0.338559] kthread+0x121/0x130
[ 0.338559] ? process_one_work+0x3d0/0x3d0
[ 0.338559] ? __kthread_bind_mask+0x60/0x60
[ 0.338559] ret_from_fork+0x24/0x30
[ 0.413149] pnp 00:04: Plug and Play ACPI device, IDs PNP0400 (active)
[ 0.414880] pnp 00:05: Plug and Play ACPI device, IDs PNP0501 (active)
[ 0.416421] pnp 00:06: Plug and Play ACPI device, IDs PNP0501 (active)
[ 0.418533] pnp: PnP ACPI: found 7 devices
[ 0.425600] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[ 0.427702] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 0.429058] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 0.430451] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[ 0.432021] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
[ 0.433752] NET: Registered protocol family 2
[ 0.435374] tcp_listen_portaddr_hash hash table entries: 512 (order: 3, 36864 bytes)
[ 0.444589] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
[ 0.446316] TCP bind hash table entries: 8192 (order: 7, 524288 bytes)
[ 0.448159] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.449826] UDP hash table entries: 512 (order: 4, 81920 bytes)
[ 0.451339] UDP-Lite hash table entries: 512 (order: 4, 81920 bytes)
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.18.0-rc3-00016-gfbd5188" of type "text/plain" (118710 bytes)
View attachment "job-script" of type "text/plain" (3966 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (22448 bytes)
Powered by blists - more mailing lists