[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180428064314.GD6376@yexl-desktop>
Date: Sat, 28 Apr 2018 14:43:14 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Gaurav Kohli <gkohli@...eaurora.org>
Cc: peterz@...radead.org, tglx@...utronix.de, mpe@...erman.id.au,
mingo@...nel.org, bigeasy@...utronix.de,
linux-kernel@...r.kernel.org, linux-arm-msm@...r.kernel.org,
Gaurav Kohli <gkohli@...eaurora.org>,
Neeraj Upadhyay <neeraju@...eaurora.org>, lkp@...org
Subject: [lkp-robot] [kthread/smpboot] cad8e99675:
inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage
FYI, we noticed the following commit (built with gcc-6):
commit: cad8e9967526d263d9a4f04ca763b2d76c045750 ("kthread/smpboot: Serialize kthread parking against wakeup")
url: https://github.com/0day-ci/linux/commits/Gaurav-Kohli/kthread-smpboot-Serialize-kthread-parking-against-wakeup/20180426-185404
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------+-----------+------------+
| | v4.17-rc2 | cad8e99675 |
+------------------------------------------------------------------+-----------+------------+
| boot_successes | 60 | 0 |
| boot_failures | 34 | 10 |
| invoked_oom-killer:gfp_mask=0x | 20 | 4 |
| Mem-Info | 20 | 4 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 11 | |
| Out_of_memory:Kill_process | 9 | 4 |
| RIP:__clear_user | 1 | 1 |
| WARNING:inconsistent_lock_state | 6 | 10 |
| inconsistent{HARDIRQ-ON-W}->{IN-HARDIRQ-W}usage | 6 | |
| calltrace:neigh_periodic_work | 2 | |
| RIP:e1000_watchdog | 4 | |
| BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h | 6 | |
| calltrace:irq_exit | 2 | |
| IP-Config:Auto-configuration_of_network_failed | 8 | 4 |
| RIP:native_safe_halt | 2 | |
| inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage | 0 | 10 |
+------------------------------------------------------------------+-----------+------------+
[ 21.664248] WARNING: inconsistent lock state
[ 21.664989] 4.17.0-rc2-00001-gcad8e99 #1 Not tainted
[ 21.665824] --------------------------------
[ 21.666510] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[ 21.667591] cpuhp/0/14 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 21.668441] (ptrval) (&p->pi_lock){?.-.}, at: smpboot_thread_fn+0x183/0x42c
[ 21.669715] {IN-HARDIRQ-W} state was registered at:
[ 21.670739] lock_acquire+0x99/0xc9
[ 21.671341] _raw_spin_lock_irqsave+0x45/0x59
[ 21.672062] try_to_wake_up+0x8f/0x528
[ 21.672733] wake_up_process+0x10/0x12
[ 21.673434] hrtimer_wakeup+0x27/0x2c
[ 21.674068] __hrtimer_run_queues+0x163/0x1d4
[ 21.674785] hrtimer_run_queues+0x175/0x1b4
[ 21.675518] run_local_timers+0x30/0x7f
[ 21.676206] update_process_times+0x22/0x4f
[ 21.686136] tick_periodic+0xc4/0xca
[ 21.689746] tick_handle_periodic+0x29/0x7b
[ 21.690518] smp_apic_timer_interrupt+0x9d/0xb1
[ 21.691318] apic_timer_interrupt+0xf/0x20
[ 21.692022] native_safe_halt+0x6/0x8
[ 21.692635] default_idle+0x13/0x1c
[ 21.693253] arch_cpu_idle+0xa/0xc
[ 21.697213] default_idle_call+0x35/0x38
[ 21.697891] do_idle+0x181/0x2bf
[ 21.698467] cpu_startup_entry+0x1a/0x1c
[ 21.699156] rest_init+0x22c/0x232
[ 21.699752] start_kernel+0x4fc/0x520
[ 21.700309] x86_64_start_reservations+0x24/0x26
[ 21.701909] x86_64_start_kernel+0x6f/0x72
[ 21.702553] secondary_startup_64+0xa5/0xb0
[ 21.703294] irq event stamp: 1401
[ 21.703834] hardirqs last enabled at (1401): [<ffffffffbd3ef4f3>] _raw_spin_unlock_irq+0x27/0x4b
[ 21.705223] hardirqs last disabled at (1400): [<ffffffffbd3e69e3>] __schedule+0x23b/0xccc
[ 21.706490] softirqs last enabled at (1206): [<ffffffffbd60028d>] __do_softirq+0x28d/0x2db
[ 21.707466] softirqs last disabled at (1181): [<ffffffffbcab67cf>] irq_exit+0x67/0x100
[ 21.708244]
[ 21.708244] other info that might help us debug this:
[ 21.709009] Possible unsafe locking scenario:
[ 21.709009]
[ 21.709919] CPU0
[ 21.710300] ----
[ 21.710696] lock(&p->pi_lock);
[ 21.711199] <Interrupt>
[ 21.711614] lock(&p->pi_lock);
[ 21.712146]
[ 21.712146] *** DEADLOCK ***
[ 21.712146]
[ 21.713108] no locks held by cpuhp/0/14.
[ 21.713773]
[ 21.713773] stack backtrace:
[ 21.714502] CPU: 0 PID: 14 Comm: cpuhp/0 Not tainted 4.17.0-rc2-00001-gcad8e99 #1
[ 21.715747] Call Trace:
[ 21.716174] dump_stack+0x9c/0xe9
[ 21.716756] print_usage_bug+0x321/0x330
[ 21.717533] mark_lock+0x4f5/0x779
[ 21.718122] ? finish_task_switch+0x274/0x325
[ 21.718653] ? print_shortest_lock_dependencies+0x1c6/0x1c6
[ 21.719230] __lock_acquire+0x4a0/0x888
[ 21.719606] lock_acquire+0x99/0xc9
[ 21.719992] ? smpboot_thread_fn+0x183/0x42c
[ 21.720457] _raw_spin_lock+0x2d/0x3c
[ 21.720885] ? smpboot_thread_fn+0x183/0x42c
[ 21.721285] smpboot_thread_fn+0x183/0x42c
[ 21.721703] ? sort_range+0x1d/0x1d
[ 21.722105] ? preempt_count_sub+0x13/0xb5
[ 21.722542] ? schedule+0xdd/0xe9
[ 21.722934] kthread+0x1db/0x1eb
[ 21.723245] ? sort_range+0x1d/0x1d
[ 21.723620] ? kthread_create_on_node+0xa1/0xa1
[ 21.724137] ret_from_fork+0x24/0x30
[ 21.730948] numa_remove_cpu cpu 0 node 0: mask now 1
[ 21.733638] CPU 0 is now offline
[ 21.735209] debug: unmapping init [mem 0xffffffffbe187000-0xffffffffbe2affff]
[ 21.736225] Write protecting the kernel read-only data: 20480k
[ 21.739451] debug: unmapping init [mem 0xffff88000ec07000-0xffff88000edfffff]
[ 21.741223] debug: unmapping init [mem 0xffff88000f2dc000-0xffff88000f3fffff]
[ 21.798549] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[ 21.815648] random: init: uninitialized urandom read (12 bytes read)
[ 21.876844] hwclock (101) used greatest stack depth: 27928 bytes left
[ 21.886110] plymouthd (99) used greatest stack depth: 27656 bytes left
[ 21.906815] sh (104) used greatest stack depth: 27640 bytes left
[ 21.953005] mountall (108) used greatest stack depth: 26776 bytes left
[ 21.976917] random: trinity: uninitialized urandom read (4 bytes read)
mountall: Event failed
[ 22.102893] random: mountall: uninitialized urandom read (12 bytes read)
[ 22.154174] init: Failed to create pty - disabling logging for job
[ 22.155285] init: Temporary process spawn error: No such file or directory
[ 22.191738] init: Failed to create pty - disabling logging for job
[ 22.193058] init: Temporary process spawn error: No such file or directory
[ 22.301682] init: Failed to create pty - disabling logging for job
[ 22.302812] init: Temporary process spawn error: No such file or directory
[ 22.307684] init: Failed to create pty - disabling logging for job
[ 22.308793] init: Temporary process spawn error: No such file or directory
[ 22.427189] init: Failed to create pty - disabling logging for job
[ 22.428994] init: Temporary process spawn error: No such file or directory
[ 22.439238] init: Failed to create pty - disabling logging for job
[ 22.440420] init: Temporary process spawn error: No such file or directory
[ 22.451555] init: Failed to create pty - disabling logging for job
[ 22.452662] init: Temporary process spawn error: No such file or directory
[ 22.477652] init: Failed to create pty - disabling logging for job
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-rc2-00001-gcad8e99" of type "text/plain" (94148 bytes)
View attachment "job-script" of type "text/plain" (4073 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (16768 bytes)
Powered by blists - more mailing lists