Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756378AbcCQNCe (ORCPT ); Thu, 17 Mar 2016 09:02:34 -0400 Received: from mail-oi0-f44.google.com ([209.85.218.44]:36613 "EHLO mail-oi0-f44.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S936079AbcCQNCa convert rfc822-to-8bit (ORCPT ); Thu, 17 Mar 2016 09:02:30 -0400 MIME-Version: 1.0 Date: Thu, 17 Mar 2016 09:02:29 -0400 X-Google-Sender-Auth: rfBH_honeL7_Casyk3q8va3exmY Message-ID: Subject: intel_pstate oopses and lockdep report with Linux v4.5-1822-g63e30271b04c From: Josh Boyer To: Srinivas Pandruvada , Len Brown Cc: "Rafael J. Wysocki" , Viresh Kumar , Linux PM list , "Linux-Kernel@Vger. Kernel. Org" Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8BIT Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 14283 Lines: 232 Hello, I have an Intel Atom based NUC that is producing the following backtraces on boot of Linus' tree as of last evening. This does not happen with a tree with top level commit 271ecc5253e2, but does happen when using the tree mentioned in the subject with top level commit 63e30271b04c. The first backtrace appears to be a warning because the intel_pstate driver is calling wrmsrl_on_cpu when interrupts are disabled? Not sure on that one. The second backtrace is a lockdep report. Both are from the same boot. josh [ 2.063588] Intel P-state driver initializing. [ 2.064225] ------------[ cut here ]------------ [ 2.064236] WARNING: CPU: 0 PID: 1 at kernel/smp.c:291 smp_call_function_single+0x116/0x130() [ 2.064240] Modules linked in: [ 2.064247] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.6.0-0.rc0.git6.1.fc25.x86_64 #1 [ 2.064250] Hardware name: \xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff \xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff/DN2820FYK, BIOS FYBYT10H.86A.0034.2014.0513.1413 05/13/2014 [ 2.064254] 0000000000000086 000000008f3c08c6 ffff880237203bf0 ffffffff8144ed43 [ 2.064262] 0000000000000000 ffffffff81c3eba4 ffff880237203c28 ffffffff810b1482 [ 2.064269] 0000000000000000 ffffffff814881b0 ffff880232bdfa80 0000000000000093 [ 2.064276] Call Trace: [ 2.064279] [] dump_stack+0x85/0xc2 [ 2.064291] [] warn_slowpath_common+0x82/0xc0 [ 2.064297] [] ? __rdmsr_on_cpu+0x70/0x70 [ 2.064302] [] warn_slowpath_null+0x1a/0x20 [ 2.064307] [] smp_call_function_single+0x116/0x130 [ 2.064313] [] wrmsrl_on_cpu+0x50/0x70 [ 2.064319] [] atom_set_pstate+0x74/0x90 [ 2.064324] [] intel_pstate_set_pstate+0x13c/0x220 [ 2.064330] [] intel_pstate_update_util+0x155/0x340 [ 2.064335] [] ? cpuacct_charge+0xd1/0x1a0 [ 2.064340] [] ? cpuacct_charge+0x5/0x1a0 [ 2.064346] [] task_tick_fair+0x613/0xa60 [ 2.064352] [] scheduler_tick+0x5b/0xe0 [ 2.064357] [] ? tick_sched_do_timer+0x60/0x60 [ 2.064362] [] update_process_times+0x51/0x60 [ 2.064367] [] tick_sched_handle.isra.20+0x25/0x60 [ 2.064372] [] tick_sched_timer+0x3d/0x70 [ 2.064377] [] __hrtimer_run_queues+0x110/0x540 [ 2.064382] [] hrtimer_interrupt+0xb7/0x1d0 [ 2.064388] [] local_apic_timer_interrupt+0x38/0x60 [ 2.064394] [] smp_apic_timer_interrupt+0x3d/0x50 [ 2.064399] [] apic_timer_interrupt+0x96/0xa0 [ 2.064402] [] ? _raw_spin_unlock_irqrestore+0x3b/0x60 [ 2.064411] [] ida_simple_get+0x98/0x100 [ 2.064417] [] __kernfs_new_node+0x5f/0xc0 [ 2.064423] [] kernfs_new_node+0x29/0x50 [ 2.064427] [] __kernfs_create_file+0x32/0xd0 [ 2.064432] [] sysfs_add_file_mode_ns+0x90/0x1b0 [ 2.064437] [] sysfs_create_file_ns+0x2a/0x30 [ 2.064442] [] cpufreq_online+0x30b/0x860 [ 2.064447] [] cpufreq_add_dev+0x62/0x90 [ 2.064453] [] subsys_interface_register+0xbc/0x110 [ 2.064459] [] cpufreq_register_driver+0x14c/0x210 [ 2.064464] [] intel_pstate_init+0x3b5/0x504 [ 2.064469] [] ? intel_pstate_setup+0x9a/0x9a [ 2.064474] [] do_one_initcall+0xb3/0x200 [ 2.064479] [] ? parse_args+0x297/0x4b0 [ 2.064486] [] kernel_init_freeable+0x1f3/0x28d [ 2.064492] [] kernel_init+0xe/0x100 [ 2.064497] [] ret_from_fork+0x22/0x50 [ 2.064501] [] ? rest_init+0x140/0x140 [ 2.064661] ---[ end trace 83cfc0c0effa9465 ]--- [ 21.748603] ====================================================== [ 21.748606] [ INFO: possible circular locking dependency detected ] [ 21.748611] 4.6.0-0.rc0.git6.1.fc25.x86_64 #1 Tainted: G W [ 21.748614] ------------------------------------------------------- [ 21.748617] abrt-handle-eve/849 is trying to acquire lock: [ 21.748620] (&p->pi_lock){-.-.-.}, at: [] try_to_wake_up+0x31/0x510 [ 21.748635] but task is already holding lock: [ 21.748638] (random_write_wait.lock){-.....}, at: [] __wake_up+0x23/0x50 [ 21.748647] which lock already depends on the new lock. [ 21.748651] the existing dependency chain (in reverse order) is: [ 21.748655] -> #2 (random_write_wait.lock){-.....}: [ 21.748662] [] lock_acquire+0xfe/0x1f0 [ 21.748667] [] _raw_spin_lock_irqsave+0x56/0x90 [ 21.748674] [] __wake_up+0x23/0x50 [ 21.748679] [] account.part.28+0x1d2/0x250 [ 21.748685] [] extract_entropy+0x9d/0x530 [ 21.748689] [] get_random_bytes+0x51/0x150 [ 21.748694] [] print_oops_end_marker+0x3f/0x60 [ 21.748700] [] warn_slowpath_common+0x87/0xc0 [ 21.748705] [] warn_slowpath_null+0x1a/0x20 [ 21.748710] [] smp_call_function_single+0x116/0x130 [ 21.748716] [] wrmsrl_on_cpu+0x50/0x70 [ 21.748723] [] atom_set_pstate+0x74/0x90 [ 21.748729] [] intel_pstate_set_pstate+0x13c/0x220 [ 21.748734] [] intel_pstate_update_util+0x155/0x340 [ 21.748739] [] task_tick_fair+0x613/0xa60 [ 21.748745] [] scheduler_tick+0x5b/0xe0 [ 21.748749] [] update_process_times+0x51/0x60 [ 21.748755] [] tick_sched_handle.isra.20+0x25/0x60 [ 21.748760] [] tick_sched_timer+0x3d/0x70 [ 21.748765] [] __hrtimer_run_queues+0x110/0x540 [ 21.748769] [] hrtimer_interrupt+0xb7/0x1d0 [ 21.748773] [] local_apic_timer_interrupt+0x38/0x60 [ 21.748779] [] smp_apic_timer_interrupt+0x3d/0x50 [ 21.748784] [] apic_timer_interrupt+0x96/0xa0 [ 21.748788] [] ida_simple_get+0x98/0x100 [ 21.748794] [] __kernfs_new_node+0x5f/0xc0 [ 21.748800] [] kernfs_new_node+0x29/0x50 [ 21.748805] [] __kernfs_create_file+0x32/0xd0 [ 21.748809] [] sysfs_add_file_mode_ns+0x90/0x1b0 [ 21.748814] [] sysfs_create_file_ns+0x2a/0x30 [ 21.748819] [] cpufreq_online+0x30b/0x860 [ 21.748824] [] cpufreq_add_dev+0x62/0x90 [ 21.748828] [] subsys_interface_register+0xbc/0x110 [ 21.748835] [] cpufreq_register_driver+0x14c/0x210 [ 21.748840] [] intel_pstate_init+0x3b5/0x504 [ 21.748846] [] do_one_initcall+0xb3/0x200 [ 21.748851] [] kernel_init_freeable+0x1f3/0x28d [ 21.748858] [] kernel_init+0xe/0x100 [ 21.748863] [] ret_from_fork+0x22/0x50 [ 21.748868] -> #1 (&rq->lock){-.-.-.}: [ 21.748874] [] lock_acquire+0xfe/0x1f0 [ 21.748880] [] _raw_spin_lock+0x3d/0x80 [ 21.748884] [] sched_move_task+0x4d/0x280 [ 21.748888] [] cpu_cgroup_fork+0xe/0x10 [ 21.748893] [] cgroup_post_fork+0x43/0x130 [ 21.748899] [] copy_process.part.25+0x15ad/0x1b30 [ 21.748904] [] _do_fork+0xee/0x700 [ 21.748908] [] kernel_thread+0x29/0x30 [ 21.748913] [] rest_init+0x22/0x140 [ 21.748917] [] start_kernel+0x49a/0x4bb [ 21.748922] [] x86_64_start_reservations+0x2a/0x2c [ 21.748927] [] x86_64_start_kernel+0x14a/0x16d [ 21.748931] -> #0 (&p->pi_lock){-.-.-.}: [ 21.748937] [] __lock_acquire+0x1a34/0x1c60 [ 21.748942] [] lock_acquire+0xfe/0x1f0 [ 21.748946] [] _raw_spin_lock_irqsave+0x56/0x90 [ 21.748951] [] try_to_wake_up+0x31/0x510 [ 21.748955] [] default_wake_function+0x12/0x20 [ 21.748960] [] pollwake+0x73/0x90 [ 21.748966] [] __wake_up_common+0x52/0x90 [ 21.748970] [] __wake_up+0x39/0x50 [ 21.748974] [] account.part.28+0x1d2/0x250 [ 21.748978] [] extract_entropy+0x9d/0x530 [ 21.748983] [] get_random_bytes+0x51/0x150 [ 21.748987] [] load_elf_binary+0xc2a/0x1750 [ 21.748992] [] search_binary_handler+0x97/0x1c0 [ 21.748997] [] do_execveat_common.isra.36+0x6a2/0x9a0 [ 21.749001] [] SyS_execve+0x3a/0x50 [ 21.749005] [] do_syscall_64+0x67/0x190 [ 21.749010] [] return_from_SYSCALL_64+0x0/0x7a [ 21.749015] other info that might help us debug this: [ 21.749019] Chain exists of: &p->pi_lock --> &rq->lock --> random_write_wait.lock [ 21.749026] Possible unsafe locking scenario: [ 21.749030] CPU0 CPU1 [ 21.749032] ---- ---- [ 21.749034] lock(random_write_wait.lock); [ 21.749038] lock(&rq->lock); [ 21.749042] lock(random_write_wait.lock); [ 21.749046] lock(&p->pi_lock); [ 21.749050] *** DEADLOCK *** [ 21.749054] 1 lock held by abrt-handle-eve/849: [ 21.749056] #0: (random_write_wait.lock){-.....}, at: [] __wake_up+0x23/0x50 [ 21.749065] stack backtrace: [ 21.749070] CPU: 0 PID: 849 Comm: abrt-handle-eve Tainted: G W 4.6.0-0.rc0.git6.1.fc25.x86_64 #1 [ 21.749073] Hardware name: \xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff \xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff\xffffffff/DN2820FYK, BIOS FYBYT10H.86A.0034.2014.0513.1413 05/13/2014 [ 21.749077] 0000000000000086 0000000077cdecb8 ffff880221b13960 ffffffff8144ed43 [ 21.749084] ffffffff82af6c50 ffffffff82aebfe0 ffff880221b139a0 ffffffff8110e863 [ 21.749090] ffff880221b13a20 0000000000000001 ffff880221b6b0c0 ffff880221b6bd68 [ 21.749097] Call Trace: [ 21.749102] [] dump_stack+0x85/0xc2 [ 21.749107] [] print_circular_bug+0x1e3/0x250 [ 21.749112] [] __lock_acquire+0x1a34/0x1c60 [ 21.749117] [] ? debug_lockdep_rcu_enabled+0x1d/0x20 [ 21.749122] [] ? __lock_acquire+0xac7/0x1c60 [ 21.749126] [] ? __lock_acquire+0x54c/0x1c60 [ 21.749131] [] lock_acquire+0xfe/0x1f0 [ 21.749136] [] ? try_to_wake_up+0x31/0x510 [ 21.749140] [] _raw_spin_lock_irqsave+0x56/0x90 [ 21.749145] [] ? try_to_wake_up+0x31/0x510 [ 21.749149] [] try_to_wake_up+0x31/0x510 [ 21.749153] [] default_wake_function+0x12/0x20 [ 21.749158] [] pollwake+0x73/0x90 [ 21.749162] [] ? wake_up_q+0x70/0x70 [ 21.749166] [] __wake_up_common+0x52/0x90 [ 21.749170] [] __wake_up+0x39/0x50 [ 21.749174] [] account.part.28+0x1d2/0x250 [ 21.749179] [] extract_entropy+0x9d/0x530 [ 21.749183] [] ? load_elf_binary+0xc2a/0x1750 [ 21.749187] [] ? load_elf_binary+0xc2a/0x1750 [ 21.749191] [] get_random_bytes+0x51/0x150 [ 21.749195] [] load_elf_binary+0xc2a/0x1750 [ 21.749200] [] search_binary_handler+0x97/0x1c0 [ 21.749205] [] do_execveat_common.isra.36+0x6a2/0x9a0 [ 21.749209] [] ? do_execveat_common.isra.36+0x5f5/0x9a0 [ 21.749213] [] SyS_execve+0x3a/0x50 [ 21.749217] [] do_syscall_64+0x67/0x190 [ 21.749222] [] entry_SYSCALL64_slow_path+0x25/0x25