WARNING: perf_aux_output_begin()

Found by

perf_fuzzer

Severity

Warning

First Seen

4.1-rc7

Most recently Seen

4.2-rc0

Reproducible

yes

Found On

Haswell

Linux-kernel

11 June 2015: perf: aux area related crash and warnings

Introduced by

Fixed in

Possibly by ee9397a6fb9bc4e52677f5e33eed4abee0f515e6 perf: Fix double-free of the AUX buffer We'll have to see if it re-occurs. If so, introduced by 57ffc5ca679f

Details

       if (WARN_ON_ONCE(local_xchg(&rb->aux_nest, 1)))

Kernel Splat

  1. *** perf_fuzzer 0.31-pre *** by Vince Weaver
    
            Linux version 4.1.0+ x86_64
            Processor: Intel 6/60/3
    
            Seeding random number generator with 1435912557
            /proc/sys/kernel/perf_event_max_sample_rate currently: 250/s
            /proc/sys/kernel/perf_event_paranoid currently: 0
            Logging perf_event_open() failures: no
            Running fsync after every syscall: no
            To reproduce, try: ./perf_fuzzer -s 30000 -r 1435912557
    
    Pid=28074, sleeping 1s
    ==================================================
    Fuzzing the following syscalls:
            mmap perf_event_open close read write ioctl fork prctl poll 
    *NOT* Fuzzing the following syscalls:
            
    Also attempting the following:
            signal-handler-on-overflow busy-instruction-loop accessing-perf-proc-and-sys-files trashing-the-mmap-page 
    *NOT* attempting the following:
            
    ==================================================
    Iteration 10000
            Open attempts: 114865  Successful: 917  Currently open: 49
                    EPERM : 18
                    ENOENT : 681
                    E2BIG : 10083
                    EBADF : 9591
                    EBUSY : 3
                    EINVAL : 93247
                    EOPNOTSUPP : 325
                    Type (Hardware 191/16111)(software 341/16759)(tracepoint 76/16367)(Cache 54/14289)(cpu 212/16536)(breakpoint 16/16489)(power 1/2093)(intel_bts 25/2066)(uncore_imc 1/2238)(#9 0/12)(#10 0/8)(#11 0/5)(#12 0/9)(#13 0/2)(#14 0/10)(>14 0/11871)
            Close:  868/868 Successful
            Read:   790/889 Successful
            Write:  0/883 Successful
            Ioctl:  392/901 Successful: (ENABLE 99/99)(DISABLE 97/97)(REFRESH 3/75)(RESET 87/87)(PERIOD 12/101)(SET_OUTPUT 6/81)(SET_FILTER 0/89)(ID 88/88)(SET_BPF 0/82)(#9 0/0)(#10 0/0)(#11 0/0)(#12 0/0)(#13 0/0)(#14 0/0)(>14 0/102)
            Mmap:   473/1078 Successful: (MMAP 473/1078)(TRASH 130/153)(READ 12/138)(UNMAP 469/1031)(AUX 0/264)(AUX_READ 1/9)
            Prctl:  910/910 Successful
            Fork:   475/475 Successful
            Poll:   917/932 Successful
            Access: 425/898 Successful
            Overflows: 0
    [44655.375617] ------------[ cut here ]------------
    [44655.381034] WARNING: CPU: 3 PID: 28074 at kernel/events/ring_buffer.c:294 perf_aux_output_begin+0x1a8/0x1c0()
    [44655.392172] Modules linked in: fuse snd_hda_codec_hdmi i915 x86_pkg_temp_thermal intel_powerclamp intel_rapl iosf_mbi coretemp kvm_intel psmouse kvm snd_hda_codec_realtek snd_hda_codec_generic crct10dif_pclmul iTCO_wdt crc32_pclmul serio_raw pcspkr ghash_clmulni_intel snd_hda_intel snd_hda_codec hmac iTCO_vendor_support evdev ppdev drbg ansi_cprng drm_kms_helper snd_hda_core drm parport_pc aesni_intel aes_x86_64 lrw gf128mul snd_hwdep glue_helper ablk_helper cryptd i2c_algo_bit snd_pcm parport snd_timer snd mei_me wmi processor video battery i2c_i801 button lpc_ich soundcore mfd_core tpm_tis tpm mei sg sr_mod sd_mod cdrom ehci_pci ehci_hcd ahci libahci libata xhci_pci xhci_hcd e1000e ptp crc32c_intel fan scsi_mod usbcore pps_core usb_common thermal thermal_sys
    [44655.469242] CPU: 3 PID: 28074 Comm: perf_fuzzer Tainted: G        W       4.1.0+ #162
    [44655.478088] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
    [44655.486480]  ffffffff81a29b45 ffff88011eac3c58 ffffffff8169e763 0000000000000000
    [44655.494987]  0000000000000000 ffff88011eac3c98 ffffffff8106ecba 000000000000cf40
    [44655.503453]  ffff880036dd5c00 ffff88011eaccf40 ffff8800c2670800 000000000000cf40
    [44655.512032] Call Trace:
    [44655.515103]    [] dump_stack+0x45/0x57
    [44655.521749]  [] warn_slowpath_common+0x8a/0xc0
    [44655.528702]  [] warn_slowpath_null+0x1a/0x20
    [44655.535418]  [] perf_aux_output_begin+0x1a8/0x1c0
    [44655.542548]  [] bts_event_add+0x6d/0x140
    [44655.548917]  [] event_sched_in.isra.85+0xf6/0x2e0
    [44655.556117]  [] group_sched_in+0xae/0x1c0
    [44655.562568]  [] ? native_sched_clock+0x28/0x90
    [44655.569495]  [] ctx_sched_in+0x1d8/0x3e0
    [44655.575889]  [] perf_event_sched_in+0x64/0x90
    [44655.582680]  [] perf_mux_hrtimer_handler+0x114/0x1f0
    [44655.590164]  [] ? perf_event_context_sched_in+0x150/0x150
    [44655.598124]  [] __hrtimer_run_queues+0xd3/0x260
    [44655.605121]  [] hrtimer_interrupt+0xab/0x1b0
    [44655.611886]  [] local_apic_timer_interrupt+0x3c/0x70
    [44655.619364]  [] smp_apic_timer_interrupt+0x41/0x60
    [44655.626618]  [] apic_timer_interrupt+0x6b/0x70
    [44655.633506]   
    [44655.635582] ---[ end trace 1b52d9dc94e8716c ]---
    
    
  2. *** perf_fuzzer 0.31-pre *** by Vince Weaver
    
            Linux version 4.1.0-rc7+ x86_64
            Processor: Intel 6/60/3
    
            Seeding random number generator with 1434065037
            /proc/sys/kernel/perf_event_max_sample_rate currently: 50000/s
            /proc/sys/kernel/perf_event_paranoid currently: 1
            Logging perf_event_open() failures: no
            Running fsync after every syscall: no
            To reproduce, try: ./perf_fuzzer -s 30000 -r 1434065037
    
    Pid=17043, sleeping 1s
    ==================================================
    Fuzzing the following syscalls:
            mmap perf_event_open close read write ioctl fork prctl poll 
    *NOT* Fuzzing the following syscalls:
            
    Also attempting the following:
            signal-handler-on-overflow busy-instruction-loop accessing-perf-proc-and-sys-files trashing-the-mmap-page 
    *NOT* attempting the following:
            
    ==================================================
    Iteration 10000
            Open attempts: 149044  Successful: 967  Currently open: 84
                    EPERM : 21
                    ENOENT : 865
                    E2BIG : 12954
                    EBADF : 12584
                    EACCES : 610
                    EBUSY : 8
                    EINVAL : 120702
                    EOPNOTSUPP : 333
                    Type (Hardware 215/20957)(software 356/21563)(tracepoint 75/21550)(Cache 68/18818)(cpu 192/21199)(breakpoint 11/21207)(power 0/2675)(intel_bts 50/2628)(uncore_imc 0/2747)(#9 0/16)(#10 0/18)(#11 0/8)(#12 0/10)(#13 0/7)(#14 0/12)(>14 0/15629)
            Close:  883/883 Successful
            Read:   784/876 Successful
            Write:  0/943 Successful
            Ioctl:  374/851 Successful: (ENABLE 93/93)(DISABLE 82/82)(REFRESH 6/103)(RESET 79/79)(PERIOD 16/79)(SET_OUTPUT 9/79)(SET_FILTER 0/88)(ID 89/89)(SET_BPF 0/89)(#9 0/0)(#10 0/0)(#11 0/0)(#12 0/0)(#13 0/0)(#14 0/0)(>14 0/70)
            Mmap:   473/1119 Successful: (MMAP 473/1119)(TRASH 119/140)(READ 14/134)(UNMAP 466/1045)(AUX 1/262)(AUX_READ 2/13)
            Prctl:  908/908 Successful
            Fork:   438/438 Successful
            Poll:   894/923 Successful
            Access: 446/898 Successful
            Overflows: 1
            SIGIOs due to RT signal queue full: 0
    [27716.779727] ------------[ cut here ]------------
    [27716.785131] WARNING: CPU: 2 PID: 17655 at kernel/events/ring_buffer.c:282 perf_aux_output_begin+0x1ce/0x1f0()
    [27716.796157] Modules linked in: fuse x86_pkg_temp_thermal intel_powerclamp intel_rapl iosf_mbi coretemp kvm_intel kvm snd_hda_codec_realtek snd_hda_codec_hdmi snd_hda_codec_generic snd_hda_intel snd_hda_controller crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec aesni_intel snd_hda_core aes_x86_64 iTCO_wdt lrw snd_hwdep gf128mul snd_pcm iTCO_vendor_support ppdev i915 snd_timer glue_helper evdev ablk_helper snd cryptd mei_me mei psmouse pcspkr soundcore serio_raw lpc_ich drm_kms_helper parport_pc battery tpm_tis mfd_core parport drm video tpm i2c_i801 i2c_algo_bit wmi processor button sg sr_mod cdrom sd_mod ehci_pci ehci_hcd ahci libahci libata xhci_pci xhci_hcd e1000e ptp scsi_mod crc32c_intel usbcore pps_core usb_common thermal fan thermal_sys
    [27716.873350] CPU: 2 PID: 17655 Comm: perf_fuzzer Tainted: G        W       4.1.0-rc7+ #155
    [27716.882671] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
    [27716.891168]  ffffffff81a230f2 ffff8800cf9afc68 ffffffff816d7229 0000000000000000
    [27716.899782]  0000000000000000 ffff8800cf9afca8 ffffffff81072eba 000000000000cf80
    [27716.908372]  ffff880036d85a00 ffff88011ea8cf80 ffff880119106000 000000000000cf80
    [27716.916981] Call Trace:
    [27716.920180]  [] dump_stack+0x45/0x57
    [27716.926250]  [] warn_slowpath_common+0x8a/0xc0
    [27716.933244]  [] warn_slowpath_null+0x1a/0x20
    [27716.939999]  [] perf_aux_output_begin+0x1ce/0x1f0
    [27716.947225]  [] ? perf_event_update_userpage+0x5/0x170
    [27716.954875]  [] bts_event_add+0x6d/0x150
    [27716.961259]  [] event_sched_in.isra.85+0xfb/0x330
    [27716.968495]  [] group_sched_in+0xba/0x1e0
    [27716.974957]  [] ? native_sched_clock+0x2a/0x90
    [27716.981888]  [] ctx_sched_in+0x1d0/0x3f0
    [27716.988274]  [] perf_event_sched_in+0x69/0xa0
    [27716.995082]  [] perf_event_context_sched_in+0x90/0x160
    [27717.002714]  [] __perf_event_task_sched_in+0xa8/0xc0
    [27717.010160]  [] finish_task_switch+0xed/0x140
    [27717.016988]  [] ? __switch_to+0x263/0x5d0
    [27717.023400]  [] schedule_tail+0x11/0xa0
    [27717.029652]  [] ret_from_fork+0xf/0x70
    [27717.035806] ---[ end trace bdbfeef5d81e5fa4 ]---
    
    
    

Back to perf_fuzzer bugs found