Re: [lkp] [sched/fair] 482eaa50ff: INFO: suspicious RCU usage. ]

From: Kirill Tkhai
Date: Tue Sep 29 2015 - 04:53:32 EST

Next message: Lee Jones: "[PATCH] ARM: STi: DT: STiH407: Rename incorrect interrupt related binding"
Previous message: tip-bot for Adrian Hunter: "[tip:perf/core] perf auxtrace: Fix 'instructions' period of zero"
In reply to: kernel test robot: "[lkp] [sched/fair] 482eaa50ff: INFO: suspicious RCU usage. ]"
Next in thread: Fengguang Wu: "[sched/fair] swapper/0/1 is trying to release lock (rcu_read_lockrcu_read_lock) at:"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On 29.09.2015 10:44, kernel test robot wrote:
> FYI, we noticed the below changes on
>
> git://internal_merge_and_test_tree revert-482eaa50ff81046e1e9f95af94176953d0743ec9-482eaa50ff81046e1e9f95af94176953d0743ec9
> commit 482eaa50ff81046e1e9f95af94176953d0743ec9 ("sched/fair: Skip wake_affine() for core siblings")

Yeah, thanks.

> +-------------------------------------------------------+----------+------------+
> | | v4.3-rc3 | 482eaa50ff |
> +-------------------------------------------------------+----------+------------+
> | boot_successes | 54 | 0 |
> | boot_failures | 10 | 13 |
> | IP-Config:Auto-configuration_of_network_failed | 10 | |
> | INFO:suspicious_RCU_usage | 0 | 13 |
> | BUG:scheduling_while_atomic | 0 | 13 |
> | INFO:lockdep_is_turned_off | 0 | 13 |
> | kernel_BUG_at_kernel/sched/core.c | 0 | 13 |
> | invalid_opcode:#[##]SMP_DEBUG_PAGEALLOC | 0 | 13 |
> | EIP_is_at__sched_setscheduler | 0 | 13 |
> | Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 13 |
> | backtrace:spawn_ksoftirqd | 0 | 13 |
> | backtrace:kernel_init_freeable | 0 | 13 |
> | backtrace:schedule | 0 | 13 |
> +-------------------------------------------------------+----------+------------+
>
>
> [ 0.074005] Failed to access perfctr msr (MSR c2 is 0)
> [ 0.075108]
> [ 0.075427] ===============================
> [ 0.076000] [ INFO: suspicious RCU usage. ]
> [ 0.076000] 4.3.0-rc3-00001-g482eaa5 #282 Not tainted
> [ 0.076000] -------------------------------
> [ 0.076000] kernel/sched/fair.c:4796 suspicious rcu_dereference_check() usage!
> [ 0.076000]
> [ 0.076000] other info that might help us debug this:
> [ 0.076000]
> [ 0.076000]
> [ 0.076000] rcu_scheduler_active = 1, debug_locks = 0
> [ 0.076000] 3 locks held by swapper/0/1:
> [ 0.076000] #0: (cpu_hotplug.lock){.+.+.+}, at: [<c104408a>] get_online_cpus+0x27/0x62
> [ 0.076000] #1: (smpboot_threads_lock){+.+.+.}, at: [<c105ae50>] smpboot_register_percpu_thread_cpumask+0x24/0xa1
> [ 0.076000] #2: (&p->pi_lock){......}, at: [<c105e0e8>] try_to_wake_up+0x1d/0x19c
> [ 0.076000]
> [ 0.076000] stack backtrace:
> [ 0.076000] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-rc3-00001-g482eaa5 #282
> [ 0.076000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 0.076000] 00000000 00000000 d3081da8 c1219245 00000001 d3081dc4 c1070a55 c1aeb4d8
> [ 0.076000] d3078000 00000000 00000000 00000000 d3081e1c c106444c 00000001 00000010
> [ 0.076000] 480d0069 00000000 d307f198 00000046 00000046 d3081e18 c107064c 00000002
> [ 0.076000] Call Trace:
> [ 0.076000] [<c1219245>] dump_stack+0x48/0x60
> [ 0.076000] [<c1070a55>] lockdep_rcu_suspicious+0xd4/0xdd
> [ 0.076000] [<c106444c>] select_task_rq_fair+0x2d8/0x64d
> [ 0.076000] [<c107064c>] ? lock_acquire+0x72/0x7d
> [ 0.076000] [<c106d2e8>] ? __lock_is_held+0x2e/0x44
> [ 0.076000] [<c105d71f>] select_task_rq+0x3c/0x8f
> [ 0.076000] [<c105e19f>] try_to_wake_up+0xd4/0x19c
> [ 0.076000] [<c105e290>] wake_up_process+0x29/0x2c
> [ 0.076000] [<c105848c>] kthread_create_on_node+0x95/0x104
> [ 0.076000] [<c10585a6>] kthread_create_on_cpu+0x14/0x44
> [ 0.076000] [<c105a9f3>] ? cpumask_next+0x26/0x26
> [ 0.076000] [<c105acbb>] __smpboot_create_thread+0x4e/0xb0
> [ 0.076000] [<c105ae70>] smpboot_register_percpu_thread_cpumask+0x44/0xa1
> [ 0.076000] [<c1d4cc3b>] ? cpu_hotplug_pm_sync_init+0x11/0x11
> [ 0.076000] [<c1d4cc58>] spawn_ksoftirqd+0x1d/0x27
> [ 0.076000] [<c1d39bcc>] do_one_initcall+0xd0/0x14e
> [ 0.076000] [<c1076213>] ? vprintk_default+0x12/0x14
> [ 0.076000] [<c10a6426>] ? printk+0x12/0x14
> [ 0.076000] [<c100dbba>] ? print_cpu_info+0x8e/0xab
> [ 0.076000] [<c100dbd0>] ? print_cpu_info+0xa4/0xab
> [ 0.076000] [<c1d47377>] ? native_smp_prepare_cpus+0x223/0x25e
> [ 0.076000] [<c1d39ca7>] kernel_init_freeable+0x5d/0x172
> [ 0.076000] [<c17aaaf8>] kernel_init+0x8/0xb5
> [ 0.076000] [<c17b29c1>] ret_from_kernel_thread+0x21/0x30
> [ 0.076000] [<c17aaaf0>] ? rest_init+0x116/0x116
> [ 0.076008] BUG: scheduling while atomic: swapper/0/1/0x00000000
> [ 0.077003] INFO: lockdep is turned off.
> [ 0.078006] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-rc3-00001-g482eaa5 #282
> [ 0.079004] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 0.080004] 00000000 00000000 d3081db0 c1219245 d3078000 d3081dbc c105c084 00000000
> [ 0.082003] d3081de0 c17aedc2 00000000 d307f188 d3081e84 d3078000 d3082000 d3081e70
> [ 0.083805] d3078000 d3081dec c17af235 7fffffff d3081e24 c17b1d4c 00000000 00000000
> [ 0.085648] Call Trace:
> [ 0.086008] [<c1219245>] dump_stack+0x48/0x60
> [ 0.087008] [<c105c084>] __schedule_bug+0x52/0x63
> [ 0.088007] [<c17aedc2>] __schedule+0x5a/0x436
> [ 0.089006] [<c17af235>] schedule+0x64/0x78
> [ 0.090007] [<c17b1d4c>] schedule_timeout+0x15/0xb1
> [ 0.091006] [<c17af938>] ? __wait_for_common+0xd4/0x105
> [ 0.092007] [<c106ea1e>] ? trace_hardirqs_on+0xb/0xd
> [ 0.093006] [<c17b2357>] ? _raw_spin_unlock_irq+0x27/0x31
> [ 0.094006] [<c17af93f>] __wait_for_common+0xdb/0x105
> [ 0.095007] [<c17b1d37>] ? console_conditional_schedule+0x24/0x24
> [ 0.096007] [<c105e974>] ? get_parent_ip+0x31/0x31
> [ 0.097007] [<c17afa10>] wait_for_completion_killable+0x17/0x2c
> [ 0.098007] [<c1058493>] kthread_create_on_node+0x9c/0x104
> [ 0.099006] [<c10585a6>] kthread_create_on_cpu+0x14/0x44
> [ 0.100005] [<c105a9f3>] ? cpumask_next+0x26/0x26
> [ 0.101005] [<c105acbb>] __smpboot_create_thread+0x4e/0xb0
> [ 0.102005] [<c105ae70>] smpboot_register_percpu_thread_cpumask+0x44/0xa1
> [ 0.103007] [<c1d4cc3b>] ? cpu_hotplug_pm_sync_init+0x11/0x11
> [ 0.104005] [<c1d4cc58>] spawn_ksoftirqd+0x1d/0x27
> [ 0.105006] [<c1d39bcc>] do_one_initcall+0xd0/0x14e
> [ 0.106006] [<c1076213>] ? vprintk_default+0x12/0x14
> [ 0.107010] [<c10a6426>] ? printk+0x12/0x14
> [ 0.107916] [<c100dbba>] ? print_cpu_info+0x8e/0xab
> [ 0.108006] [<c100dbd0>] ? print_cpu_info+0xa4/0xab
> [ 0.109007] [<c1d47377>] ? native_smp_prepare_cpus+0x223/0x25e
> [ 0.110006] [<c1d39ca7>] kernel_init_freeable+0x5d/0x172
> [ 0.111008] [<c17aaaf8>] kernel_init+0x8/0xb5
> [ 0.112007] [<c17b29c1>] ret_from_kernel_thread+0x21/0x30
> [ 0.113006] [<c17aaaf0>] ? rest_init+0x116/0x116
> [ 0.114092] BUG: scheduling while atomic: kthreadd/3/0x00000000
> [ 0.115003] INFO: lockdep is turned off.
> [ 0.116006] CPU: 0 PID: 3 Comm: kthreadd Tainted: G W 4.3.0-rc3-00001-g482eaa5 #282
> [ 0.117005] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 0.118005] 00000000 00000000 d3093ef4 c1219245 d3078dc0 d3093f00 c105c084 00000000
> [ 0.120293] d3093f24 c17aedc2 00000282 d3093f1c c17b2325 d3078dc0 d3094000 d3058c00
> [ 0.122072] c105a9f3 d3093f30 c17af235 d3059dd0 d3093fac c105830a d3093f74 00000000
> [ 0.124069] Call Trace:
> [ 0.124610] [<c1219245>] dump_stack+0x48/0x60
> [ 0.125007] [<c105c084>] __schedule_bug+0x52/0x63
> [ 0.126008] [<c17aedc2>] __schedule+0x5a/0x436
> [ 0.127007] [<c17b2325>] ? _raw_spin_unlock_irqrestore+0x3f/0x4a
> [ 0.128006] [<c105a9f3>] ? cpumask_next+0x26/0x26
> [ 0.129006] [<c17af235>] schedule+0x64/0x78
> [ 0.130006] [<c105830a>] kthread+0x87/0xa5
> [ 0.131007] [<c107064c>] ? lock_acquire+0x72/0x7d
> [ 0.132007] [<c17b29c1>] ret_from_kernel_thread+0x21/0x30
> [ 0.133007] [<c1058283>] ? __kthread_parkme+0x83/0x83
> [ 0.134020] ------------[ cut here ]------------
> [ 0.135000] kernel BUG at kernel/sched/core.c:3740!
> [ 0.135000] invalid opcode: 0000 [#1] SMP DEBUG_PAGEALLOC
> [ 0.135000] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G W 4.3.0-rc3-00001-g482eaa5 #282
> [ 0.135000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 0.135000] task: d3078000 ti: d3080000 task.ti: d3080000
> [ 0.135000] EIP: 0060:[<c105ec63>] EFLAGS: 00010206 CPU: 0
> [ 0.135000] EIP is at __sched_setscheduler+0x39/0x6b8
> [ 0.135000] EAX: 7fffffff EBX: 00000000 ECX: 00000000 EDX: 00000063
> [ 0.135000] ESI: d3078dc0 EDI: d3081e18 EBP: d3081e0c ESP: d3081dc4
> [ 0.135000] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> [ 0.135000] CR0: 8005003b CR2: ffffffff CR3: 01dd3000 CR4: 000006b0
> [ 0.135000] Stack:
> [ 0.135000] 00000000 00000000 d3081e84 00000086 d3081ddc 00000063 d3081e18 c1070700
> [ 0.135000] 00000001 00000001 00010000 d30790ac 00000030 00000000 00000086 d3078dc0
> [ 0.135000] c17bcf28 d3081e48 d3081e54 c105f344 00000000 00000000 00000000 00000000
> [ 0.135000] Call Trace:
> [ 0.135000] [<c1070700>] ? lock_release+0xa9/0x29a
> [ 0.135000] [<c105f344>] _sched_setscheduler+0x62/0x6a
> [ 0.135000] [<c105f533>] sched_setscheduler_nocheck+0xa/0xc
> [ 0.135000] [<c10584dd>] kthread_create_on_node+0xe6/0x104
> [ 0.135000] [<c10585a6>] kthread_create_on_cpu+0x14/0x44
> [ 0.135000] [<c105a9f3>] ? cpumask_next+0x26/0x26
> [ 0.135000] [<c105acbb>] __smpboot_create_thread+0x4e/0xb0
> [ 0.135000] [<c105ae70>] smpboot_register_percpu_thread_cpumask+0x44/0xa1
> [ 0.135000] [<c1d4cc3b>] ? cpu_hotplug_pm_sync_init+0x11/0x11
> [ 0.135000] [<c1d4cc58>] spawn_ksoftirqd+0x1d/0x27
> [ 0.135000] [<c1d39bcc>] do_one_initcall+0xd0/0x14e
> [ 0.135000] [<c1076213>] ? vprintk_default+0x12/0x14
> [ 0.135000] [<c10a6426>] ? printk+0x12/0x14
> [ 0.135000] [<c100dbba>] ? print_cpu_info+0x8e/0xab
> [ 0.135000] [<c100dbd0>] ? print_cpu_info+0xa4/0xab
> [ 0.135000] [<c1d47377>] ? native_smp_prepare_cpus+0x223/0x25e
> [ 0.135000] [<c1d39ca7>] kernel_init_freeable+0x5d/0x172
> [ 0.135000] [<c17aaaf8>] kernel_init+0x8/0xb5
> [ 0.135000] [<c17b29c1>] ret_from_kernel_thread+0x21/0x30
> [ 0.135000] [<c17aaaf0>] ? rest_init+0x116/0x116
> [ 0.135000] Code: 42 04 88 4d d4 c7 45 cc ff ff ff ff 83 f8 06 74 0b ba 63 00 00 00 2b 57 14 89 55 cc 89 c3 64 a1 04 28 dc c1 a9 00 ff 1f 00 74 3d <0f> 0b 8b 8e 3c 01 00 00 39 cb 0f 84 27 02 00 00 80 7d d4 00 0f
> [ 0.135000] EIP: [<c105ec63>] __sched_setscheduler+0x39/0x6b8 SS:ESP 0068:d3081dc4
> [ 0.135012] ---[ end trace d248a7baa3fff262 ]---
> [ 0.136006] Kernel panic - not syncing: Fatal exception in interrupt
>
>
>
>
>
> Thanks,
> Ying Huang
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Next message: Lee Jones: "[PATCH] ARM: STi: DT: STiH407: Rename incorrect interrupt related binding"
Previous message: tip-bot for Adrian Hunter: "[tip:perf/core] perf auxtrace: Fix 'instructions' period of zero"
In reply to: kernel test robot: "[lkp] [sched/fair] 482eaa50ff: INFO: suspicious RCU usage. ]"
Next in thread: Fengguang Wu: "[sched/fair] swapper/0/1 is trying to release lock (rcu_read_lockrcu_read_lock) at:"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]