[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <alpine.DEB.2.11.1502171109390.26492@vincent-weaver-1.umelst.maine.edu>
Date: Tue, 17 Feb 2015 11:17:55 -0500 (EST)
From: Vince Weaver <vincent.weaver@...ne.edu>
To: linux-kernel@...r.kernel.org
cc: Peter Zijlstra <a.p.zijlstra@...llo.nl>,
Paul Mackerras <paulus@...ba.org>,
Ingo Molnar <mingo@...hat.com>,
Arnaldo Carvalho de Melo <acme@...nel.org>,
Jiri Olsa <jolsa@...hat.com>
Subject: perf: fuzzer causes lockup in x86_pmu_event_init()
This is on a Haswell machine, current git as of this past Friday.
I let the perf_fuzzer run and it took 4 days to find this.
Sadly it doesn't seem to be reproducible so I am not sure
how it exactly got into this state.
It got stuck and kept printing the following message until I rebooted
the system.
[328363.704011] INFO: rcu_sched self-detected stall on CPU { 2} (t=5251 jiffies g=28607531 c=28607530 q=232)
[328363.715076] Task dump for CPU 2:
[328363.719278] perf_fuzzer R running task 0 20935 2309 0x00000008
[328363.727653] 0000000000000905 ffff88011ea83d68 ffffffff8109a126 ffffffff8109a095
[328363.736466] 0000000000000007 0000000000000002 ffffffff81c50780 ffff88011ea83d88
[328363.745256] ffffffff8109d9fd ffff88011ea95b00 0000000000000003 ffff88011ea83db8
[328363.754037] Call Trace:
[328363.757382] <IRQ> [<ffffffff8109a126>] sched_show_task+0xf6/0x160
[328363.764853] [<ffffffff8109a095>] ? sched_show_task+0x65/0x160
[328363.771769] [<ffffffff8109d9fd>] dump_cpu_task+0x3d/0x50
[328363.778205] [<ffffffff810d2301>] rcu_dump_cpu_stacks+0x91/0xd0
[328363.785181] [<ffffffff810d5dab>] rcu_check_callbacks+0x48b/0x760
[328363.792345] [<ffffffff810db429>] update_process_times+0x39/0x60
[328363.799431] [<ffffffff810eb195>] tick_sched_handle.isra.18+0x25/0x60
[328363.806923] [<ffffffff810eb8e4>] tick_sched_timer+0x44/0x80
[328363.813594] [<ffffffff810dc0d4>] __run_hrtimer+0x94/0x1f0
[328363.820090] [<ffffffff810dc623>] ? hrtimer_interrupt+0x83/0x220
[328363.827166] [<ffffffff810eb8a0>] ? tick_sched_do_timer+0x40/0x40
[328363.834322] [<ffffffff810dc69b>] hrtimer_interrupt+0xfb/0x220
[328363.841188] [<ffffffff810495ec>] local_apic_timer_interrupt+0x3c/0x70
[328363.848802] [<ffffffff816caf11>] smp_apic_timer_interrupt+0x41/0x60
[328363.856197] [<ffffffff816c8fbd>] apic_timer_interrupt+0x6d/0x80
[328363.863238] <EOI> [<ffffffff810bad96>] ? __raw_spin_lock_init+0x36/0x60
[328363.871175] [<ffffffff81029cb5>] ? collect_events+0x55/0xb0
[328363.877844] [<ffffffff8102a6be>] x86_pmu_event_init+0xfe/0x3c0
[328363.884817] [<ffffffff811559d3>] perf_try_init_event+0x33/0x70
[328363.891797] [<ffffffff8115eb4f>] perf_init_event+0x13f/0x170
[328363.898586] [<ffffffff8115ea15>] ? perf_init_event+0x5/0x170
[328363.905369] [<ffffffff8115ef18>] perf_event_alloc+0x398/0x450
[328363.912237] [<ffffffff8115f343>] SYSC_perf_event_open+0x373/0xc80
[328363.919502] [<ffffffff8116009e>] SyS_perf_event_open+0xe/0x10
[328363.926387] [<ffffffff816c7ead>] system_call_fastpath+0x16/0x1b
[328363.933452] INFO: rcu_sched detected stalls on CPUs/tasks: { 2} (detected by 0, t=5308 jiffies, g=28607531, c=28607530, q=232)
[328363.946389] Task dump for CPU 2:
[328363.950495] perf_fuzzer R running task 0 20935 2309 0x00000008
[328363.958750] 0000000000000246 ffff88011edf8f18 0000000000000141 ffff8800947d0990
[328363.967451] ffff880036e36000 ffff88011a000640 000001ff00000020 0000000000000000
[328363.976158] ffff88011a000640 ffff880036e36000 0000000080002800 ffffffff81032ead
[328363.984776] Call Trace:
[328363.988059] [<ffffffff81032ead>] ? allocate_shared_regs+0x3d/0x90
[328363.995306] [<ffffffff811c190b>] ? cache_alloc_debugcheck_after.isra.51+0x1fb/0x280
[328364.004275] [<ffffffff810b53bd>] ? lockdep_init_map+0x5d/0x640
[328364.011286] [<ffffffff8102a562>] ? allocate_fake_cpuc+0x32/0x90
[328364.018369] [<ffffffff811c190b>] ? cache_alloc_debugcheck_after.isra.51+0x1fb/0x280
[328364.027342] [<ffffffff810bad96>] ? __raw_spin_lock_init+0x36/0x60
[328364.034626] [<ffffffff81029cb5>] ? collect_events+0x55/0xb0
[328364.041342] [<ffffffff8102a6be>] ? x86_pmu_event_init+0xfe/0x3c0
[328364.048514] [<ffffffff811559d3>] ? perf_try_init_event+0x33/0x70
[328364.055727] [<ffffffff8115eb4f>] ? perf_init_event+0x13f/0x170
[328364.062731] [<ffffffff8115ea15>] ? perf_init_event+0x5/0x170
[328364.069552] [<ffffffff8115ef18>] ? perf_event_alloc+0x398/0x450
[328364.076619] [<ffffffff8115f343>] ? SYSC_perf_event_open+0x373/0xc80
[328364.084124] [<ffffffff8116009e>] ? SyS_perf_event_open+0xe/0x10
[328364.091184] [<ffffffff816c7ead>] ? system_call_fastpath+0x16/0x1b
[328390.679373] NMI watchdog: BUG: soft lockup - CPU#2 stuck for 22s! [perf_fuzzer:20935]
[328390.688418] Modules linked in: fuse x86_pkg_temp_thermal intel_powerclamp intel_rapl iosf_mbi coretemp kvm snd_hda_codec_realtek snd_hda_codec_hdmi snd_hda_codec_generic crct10dif_pclmul crc32_pclmul snd_hda_intel snd_hda_controller ghash_clmulni_intel snd_hda_codec aesni_intel aes_x86_64 snd_hwdep lrw ppdev i915 snd_pcm gf128mul iTCO_wdt evdev iTCO_vendor_support drm_kms_helper glue_helper psmouse drm ablk_helper cryptd snd_timer serio_raw mei_me parport_pc tpm_tis snd lpc_ich tpm soundcore i2c_i801 xhci_pci battery mei i2c_algo_bit parport pcspkr xhci_hcd mfd_core wmi button processor video sg sr_mod cdrom sd_mod ahci e1000e ehci_pci libahci ptp ehci_hcd libata usbcore crc32c_intel scsi_mod usb_common pps_core thermal fan thermal_sys
[328390.762307] CPU: 2 PID: 20935 Comm: perf_fuzzer Tainted: G W 3.19.0+ #127
[328390.771527] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
[328390.780237] task: ffff8800947d0990 ti: ffff8800946c4000 task.ti: ffff8800946c4000
[328390.789004] RIP: 0010:[<ffffffff81029cad>] [<ffffffff81029cad>] collect_events+0x4d/0xb0
[328390.798577] RSP: 0018:ffff8800946c7d38 EFLAGS: 00000202
[328390.805033] RAX: ffff8800ce837000 RBX: ffffffff810bad96 RCX: 0000000000000001
[328390.813454] RDX: ffff8800ce837010 RSI: ffff8801193cb020 RDI: ffff8800958b3000
[328390.821845] RBP: ffff8800946c7d38 R08: 0000000000000007 R09: ffffffff828fb310
[328390.830256] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff81c220c0
[328390.838661] R13: ffff8801193cb000 R14: ffffffff81e7f181 R15: ffffffff81a24c53
[328390.847094] FS: 00007fb692472700(0000) GS:ffff88011ea80000(0000) knlGS:0000000000000000
[328390.856548] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[328390.863438] CR2: 0000000001e1d038 CR3: 0000000094724000 CR4: 00000000001407e0
[328390.871839] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[328390.880251] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
[328390.888646] Stack:
[328390.891588] ffff8800946c7d88 ffffffff8102a6be ffff8800946c7db8 0000000000000292
[328390.900379] ffff8800947d0990 ffffffff81c220c0 ffff8800a0274000 0000000000000000
[328390.909169] 0000000000000000 0000000000000000 ffff8800946c7db8 ffffffff811559d3
[328390.917922] Call Trace:
[328390.921321] [<ffffffff8102a6be>] x86_pmu_event_init+0xfe/0x3c0
[328390.928405] [<ffffffff811559d3>] perf_try_init_event+0x33/0x70
[328390.935479] [<ffffffff8115eb4f>] perf_init_event+0x13f/0x170
[328390.942426] [<ffffffff8115ea15>] ? perf_init_event+0x5/0x170
[328390.949360] [<ffffffff8115ef18>] perf_event_alloc+0x398/0x450
[328390.956398] [<ffffffff8115f343>] SYSC_perf_event_open+0x373/0xc80
[328390.963774] [<ffffffff8116009e>] SyS_perf_event_open+0xe/0x10
[328390.970773] [<ffffffff816c7ead>] system_call_fastpath+0x16/0x1b
[328390.977968] Code: 84 d2 89 c8 74 5a 48 8b 56 20 48 83 c6 20 48 39 d6 48 8d 42 f0 75 14 eb 45 0f 1f 44 00 00 48 8b 50 10 48 39 d6 48 8d 42 f0 74 33 <48> 81 78 70 c0 20 c2 81 75 e9 8b 50 78 85 d2 78 e2 41 39 c8 7e
[328390.679373] NMI watchdog: BUG: soft lockup - CPU#2 stuck for 22s! [perf_fuzzer:20935]
[328418.691171] NMI watchdog: BUG: soft lockup - CPU#2 stuck for 22s! [perf_fuzzer:20935]
...
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists