WARNING: CPU: 1 PID: 20027 at kernel/events/ring_buffer.c:539 __rb_free_aux+0x111/0x120

Found by

perf_fuzzer

First Seen

4.8-rc1

Most recently Seen

4.9-rc5

Reproducible

???

Type

warning

Found On

Haswell, Skylake

Linux-kernel Mailing List Report

9 August 2016: Re: perf: WARNING: kernel/events/core.c:4893 perf_mmap_close November 2016: Re: perf: perf_fuzzer WARNING: ring_buffer.c:546 __rb_free_aux

Kernel Splat

  1. static void __rb_free_aux(struct ring_buffer *rb)
    {
            int pg;
    
            /*
             * Should never happen, the last reference should be dropped from
             * perf_mmap_close() path, which first stops aux transactions (which
             * in turn are the atomic holders of aux_refcount) and then does the
             * last rb_free_aux().
             */
            WARN_ON_ONCE(in_atomic());
    
    
    
    *** perf_fuzzer 0.32-rc0 *** by Vince Weaver
    
            Linux version 4.9.0-rc5+ x86_64
            Processor: Intel 6/94/3
    
            Stopping after 30000
            Watchdog enabled with timeout 60s
            Will auto-exit if signal storm detected
            Seeding RNG from time 1479387077
    
            To reproduce, try:
                    echo 1 > /proc/sys/kernel/nmi_watchdog
                    echo 0 > /proc/sys/kernel/perf_event_paranoid
                    echo 250 > /proc/sys/kernel/perf_event_max_sample_rate
                    ./perf_fuzzer -s 30000 -r 1479387077
    
            Fuzzing the following syscalls: mmap perf_event_open close read write ioctl fork prctl poll 
            Also attempting the following: signal-handler-on-overflow busy-instruction-loop accessing-perf-proc-and-sys-files trashing-the-mmap-page 
    
            Pid=32648, sleeping 1s
    
    ==================================================
    Starting fuzzing at 2016-11-17 07:51:18
    ==================================================
    Cannot open /sys/kernel/tracing/kprobe_events
    Iteration 10000 (2000.000000 ops/s)
            Open attempts: 107208  Successful: 896  Currently open: 2
                    EPERM : 17
                    ENOENT : 572
                    E2BIG : 9497
                    EBADF : 9100
                    EBUSY : 9
                    EINVAL : 87022
                    EOPNOTSUPP : 95
                    Trinity Type (Normal 292/27035)(Sampling 33/26659)(Global 535/26800)(Random 36/26714)
                    Type (Hardware 206/15076)(software 326/14565)(tracepoint 64/14359)(Cache 51/13340)(cpu 206/14215)(breakpoint 11/14235)(intel_bts 10/838)(intel_pt 3/910)(msr 5/929)(power 1/852)(uncore_imc 1/863)(uncore_cbox_0 1/826)(uncore_cbox_1 0/822)(uncore_cbox_2 2/882)(uncore_cbox_3 2/829)(uncore_arb 2/825)(cstate_core 1/1035)(cstate_pkg 4/881)(#18 0/10)(>19 0/10916)
            Close:  894/894 Successful
            Read:   827/895 Successful
            Write:  0/890 Successful
            Ioctl:  364/863 Successful: (ENABLE 89/89)(DISABLE 71/71)(REFRESH 8/72)(RESET 77/77)(PERIOD 9/70)(SET_OUTPUT 8/69)(SET_FILTER 0/78)(ID 91/91)(SET_BPF 0/89)(PAUSE_OUTPUT 11/85)(#10 0/0)(#11 0/0)(#12 0/0)(#13 0/0)(#14 0/0)(>14 0/72)
            Mmap:   453/1040 Successful: (MMAP 453/1040)(TRASH 84/147)(READ 89/90)(UNMAP 453/989)(AUX 0/116)(AUX_READ 0/0)
            Prctl:  928/928 Successful
            Fork:   449/449 Successful
            Poll:   898/916 Successful
            Access: 116/929 Successful
            Overflows: 0  Recursive: 0
            SIGIOs due to RT signal queue full: 0
    Iteration 20000 (1666.666667 ops/s)
            Open attempts: 105675  Successful: 893  Currently open: 8
                    EPERM : 13
                    ENOENT : 587
                    E2BIG : 9282
                    EBADF : 8755
                    EBUSY : 11
                    EINVAL : 86022
                    EOVERFLOW : 1
                    EOPNOTSUPP : 111
                    Trinity Type (Normal 281/26401)(Sampling 37/26741)(Global 535/26128)(Random 40/26405)
                    Type (Hardware 181/14630)(software 360/14325)(tracepoint 65/14059)(Cache 51/13492)(cpu 190/14161)(breakpoint 12/13940)(intel_bts 10/826)(intel_pt 3/829)(msr 9/885)(power 0/802)(uncore_imc 0/827)(uncore_cbox_0 3/813)(uncore_cbox_1 1/867)(uncore_cbox_2 0/782)(uncore_cbox_3 2/822)(uncore_arb 1/877)(cstate_core 2/1006)(cstate_pkg 3/831)(#18 0/9)(>19 0/10892)
            Close:  887/887 Successful
            Read:   727/825 Successful
            Write:  0/820 Successful
            Ioctl:  345/869 Successful: (ENABLE 74/74)(DISABLE 66/66)(REFRESH 10/79)(RESET 77/77)(PERIOD 11/75)(SET_OUTPUT 8/85)(SET_FILTER 0/78)(ID 92/92)(SET_BPF 0/85)(PAUSE_OUTPUT 7/86)(#10 0/0)(#11 0/0)(#12 0/0)(#13 0/0)(#14 0/0)(>14 0/72)
            Mmap:   433/1061 Successful: (MMAP 433/1061)(TRASH 94/157)(READ 87/96)(UNMAP 433/980)(AUX 0/87)(AUX_READ 0/0)
            Prctl:  930/930 Successful
            Fork:   461/461 Successful
            Poll:   910/939 Successful
            Access: 106/898 Successful
            Overflows: 5  Recursive: 0
            SIGIOs due to RT signal queue full: 0
    [150064.587195] ------------[ cut here ]------------
    [150064.594626] WARNING: CPU: 0 PID: 0 at kernel/events/ring_buffer.c:546 __rb_free_aux+0x1cb/0x1d0
    [150064.709271] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W    L  4.9.0-rc5+ #11
    [150064.719631] Hardware name: LENOVO 10FY0017US/SKYBAY, BIOS FWKT53A   06/06/2016
    [150064.729680]  ffff8801f5a07ce0 ffffffffa9ebe748 0000000000000000 0000000000000000
    [150064.740027]  ffff8801f5a07d28 ffffffffa9ab6ee7 ffffffffaa812540 00000222de0dca00
    [150064.750380]  ffff8801e50ed340 ffff8801f5a14740 ffff8801e50ed340 0000000000000000
    [150064.760683] Call Trace:
    [150064.765834]   [150064.767909]  [] dump_stack+0x63/0x8b
    [150064.775798]  [] __warn+0x117/0x140
    [150064.783473]  [] warn_slowpath_null+0x1d/0x20
    [150064.792064]  [] __rb_free_aux+0x1cb/0x1d0
    [150064.800362]  [] rb_free_aux+0x18/0x20
    [150064.808266]  [] perf_aux_output_end+0x19a/0x220
    [150064.817015]  [] bts_event_stop+0x104/0x1d0
    [150064.825268]  [] bts_event_del+0x13/0x20
    [150064.833160]  [] event_sched_out.isra.91+0x1c4/0x5d0
    [150064.842060]  [] ? x86_pmu_disable+0x6c/0x80
    [150064.850208]  [] group_sched_out+0x6e/0x110
    [150064.858221]  [] __perf_event_disable+0x140/0x1b0
    [150064.866696]  [] event_function+0x10f/0x1e0
    [150064.874605]  [] ? group_sched_out+0x110/0x110
    [150064.882767]  [] ? cpu_clock_event_read+0x10/0x10
    [150064.891144]  [] ? perf_cgroup_attach+0x70/0x70
    [150064.899332]  [] remote_function+0x76/0xa0
    [150064.907068]  [] flush_smp_call_function_queue+0xb3/0x1d0
    [150064.916149]  [] generic_smp_call_function_single_interrupt+0x13/0x60
    [150064.926282]  [] smp_call_function_single_interrupt+0x40/0x50
    [150064.935716]  [] call_function_single_interrupt+0x82/0x90
    [150064.944835]   [150064.946918]  [] ? sched_idle_set_state+0x2a/0x40
    [150064.955373]  [] ? cpuidle_enter_state+0x158/0x320
    [150064.963900]  [] cpuidle_enter+0x17/0x20
    [150064.971550]  [] call_cpuidle+0x4d/0x80
    [150064.979131]  [] cpu_startup_entry+0x1b7/0x290
    [150064.987287]  [] rest_init+0x87/0x90
    [150064.994610]  [] start_kernel+0x59c/0x5bf
    [150065.002351]  [] ? early_idt_handler_array+0x120/0x120
    [150065.011260]  [] x86_64_start_reservations+0x24/0x26
    [150065.019993]  [] x86_64_start_kernel+0x14c/0x16f
    [150065.028338] ---[ end trace 806838d55bf2c099 ]---
    
  2. *** perf_fuzzer 0.31-pre *** by Vince Weaver
    
            Linux version 4.8.0-rc1+ x86_64
            Processor: Intel 6/60/3
    
            Seeding random number generator with 1470694177
            /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 -t OCIRMQWPFpAi -s 50000 -r 1470694177
    
    Pid=21097, 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:
            busy-instruction-loop accessing-perf-proc-and-sys-files trashing-the-mmap-page 
    *NOT* attempting the following:
            signal-handler-on-overflow 
    ==================================================
    Cannot open /sys/kernel/tracing/kprobe_events
    Iteration 20000
            Open attempts: 101133  Successful: 854  Currently open: 30
                    EPERM : 21
                    ENOENT : 588
                    E2BIG : 8868
                    EBADF : 8442
                    EBUSY : 2
                    EINVAL : 82281
                    EOPNOTSUPP : 77
                    Trinity Type (Normal 290/25199)(Sampling 37/25333)(Global 496/25404)(Random 31/25197)
                    Type (Hardware 202/14174)(software 314/13503)(tracepoint 38/13521)(Cache 57/12646)(cpu 199/13673)(breakpoint 13/13611)(intel_bts 12/853)(msr 5/841)(power 1/958)(uncore_imc 1/859)(uncore_cbox_0 3/870)(uncore_cbox_1 4/831)(uncore_cbox_2 3/851)(uncore_cbox_3 0/834)(uncore_arb 2/838)(cstate_core 0/858)(cstate_pkg 0/944)(#17 0/6)(#18 0/10)(>19 0/10452)
            Close:  878/878 Successful
            Read:   815/906 Successful
            Write:  0/870 Successful
            Ioctl:  333/876 Successful: (ENABLE 68/68)(DISABLE 81/81)(REFRESH 3/76)(RESET 80/80)(PERIOD 4/78)(SET_OUTPUT 3/71)(SET_FILTER 0/93)(ID 85/85)(SET_BPF 0/81)(PAUSE_OUTPUT 9/89)(#10 0/0)(#11 0/0)(#12 0/0)(#13 0/0)(#14 0/0)(>14 0/74)
            Mmap:   410/1014 Successful: (MMAP 410/1014)(TRASH 122/166)(READ 21/143)(UNMAP 415/1009)(AUX 2/96)(AUX_READ 0/14)
            Prctl:  932/932 Successful
            Fork:   460/460 Successful
            Poll:   841/896 Successful
            Access: 477/925 Successful
            Overflows: 0  Recursive: 0
            SIGIOs due to RT signal queue full: 0
    Iteration 10000
            Open attempts: 103854  Successful: 940  Currently open: 16
                    EPERM : 17
                    ENOENT : 605
                    E2BIG : 9211
                    EBADF : 8592
                    EBUSY : 3
                    EINVAL : 84389
                    EOPNOTSUPP : 97
                    Trinity Type (Normal 338/26010)(Sampling 25/25888)(Global 535/26071)(Random 42/25885)
                    Type (Hardware 220/14442)(software 346/13962)(tracepoint 41/13909)(Cache 46/13000)(cpu 240/13981)(breakpoint 13/13956)(intel_bts 16/829)(msr 4/905)(power 0/944)(uncore_imc 0/904)(uncore_cbox_0 4/895)(uncore_cbox_1 1/834)(uncore_cbox_2 3/915)(uncore_cbox_3 2/829)(uncore_arb 2/900)(cstate_core 1/892)(cstate_pkg 1/946)(#17 0/10)(#18 0/9)(>19 0/10792)
            Close:  924/924 Successful
            Read:   803/888 Successful
            Write:  0/930 Successful
            Ioctl:  358/910 Successful: (ENABLE 68/68)(DISABLE 75/75)(REFRESH 9/93)(RESET 87/87)(PERIOD 11/89)(SET_OUTPUT 11/75)(SET_FILTER 0/81)(ID 86/86)(SET_BPF 0/102)(PAUSE_OUTPUT 11/76)(#10 0/0)(#11 0/0)(#12 0/0)(#13 0/0)(#14 0/0)(>14 0/78)
            Mmap:   429/1087 Successful: (MMAP 429/1087)(TRASH 111/145)(READ 22/168)(UNMAP 426/1078)(AUX 0/104)(AUX_READ 1/6)
            Prctl:  906/906 Successful
            Fork:   433/433 Successful
            Poll:   947/960 Successful
            Access: 437/859 Successful
            Overflows: 0  Recursive: 0
            SIGIOs due to RT signal queue full: 0
    [10772.606425] ------------[ cut here ]------------
    [10772.611802] WARNING: CPU: 1 PID: 20027 at kernel/events/ring_buffer.c:539 __rb_free_aux+0x111/0x120
    [10772.621856] Modules linked in: fuse binfmt_misc intel_rapl iosf_mbi x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel snd_hda_codec_hdmi aes_x86_64 lrw gf128mul glue_helper snd_hda_codec_realtek snd_hda_codec_generic ablk_helper ppdev iTCO_wdt snd_hda_intel snd_hda_codec snd_hda_core cryptd evdev iTCO_vendor_support snd_hwdep snd_pcm snd_timer snd i915 drm_kms_helper parport_pc wmi parport psmouse tpm_tis tpm_tis_core pcspkr serio_raw sg button i2c_i801 soundcore lpc_ich drm mei_me mfd_core i2c_smbus tpm mei video battery i2c_algo_bit sr_mod sd_mod cdrom ahci libahci xhci_pci libata ehci_pci xhci_hcd ehci_hcd e1000e usbcore ptp crc32c_intel scsi_mod pps_core usb_common fan thermal
    [10772.699231] CPU: 1 PID: 20027 Comm: perf_fuzzer Tainted: G        W       4.8.0-rc1+ #187
    [10772.708539] Hardware name: LENOVO 10AM000AUS/SHARKBAY, BIOS FBKT72AUS 01/26/2014
    [10772.717011]  0000000000000000 ffff88011ea43cb0 ffffffff81437641 0000000000000000
    [10772.725555]  0000000000000000 ffff88011ea43cf0 ffffffff81076bab 0000021b1ea43d48
    [10772.734103]  ffff8800d0663800 ffff88011ea4b700 0000000000000000 ffff880036cf9800
    [10772.742694] Call Trace:
    

Back to perf_fuzzer bugs found