[LKP] [sched] INFO: suspicious RCU usage. ]

From: Yuanhan Liu
Date: Mon Nov 24 2014 - 07:37:21 EST

Next message: Yuanhan Liu: "[LKP] [net] 4ed2d765dfa:"
Previous message: Arnd Bergmann: "Re: [PATCH v2 1/5] misc: sensorhub: Add sensorhub driver"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

FYI, we noticed the below changes on

commit eeb61e53ea19be0c4015b00b2e8b3b2185436f2b ("sched: Fix race between task_group and sched_task_group")

+---------------------------+------------+------------+
| | xfs-for-li | eeb61e53ea |
+---------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 54 | 10 |
| BUG:kernel_boot_hang | 54 | 10 |
| INFO:suspicious_RCU_usage | 0 | 10 |
| backtrace:do_fork | 0 | 10 |
+---------------------------+------------+------------+

[ 0.054010] ftrace: allocating 44163 entries in 87 pages
[ 0.072399]
[ 0.073480] ===============================
[ 0.074916] [ INFO: suspicious RCU usage. ]
[ 0.076000] 3.18.0-rc2-g05da589 #861 Not tainted
[ 0.076000] -------------------------------
[ 0.076000] kernel/sched/core.c:7449 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] 2 locks held by swapper/0/0:
[ 0.076000] #0: (&p->pi_lock){......}, at: [<c1069318>] task_rq_lock+0x28/0xba
[ 0.076000] #1: (&rq->lock){-.....}, at: [<c1069336>] task_rq_lock+0x46/0xba
[ 0.076000]
[ 0.076000] stack backtrace:
[ 0.076000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.18.0-rc2-g05da589 #861
[ 0.076000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[ 0.076000] 00000000 00000000 c209be98 c1b238b0 00000001 c209beb4 c108ba6a c1f54e96
[ 0.076000] c20a3550 d30c0000 d370c300 c20b28a0 c209bed4 c10731b6 00000000 00003550
[ 0.076000] 00200246 d30c0000 00000000 00000000 c209bedc c1073285 c209bef0 c10cb273
[ 0.076000] Call Trace:
[ 0.076000] [<c1b238b0>] dump_stack+0x48/0x60
[ 0.076000] [<c108ba6a>] lockdep_rcu_suspicious+0xd3/0xdc
[ 0.076000] [<c10731b6>] sched_move_task+0xd1/0x17c
[ 0.076000] [<c1073285>] cpu_cgroup_fork+0xd/0xf
[ 0.076000] [<c10cb273>] cgroup_post_fork+0xe1/0xec
[ 0.076000] [<c10464a4>] copy_process+0x1652/0x181f
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c1073f5b>] ? sched_clock_cpu+0x11b/0x136
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c10467c7>] do_fork+0x7d/0x632
[ 0.076000] [<c1088ad7>] ? trace_hardirqs_on_caller+0x160/0x17b
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c1088afd>] ? trace_hardirqs_on+0xb/0xd
[ 0.076000] [<c106ce9c>] ? nr_context_switches+0xb2/0xe4
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c1046d9b>] kernel_thread+0x1f/0x24
[ 0.076000] [<c1b1c22a>] rest_init+0x1f/0x116
[ 0.076000] [<c222db5b>] start_kernel+0x3fd/0x404
[ 0.076000] [<c222d2af>] i386_start_kernel+0x79/0x7d
[ 0.076113] Getting VERSION: 50014
[ 0.077525] Getting VERSION: 50014
[ 0.080016] Getting ID: 0

--yliu
early console in setup code
early console in decompress_kernel

Decompressing Linux... Parsing ELF... done.
Booting the kernel.
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Linux version 3.18.0-rc2-g05da589 (kbuild@lkp-hsx01) (gcc version 4.9.1 (Debian 4.9.1-19) ) #861 SMP Mon Nov 10 11:26:57 CST 2014
[ 0.000000] e820: BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x0000000013ffdfff] usable
[ 0.000000] BIOS-e820: [mem 0x0000000013ffe000-0x0000000013ffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[ 0.000000] bootconsole [earlyser0] enabled
[ 0.000000] Notice: NX (Execute Disable) protection missing in CPU!
[ 0.000000] SMBIOS 2.4 present.
[ 0.000000] DMI: Bochs Bochs, BIOS Bochs 01/01/2011
[ 0.000000] Hypervisor detected: KVM
[ 0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[ 0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[ 0.000000] e820: last_pfn = 0x13ffe max_arch_pfn = 0x1000000
[ 0.000000] initial memory mapped: [mem 0x00000000-0x031fffff]
[ 0.000000] Base memory trampoline at [c009b000] 9b000 size 16384
[ 0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[ 0.000000] [mem 0x00000000-0x000fffff] page 4k
[ 0.000000] init_memory_mapping: [mem 0x13a00000-0x13bfffff]
[ 0.000000] [mem 0x13a00000-0x13bfffff] page 4k
[ 0.000000] BRK [0x02d81000, 0x02d81fff] PGTABLE
[ 0.000000] init_memory_mapping: [mem 0x10000000-0x139fffff]
[ 0.000000] [mem 0x10000000-0x139fffff] page 4k
[ 0.000000] BRK [0x02d82000, 0x02d82fff] PGTABLE
[ 0.000000] BRK [0x02d83000, 0x02d83fff] PGTABLE
[ 0.000000] BRK [0x02d84000, 0x02d84fff] PGTABLE
[ 0.000000] BRK [0x02d85000, 0x02d85fff] PGTABLE
[ 0.000000] BRK [0x02d86000, 0x02d86fff] PGTABLE
[ 0.000000] init_memory_mapping: [mem 0x00100000-0x0fffffff]
[ 0.000000] [mem 0x00100000-0x0fffffff] page 4k
[ 0.000000] init_memory_mapping: [mem 0x13c00000-0x13ffdfff]
[ 0.000000] [mem 0x13c00000-0x13ffdfff] page 4k
[ 0.000000] RAMDISK: [mem 0x13c0c000-0x13feffff]
[ 0.000000] ACPI: Early table checksum verification disabled
[ 0.000000] ACPI: RSDP 0x000FD950 000014 (v00 BOCHS )
[ 0.000000] ACPI: RSDT 0x13FFE450 000034 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: FACP 0x13FFFF80 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
[ 0.000000] ACPI: DSDT 0x13FFE490 0011A9 (v01 BXPC BXDSDT 00000001 INTL 20100528)
[ 0.000000] ACPI: FACS 0x13FFFF40 000040
[ 0.000000] ACPI: SSDT 0x13FFF7A0 000796 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: APIC 0x13FFF680 000080 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
[ 0.000000] ACPI: HPET 0x13FFF640 000038 (v01 BOCHS BXPCHPET 00000001 BXPC 00000001)
[ 0.000000] ACPI: Local APIC address 0xfee00000
[ 0.000000] mapped APIC to ffffb000 ( fee00000)
[ 0.000000] 0MB HIGHMEM available.
[ 0.000000] 319MB LOWMEM available.
[ 0.000000] mapped low ram: 0 - 13ffe000
[ 0.000000] low ram: 0 - 13ffe000
[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[ 0.000000] kvm-clock: cpu 0, msr 0:13ffc001, primary cpu clock
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x00001000-0x00ffffff]
[ 0.000000] Normal [mem 0x01000000-0x13ffdfff]
[ 0.000000] HighMem empty
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x00001000-0x0009efff]
[ 0.000000] node 0: [mem 0x00100000-0x13ffdfff]
[ 0.000000] Initmem setup node 0 [mem 0x00001000-0x13ffdfff]
[ 0.000000] On node 0 totalpages: 81820
[ 0.000000] free_area_init_node: node 0, pgdat c21951a0, node_mem_map d385f028
[ 0.000000] DMA zone: 40 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 3998 pages, LIFO batch:0
[ 0.000000] Normal zone: 760 pages used for memmap
[ 0.000000] Normal zone: 77822 pages, LIFO batch:15
[ 0.000000] Using APIC driver default
[ 0.000000] ACPI: PM-Timer IO Port: 0xb008
[ 0.000000] ACPI: Local APIC address 0xfee00000
[ 0.000000] mapped APIC to ffffb000 ( fee00000)
[ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[ 0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0])
[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 00, APIC ID 0, APIC INT 02
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 05, APIC ID 0, APIC INT 05
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 09, APIC ID 0, APIC INT 09
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 0a, APIC ID 0, APIC INT 0a
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 0b, APIC ID 0, APIC INT 0b
[ 0.000000] ACPI: IRQ0 used by override.
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 01, APIC ID 0, APIC INT 01
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 03, APIC ID 0, APIC INT 03
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 04, APIC ID 0, APIC INT 04
[ 0.000000] ACPI: IRQ5 used by override.
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 06, APIC ID 0, APIC INT 06
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 07, APIC ID 0, APIC INT 07
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 08, APIC ID 0, APIC INT 08
[ 0.000000] ACPI: IRQ9 used by override.
[ 0.000000] ACPI: IRQ10 used by override.
[ 0.000000] ACPI: IRQ11 used by override.
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0c, APIC ID 0, APIC INT 0c
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0d, APIC ID 0, APIC INT 0d
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0e, APIC ID 0, APIC INT 0e
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0f, APIC ID 0, APIC INT 0f
[ 0.000000] Using ACPI (MADT) for SMP configuration information
[ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[ 0.000000] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[ 0.000000] mapped IOAPIC to ffffa000 (fec00000)
[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]
[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[ 0.000000] e820: [mem 0x14000000-0xfeffbfff] available for PCI devices
[ 0.000000] Booting paravirtualized kernel on KVM
[ 0.000000] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:2 nr_node_ids:1
[ 0.000000] PERCPU: Embedded 333 pages/cpu @d35c5000 s1342048 r0 d21920 u1363968
[ 0.000000] pcpu-alloc: s1342048 r0 d21920 u1363968 alloc=333*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1
[ 0.000000] KVM setup async PF for cpu 0
[ 0.000000] kvm-stealtime: cpu 0, msr 135c75c0
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 81020
[ 0.000000] Kernel command line: user=lkp job=/lkp/scheduled/vm-kbuild-yocto-i386-62/rand_boot-1-yocto-minimal-i386.cgz-i386-randconfig-ha2-1109-05da5898a96c05e32aa9850c9cd89eef29471b13-1.yaml ARCH=i386 BOOT_IMAGE=/kernel/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/vmlinuz-3.18.0-rc2-g05da589 kconfig=i386-randconfig-ha2-1109 commit=05da5898a96c05e32aa9850c9cd89eef29471b13 branch=pshelar-openvswitch/net_next_ovs root=/dev/ram0 max_uptime=3600 RESULT_ROOT=/result/vm-kbuild-yocto-i386/boot/1/yocto-minimal-i386.cgz/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/0 ip=::::vm-kbuild-yocto-i386-62::dhcp earlyprintk=ttyS0,115200 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8
[ 0.000000] sysrq: sysrq always enabled.
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Initializing CPU#0
[ 0.000000] Initializing HighMem for node 0 (00000000:00000000)
[ 0.000000] Memory: 286168K/327280K available (11509K kernel code, 1609K rwdata, 5480K rodata, 2316K init, 9152K bss, 41112K reserved, 0K highmem)
[ 0.000000] virtual kernel memory layout:
[ 0.000000] fixmap : 0xffe6e000 - 0xfffff000 (1604 kB)
[ 0.000000] pkmap : 0xff800000 - 0xffa00000 (2048 kB)
[ 0.000000] vmalloc : 0xd47fe000 - 0xff7fe000 ( 688 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xd3ffe000 ( 319 MB)
[ 0.000000] .init : 0xc222d000 - 0xc2470000 (2316 kB)
[ 0.000000] .data : 0xc1b3d844 - 0xc222b400 (7094 kB)
[ 0.000000] .text : 0xc1000000 - 0xc1b3d844 (11510 kB)
[ 0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 0.000000] NR_IRQS:2304 nr_irqs:440 0
[ 0.000000] CPU 0 irqstacks, hard=d300a000 soft=d300c000
[ 0.000000] Console: colour VGA+ 80x25
[ 0.000000] console [tty0] enabled
[ 0.000000] bootconsole [earlyser0] disabled
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Linux version 3.18.0-rc2-g05da589 (kbuild@lkp-hsx01) (gcc version 4.9.1 (Debian 4.9.1-19) ) #861 SMP Mon Nov 10 11:26:57 CST 2014
[ 0.000000] e820: BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x0000000013ffdfff] usable
[ 0.000000] BIOS-e820: [mem 0x0000000013ffe000-0x0000000013ffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[ 0.000000] bootconsole [earlyser0] enabled
[ 0.000000] Notice: NX (Execute Disable) protection missing in CPU!
[ 0.000000] SMBIOS 2.4 present.
[ 0.000000] DMI: Bochs Bochs, BIOS Bochs 01/01/2011
[ 0.000000] Hypervisor detected: KVM
[ 0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[ 0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[ 0.000000] e820: last_pfn = 0x13ffe max_arch_pfn = 0x1000000
[ 0.000000] initial memory mapped: [mem 0x00000000-0x031fffff]
[ 0.000000] Base memory trampoline at [c009b000] 9b000 size 16384
[ 0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[ 0.000000] [mem 0x00000000-0x000fffff] page 4k
[ 0.000000] init_memory_mapping: [mem 0x13a00000-0x13bfffff]
[ 0.000000] [mem 0x13a00000-0x13bfffff] page 4k
[ 0.000000] BRK [0x02d81000, 0x02d81fff] PGTABLE
[ 0.000000] init_memory_mapping: [mem 0x10000000-0x139fffff]
[ 0.000000] [mem 0x10000000-0x139fffff] page 4k
[ 0.000000] BRK [0x02d82000, 0x02d82fff] PGTABLE
[ 0.000000] BRK [0x02d83000, 0x02d83fff] PGTABLE
[ 0.000000] BRK [0x02d84000, 0x02d84fff] PGTABLE
[ 0.000000] BRK [0x02d85000, 0x02d85fff] PGTABLE
[ 0.000000] BRK [0x02d86000, 0x02d86fff] PGTABLE
[ 0.000000] init_memory_mapping: [mem 0x00100000-0x0fffffff]
[ 0.000000] [mem 0x00100000-0x0fffffff] page 4k
[ 0.000000] init_memory_mapping: [mem 0x13c00000-0x13ffdfff]
[ 0.000000] [mem 0x13c00000-0x13ffdfff] page 4k
[ 0.000000] RAMDISK: [mem 0x13c0c000-0x13feffff]
[ 0.000000] ACPI: Early table checksum verification disabled
[ 0.000000] ACPI: RSDP 0x000FD950 000014 (v00 BOCHS )
[ 0.000000] ACPI: RSDT 0x13FFE450 000034 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: FACP 0x13FFFF80 000074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
[ 0.000000] ACPI: DSDT 0x13FFE490 0011A9 (v01 BXPC BXDSDT 00000001 INTL 20100528)
[ 0.000000] ACPI: FACS 0x13FFFF40 000040
[ 0.000000] ACPI: SSDT 0x13FFF7A0 000796 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001)
[ 0.000000] ACPI: APIC 0x13FFF680 000080 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
[ 0.000000] ACPI: HPET 0x13FFF640 000038 (v01 BOCHS BXPCHPET 00000001 BXPC 00000001)
[ 0.000000] ACPI: Local APIC address 0xfee00000
[ 0.000000] mapped APIC to ffffb000 ( fee00000)
[ 0.000000] 0MB HIGHMEM available.
[ 0.000000] 319MB LOWMEM available.
[ 0.000000] mapped low ram: 0 - 13ffe000
[ 0.000000] low ram: 0 - 13ffe000
[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[ 0.000000] kvm-clock: cpu 0, msr 0:13ffc001, primary cpu clock
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x00001000-0x00ffffff]
[ 0.000000] Normal [mem 0x01000000-0x13ffdfff]
[ 0.000000] HighMem empty
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x00001000-0x0009efff]
[ 0.000000] node 0: [mem 0x00100000-0x13ffdfff]
[ 0.000000] Initmem setup node 0 [mem 0x00001000-0x13ffdfff]
[ 0.000000] On node 0 totalpages: 81820
[ 0.000000] free_area_init_node: node 0, pgdat c21951a0, node_mem_map d385f028
[ 0.000000] DMA zone: 40 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 3998 pages, LIFO batch:0
[ 0.000000] Normal zone: 760 pages used for memmap
[ 0.000000] Normal zone: 77822 pages, LIFO batch:15
[ 0.000000] Using APIC driver default
[ 0.000000] ACPI: PM-Timer IO Port: 0xb008
[ 0.000000] ACPI: Local APIC address 0xfee00000
[ 0.000000] mapped APIC to ffffb000 ( fee00000)
[ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[ 0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0])
[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 00, APIC ID 0, APIC INT 02
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 05, APIC ID 0, APIC INT 05
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 09, APIC ID 0, APIC INT 09
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 0a, APIC ID 0, APIC INT 0a
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.000000] Int: type 0, pol 1, trig 3, bus 00, IRQ 0b, APIC ID 0, APIC INT 0b
[ 0.000000] ACPI: IRQ0 used by override.
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 01, APIC ID 0, APIC INT 01
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 03, APIC ID 0, APIC INT 03
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 04, APIC ID 0, APIC INT 04
[ 0.000000] ACPI: IRQ5 used by override.
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 06, APIC ID 0, APIC INT 06
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 07, APIC ID 0, APIC INT 07
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 08, APIC ID 0, APIC INT 08
[ 0.000000] ACPI: IRQ9 used by override.
[ 0.000000] ACPI: IRQ10 used by override.
[ 0.000000] ACPI: IRQ11 used by override.
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0c, APIC ID 0, APIC INT 0c
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0d, APIC ID 0, APIC INT 0d
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0e, APIC ID 0, APIC INT 0e
[ 0.000000] Int: type 0, pol 0, trig 0, bus 00, IRQ 0f, APIC ID 0, APIC INT 0f
[ 0.000000] Using ACPI (MADT) for SMP configuration information
[ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[ 0.000000] smpboot: Allowing 2 CPUs, 0 hotplug CPUs
[ 0.000000] mapped IOAPIC to ffffa000 (fec00000)
[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]
[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[ 0.000000] e820: [mem 0x14000000-0xfeffbfff] available for PCI devices
[ 0.000000] Booting paravirtualized kernel on KVM
[ 0.000000] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:2 nr_node_ids:1
[ 0.000000] PERCPU: Embedded 333 pages/cpu @d35c5000 s1342048 r0 d21920 u1363968
[ 0.000000] pcpu-alloc: s1342048 r0 d21920 u1363968 alloc=333*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1
[ 0.000000] KVM setup async PF for cpu 0
[ 0.000000] kvm-stealtime: cpu 0, msr 135c75c0
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 81020
[ 0.000000] Kernel command line: user=lkp job=/lkp/scheduled/vm-kbuild-yocto-i386-62/rand_boot-1-yocto-minimal-i386.cgz-i386-randconfig-ha2-1109-05da5898a96c05e32aa9850c9cd89eef29471b13-1.yaml ARCH=i386 BOOT_IMAGE=/kernel/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/vmlinuz-3.18.0-rc2-g05da589 kconfig=i386-randconfig-ha2-1109 commit=05da5898a96c05e32aa9850c9cd89eef29471b13 branch=pshelar-openvswitch/net_next_ovs root=/dev/ram0 max_uptime=3600 RESULT_ROOT=/result/vm-kbuild-yocto-i386/boot/1/yocto-minimal-i386.cgz/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/0 ip=::::vm-kbuild-yocto-i386-62::dhcp earlyprintk=ttyS0,115200 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8
[ 0.000000] sysrq: sysrq always enabled.
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Initializing CPU#0
[ 0.000000] Initializing HighMem for node 0 (00000000:00000000)
[ 0.000000] Memory: 286168K/327280K available (11509K kernel code, 1609K rwdata, 5480K rodata, 2316K init, 9152K bss, 41112K reserved, 0K highmem)
[ 0.000000] virtual kernel memory layout:
[ 0.000000] fixmap : 0xffe6e000 - 0xfffff000 (1604 kB)
[ 0.000000] pkmap : 0xff800000 - 0xffa00000 (2048 kB)
[ 0.000000] vmalloc : 0xd47fe000 - 0xff7fe000 ( 688 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xd3ffe000 ( 319 MB)
[ 0.000000] .init : 0xc222d000 - 0xc2470000 (2316 kB)
[ 0.000000] .data : 0xc1b3d844 - 0xc222b400 (7094 kB)
[ 0.000000] .text : 0xc1000000 - 0xc1b3d844 (11510 kB)
[ 0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 0.000000] NR_IRQS:2304 nr_irqs:440 0
[ 0.000000] CPU 0 irqstacks, hard=d300a000 soft=d300c000
[ 0.000000] Console: colour VGA+ 80x25
[ 0.000000] console [tty0] enabled
[ 0.000000] bootconsole [earlyser0] disabled
[ 0.000000] console [ttyS0] enabled
[ 0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 0.000000] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.000000] ... MAX_LOCK_DEPTH: 48
[ 0.000000] ... MAX_LOCKDEP_KEYS: 8191
[ 0.000000] ... CLASSHASH_SIZE: 4096
[ 0.000000] ... MAX_LOCKDEP_ENTRIES: 32768
[ 0.000000] ... MAX_LOCKDEP_CHAINS: 65536
[ 0.000000] ... CHAINHASH_SIZE: 32768
[ 0.000000] memory used by lock dependency info: 5167 kB
[ 0.000000] per task-struct memory footprint: 1920 bytes
[ 0.000000] ------------------------
[ 0.000000] | Locking API testsuite:
[ 0.000000] ----------------------------------------------------------------------------
[ 0.000000] | spin |wlock |rlock |mutex | wsem | rsem |
[ 0.000000] --------------------------------------------------------------------------
[ 0.000000] A-A deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] double unlock: ok | ok | ok | ok | ok | ok |
[ 0.000000] initialize held: ok | ok | ok | ok | ok | ok |
[ 0.000000] bad unlock order: ok | ok | ok | ok | ok | ok |
[ 0.000000] --------------------------------------------------------------------------
[ 0.000000] recursive read-lock: | ok | | ok |
[ 0.000000] recursive read-lock #2: | ok | | ok |
[ 0.000000] mixed read-write-lock: | ok | | ok |
[ 0.000000] mixed write-read-lock: | ok | | ok |
[ 0.000000] --------------------------------------------------------------------------
[ 0.000000] hard-irqs-on + irq-safe-A/12: ok | ok | ok |
[ 0.000000] soft-irqs-on + irq-safe-A/12: ok | ok | ok |
[ 0.000000] hard-irqs-on + irq-safe-A/21: ok | ok | ok |
[ 0.000000] soft-irqs-on + irq-safe-A/21: ok | ok | ok |
[ 0.000000] sirq-safe-A => hirqs-on/12: ok | ok | ok |
[ 0.000000] sirq-safe-A => hirqs-on/21: ok | ok | ok |
[ 0.000000] hard-safe-A + irqs-on/12: ok | ok | ok |
[ 0.000000] soft-safe-A + irqs-on/12: ok | ok | ok |
[ 0.000000] hard-safe-A + irqs-on/21: ok | ok | ok |
[ 0.000000] soft-safe-A + irqs-on/21: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #1/123: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #1/123: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #1/132: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #1/132: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #1/213: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #1/213: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #1/231: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #1/231: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #1/312: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #1/312: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #1/321: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #1/321: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #2/123: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #2/123: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #2/132: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #2/132: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #2/213: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #2/213: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #2/231: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #2/231: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #2/312: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #2/312: ok | ok | ok |
[ 0.000000] hard-safe-A + unsafe-B #2/321: ok | ok | ok |
[ 0.000000] soft-safe-A + unsafe-B #2/321: ok | ok | ok |
[ 0.000000] hard-irq lock-inversion/123: ok | ok | ok |
[ 0.000000] soft-irq lock-inversion/123: ok | ok | ok |
[ 0.000000] hard-irq lock-inversion/132: ok | ok | ok |
[ 0.000000] soft-irq lock-inversion/132: ok | ok | ok |
[ 0.000000] hard-irq lock-inversion/213: ok | ok | ok |
[ 0.000000] soft-irq lock-inversion/213: ok | ok | ok |
[ 0.000000] hard-irq lock-inversion/231: ok | ok | ok |
[ 0.000000] soft-irq lock-inversion/231: ok | ok | ok |
[ 0.000000] hard-irq lock-inversion/312: ok | ok | ok |
[ 0.000000] soft-irq lock-inversion/312: ok | ok | ok |
[ 0.000000] hard-irq lock-inversion/321: ok | ok | ok |
[ 0.000000] soft-irq lock-inversion/321: ok | ok | ok |
[ 0.000000] hard-irq read-recursion/123: ok |
[ 0.000000] soft-irq read-recursion/123: ok |
[ 0.000000] hard-irq read-recursion/132: ok |
[ 0.000000] soft-irq read-recursion/132: ok |
[ 0.000000] hard-irq read-recursion/213: ok |
[ 0.000000] soft-irq read-recursion/213: ok |
[ 0.000000] hard-irq read-recursion/231: ok |
[ 0.000000] soft-irq read-recursion/231: ok |
[ 0.000000] hard-irq read-recursion/312: ok |
[ 0.000000] soft-irq read-recursion/312: ok |
[ 0.000000] hard-irq read-recursion/321: ok |
[ 0.000000] soft-irq read-recursion/321: ok |
[ 0.000000] --------------------------------------------------------------------------
[ 0.000000] | Wound/wait tests |
[ 0.000000] ---------------------
[ 0.000000] ww api failures: ok | ok | ok |
[ 0.000000] ww contexts mixing: ok | ok |
[ 0.000000] finishing ww context: ok | ok | ok | ok |
[ 0.000000] locking mismatches: ok | ok | ok |
[ 0.000000] EDEADLK handling: ok | ok | ok | ok | ok | ok | ok | ok | ok | ok |
[ 0.000000] spinlock nest unlocked: ok |
[ 0.000000] -----------------------------------------------------
[ 0.000000] |block | try |context|
[ 0.000000] -----------------------------------------------------
[ 0.000000] context: ok | ok | ok |
[ 0.000000] try: ok | ok | ok |
[ 0.000000] block: ok | ok | ok |
[ 0.000000] spinlock: ok | ok | ok |
[ 0.000000] -------------------------------------------------------
[ 0.000000] Good, all 253 testcases passed! |
[ 0.000000] ---------------------------------
[ 0.000000] hpet clockevent registered
[ 0.000000] tsc: Detected 2693.630 MHz processor
[ 0.008000] Calibrating delay loop (skipped) preset value.. 5387.26 BogoMIPS (lpj=10774520)
[ 0.009935] pid_max: default: 32768 minimum: 301
[ 0.010997] ACPI: Core revision 20140926
[ 0.019674] ACPI: All ACPI Tables successfully acquired
[ 0.021804] Security Framework initialized
[ 0.023503] Yama: becoming mindful.
[ 0.024099] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.026240] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.029137] Initializing cgroup subsys devices
[ 0.032036] Initializing cgroup subsys freezer
[ 0.033837] Initializing cgroup subsys blkio
[ 0.036108] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 0.036108] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.041349] debug: unmapping init [mem 0xc2470000-0xc2476fff]
[ 0.054010] ftrace: allocating 44163 entries in 87 pages
[ 0.072399]
[ 0.073480] ===============================
[ 0.074916] [ INFO: suspicious RCU usage. ]
[ 0.076000] 3.18.0-rc2-g05da589 #861 Not tainted
[ 0.076000] -------------------------------
[ 0.076000] kernel/sched/core.c:7449 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] 2 locks held by swapper/0/0:
[ 0.076000] #0: (&p->pi_lock){......}, at: [<c1069318>] task_rq_lock+0x28/0xba
[ 0.076000] #1: (&rq->lock){-.....}, at: [<c1069336>] task_rq_lock+0x46/0xba
[ 0.076000]
[ 0.076000] stack backtrace:
[ 0.076000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.18.0-rc2-g05da589 #861
[ 0.076000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[ 0.076000] 00000000 00000000 c209be98 c1b238b0 00000001 c209beb4 c108ba6a c1f54e96
[ 0.076000] c20a3550 d30c0000 d370c300 c20b28a0 c209bed4 c10731b6 00000000 00003550
[ 0.076000] 00200246 d30c0000 00000000 00000000 c209bedc c1073285 c209bef0 c10cb273
[ 0.076000] Call Trace:
[ 0.076000] [<c1b238b0>] dump_stack+0x48/0x60
[ 0.076000] [<c108ba6a>] lockdep_rcu_suspicious+0xd3/0xdc
[ 0.076000] [<c10731b6>] sched_move_task+0xd1/0x17c
[ 0.076000] [<c1073285>] cpu_cgroup_fork+0xd/0xf
[ 0.076000] [<c10cb273>] cgroup_post_fork+0xe1/0xec
[ 0.076000] [<c10464a4>] copy_process+0x1652/0x181f
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c1073f5b>] ? sched_clock_cpu+0x11b/0x136
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c10467c7>] do_fork+0x7d/0x632
[ 0.076000] [<c1088ad7>] ? trace_hardirqs_on_caller+0x160/0x17b
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c1088afd>] ? trace_hardirqs_on+0xb/0xd
[ 0.076000] [<c106ce9c>] ? nr_context_switches+0xb2/0xe4
[ 0.076000] [<c1b1c321>] ? rest_init+0x116/0x116
[ 0.076000] [<c1046d9b>] kernel_thread+0x1f/0x24
[ 0.076000] [<c1b1c22a>] rest_init+0x1f/0x116
[ 0.076000] [<c222db5b>] start_kernel+0x3fd/0x404
[ 0.076000] [<c222d2af>] i386_start_kernel+0x79/0x7d
[ 0.076113] Getting VERSION: 50014
[ 0.077525] Getting VERSION: 50014
[ 0.080016] Getting ID: 0
[ 0.081304] Getting ID: f000000
[ 0.082706] Getting LVT0: 8700
[ 0.084012] Getting LVT1: 8400
[ 0.085346] Enabling APIC mode: Flat. Using 1 I/O APICs
[ 0.088108] enabled ExtINT on CPU#0
[ 0.090958] ENABLING IO-APIC IRQs
[ 0.092018] init IO_APIC IRQs
[ 0.093426] apic 0 pin 0 not connected
[ 0.094907] IOAPIC[0]: Set routing entry (0-1 -> 0x31 -> IRQ 1 Mode:0 Active:0 Dest:1)
[ 0.096033] IOAPIC[0]: Set routing entry (0-2 -> 0x30 -> IRQ 0 Mode:0 Active:0 Dest:1)
[ 0.100030] IOAPIC[0]: Set routing entry (0-2 -> 0x30 -> IRQ 0 Mode:0 Active:0 Dest:1)
[ 0.104030] IOAPIC[0]: Set routing entry (0-3 -> 0x33 -> IRQ 3 Mode:0 Active:0 Dest:1)
[ 0.106909] IOAPIC[0]: Set routing entry (0-4 -> 0x34 -> IRQ 4 Mode:0 Active:0 Dest:1)
[ 0.108032] IOAPIC[0]: Set routing entry (0-5 -> 0x35 -> IRQ 5 Mode:1 Active:0 Dest:1)
[ 0.112030] IOAPIC[0]: Set routing entry (0-6 -> 0x36 -> IRQ 6 Mode:0 Active:0 Dest:1)
[ 0.114855] IOAPIC[0]: Set routing entry (0-7 -> 0x37 -> IRQ 7 Mode:0 Active:0 Dest:1)
[ 0.116030] IOAPIC[0]: Set routing entry (0-8 -> 0x38 -> IRQ 8 Mode:0 Active:0 Dest:1)
[ 0.120030] IOAPIC[0]: Set routing entry (0-9 -> 0x39 -> IRQ 9 Mode:1 Active:0 Dest:1)
[ 0.124029] IOAPIC[0]: Set routing entry (0-10 -> 0x3a -> IRQ 10 Mode:1 Active:0 Dest:1)
[ 0.126704] IOAPIC[0]: Set routing entry (0-11 -> 0x3b -> IRQ 11 Mode:1 Active:0 Dest:1)
[ 0.128030] IOAPIC[0]: Set routing entry (0-12 -> 0x3c -> IRQ 12 Mode:0 Active:0 Dest:1)
[ 0.132030] IOAPIC[0]: Set routing entry (0-13 -> 0x3d -> IRQ 13 Mode:0 Active:0 Dest:1)
[ 0.134773] IOAPIC[0]: Set routing entry (0-14 -> 0x3e -> IRQ 14 Mode:0 Active:0 Dest:1)
[ 0.136034] IOAPIC[0]: Set routing entry (0-15 -> 0x3f -> IRQ 15 Mode:0 Active:0 Dest:1)
[ 0.140029] apic 0 pin 16 not connected
[ 0.141526] apic 0 pin 17 not connected
[ 0.144006] apic 0 pin 18 not connected
[ 0.145500] apic 0 pin 19 not connected
[ 0.148006] apic 0 pin 20 not connected
[ 0.149504] apic 0 pin 21 not connected
[ 0.151015] apic 0 pin 22 not connected
[ 0.152006] apic 0 pin 23 not connected
[ 0.153660] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 0.156005] smpboot: CPU0: Intel QEMU Virtual CPU version 1.7.1 (fam: 06, model: 06, stepping: 03)
[ 0.159580] Using local APIC timer interrupts.
[ 0.159580] calibrating APIC timer ...
[ 0.164000] ... lapic delta = 6250910
[ 0.164000] ... PM-Timer delta = 358004
[ 0.164000] ... PM-Timer result ok
[ 0.164000] ..... delta 6250910
[ 0.164000] ..... mult: 268474540
[ 0.164000] ..... calibration result: 4000582
[ 0.164000] ..... CPU clock speed is 2693.3523 MHz.
[ 0.164000] ..... host bus clock speed is 1000.0582 MHz.
[ 0.164117] Performance Events: Broken PMU hardware detected, using software events only.
[ 0.170586] Failed to access perfctr msr (MSR c1 is 0)
[ 0.172984] Testing tracer nop: PASSED
[ 0.177866] NMI watchdog: disabled (cpu0): hardware events not enabled
[ 0.180544] CPU 1 irqstacks, hard=d3168000 soft=d316a000
[ 0.182379] x86: Booting SMP configuration:
[ 0.184008] .... node #0, CPUs: #1
[ 0.004000] Initializing CPU#1
[ 0.008000] kvm-clock: cpu 1, msr 0:13ffc021, secondary cpu clock
[ 0.008000] masked ExtINT on CPU#1
[ 0.200113] x86: Booted up 1 node, 2 CPUs
[ 0.200069] KVM setup async PF for cpu 1
[ 0.200069] kvm-stealtime: cpu 1, msr 137145c0
[ 0.208008] ----------------
[ 0.209126] | NMI testsuite:
[ 0.210286] --------------------
[ 0.212005] remote IPI: ok |
[ 0.217066] local IPI: ok |
[ 0.224022] --------------------
[ 0.225332] Good, all 2 testcases passed! |
[ 0.227023] ---------------------------------
[ 0.228014] smpboot: Total of 2 processors activated (10774.52 BogoMIPS)
[ 0.232620] evm: security.capability
[ 0.244025] Testing tracer function: PASSED
[ 0.755189] Testing dynamic ftrace: PASSED
[ 1.000745] Testing dynamic ftrace ops #1: (1 0 1 0 0) (1 1 2 0 0) (2 1 3 0 204786) (2 2 4 0 205037) PASSED
[ 1.582879] Testing dynamic ftrace ops #2: (1 0 1 203405 0) (1 1 2 203644 0) (2 1 3 3 654) (2 2 4 239 890) PASSED
[ 2.124005] Testing ftrace recursion: PASSED
[ 2.163703] Testing ftrace recursion safe: PASSED
[ 2.202408] Testing ftrace regs: PASSED
[ 2.264025] Testing tracer wakeup:
[ 2.696027] ftrace-test (24) used greatest stack depth: 7460 bytes left
[ 2.712025] PASSED
[ 2.724028] Testing tracer wakeup_rt: PASSED
[ 3.160020] Testing tracer wakeup_dl: PASSED
[ 3.621576] xor: measuring software checksum speed
[ 3.656949] pIII_sse : 161.000 MB/sec
[ 3.696928] prefetch64-sse: 111.000 MB/sec
[ 3.698537] xor: using function: pIII_sse (161.000 MB/sec)
[ 3.700034] atomic64_test: passed for i586+ platform with CX8 and with SSE
[ 3.702212] regulator-dummy: no parameters
[ 3.703829] RTC time: 11:59:29, date: 11/10/14
[ 3.708234] NET: Registered protocol family 16
[ 3.708804] EISA bus registered
[ 3.716031] cpuidle: using governor ladder
[ 3.720017] cpuidle: using governor menu
[ 3.720017] ACPI: bus type PCI registered
[ 3.720080] PCI: Using configuration type 1 for base access
[ 3.741820] Running resizable hashtable tests...
[ 3.741820] Adding 2048 keys
[ 3.848028] Traversal complete: counted=2048, nelems=2048, entries=2048
[ 3.848028] Table expansion iteration 0...
[ 3.868027] Verifying lookups...
[ 3.868027] Table expansion iteration 1...
[ 3.880030] Verifying lookups...
[ 3.880030] Table expansion iteration 2...
[ 3.892023] Verifying lookups...
[ 3.892023] Table expansion iteration 3...
[ 3.908018] Verifying lookups...
[ 3.908018] Table shrinkage iteration 0...
[ 3.916020] Verifying lookups...
[ 3.916020] Table shrinkage iteration 1...
[ 3.920017] Verifying lookups...
[ 3.920017] Table shrinkage iteration 2...
[ 3.928026] Verifying lookups...
[ 3.928026] Table shrinkage iteration 3...
[ 3.932021] Verifying lookups...
[ 3.932021] Deleting 2048 keys
[ 4.036925] raid6: mmxx1 3591 MB/s
[ 4.104903] raid6: mmxx2 3312 MB/s
[ 4.172916] raid6: sse1x1 2615 MB/s
[ 4.241128] raid6: sse1x2 3481 MB/s
[ 4.308906] raid6: sse2x1 6226 MB/s
[ 4.376910] raid6: sse2x2 9661 MB/s
[ 4.377840] raid6: using algorithm sse2x2 (9661 MB/s)
[ 4.379122] raid6: using intx1 recovery algorithm
[ 4.380337] ACPI: Added _OSI(Module Device)
[ 4.381294] ACPI: Added _OSI(Processor Device)
[ 4.382342] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 4.383348] ACPI: Added _OSI(Processor Aggregator Device)
[ 4.384874] IOAPIC[0]: Set routing entry (0-9 -> 0x39 -> IRQ 9 Mode:1 Active:0 Dest:3)
[ 4.391140] ACPI: Interpreter enabled
[ 4.392020] ACPI: (supports S0 S4 S5)
[ 4.393155] ACPI: Using IOAPIC for interrupt routing
[ 4.394692] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[ 4.401801] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[ 4.403077] acpi PNP0A03:00: _OSC: OS supports [Segments MSI]
[ 4.404014] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[ 4.405635] PCI host bridge to bus 0000:00
[ 4.407070] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 4.408007] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7]
[ 4.409164] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff]
[ 4.410388] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff]
[ 4.412006] pci_bus 0000:00: root bus resource [mem 0x80000000-0xfebfffff]
[ 4.413270] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
[ 4.414881] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
[ 4.416731] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
[ 4.421234] pci 0000:00:01.1: reg 0x20: [io 0xc080-0xc08f]
[ 4.423704] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
[ 4.428006] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
[ 4.429455] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
[ 4.429455] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
[ 4.429588] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
[ 4.430987] pci 0000:00:01.3: quirk: [io 0xb000-0xb03f] claimed by PIIX4 ACPI
[ 4.436015] pci 0000:00:01.3: quirk: [io 0xb100-0xb10f] claimed by PIIX4 SMB
[ 4.437554] pci 0000:00:02.0: [1013:00b8] type 00 class 0x030000
[ 4.450962] pci 0000:00:02.0: reg 0x10: [mem 0xfc000000-0xfdffffff pref]
[ 4.450962] pci 0000:00:02.0: reg 0x14: [mem 0xfebf0000-0xfebf0fff]
[ 4.457111] pci 0000:00:02.0: reg 0x30: [mem 0xfebe0000-0xfebeffff pref]
[ 4.458834] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000
[ 4.460799] pci 0000:00:03.0: reg 0x10: [mem 0xfeba0000-0xfebbffff]
[ 4.462740] pci 0000:00:03.0: reg 0x14: [io 0xc000-0xc03f]
[ 4.467808] pci 0000:00:03.0: reg 0x30: [mem 0xfebc0000-0xfebdffff pref]
[ 4.472280] pci 0000:00:04.0: [1af4:1001] type 00 class 0x010000
[ 4.474255] pci 0000:00:04.0: reg 0x10: [io 0xc040-0xc07f]
[ 4.474255] pci 0000:00:04.0: reg 0x14: [mem 0xfebf1000-0xfebf1fff]
[ 4.478674] pci 0000:00:05.0: [8086:25ab] type 00 class 0x088000
[ 4.480223] pci 0000:00:05.0: reg 0x10: [mem 0xfebf2000-0xfebf200f]
[ 4.484325] pci_bus 0000:00: on NUMA node 0
[ 4.485880] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[ 4.487407] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[ 4.488889] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[ 4.490439] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[ 4.491913] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[ 4.493182] ACPI: Enabled 16 GPEs in block 00 to 0F
[ 4.495115] vgaarb: setting as boot device: PCI:0000:00:02.0
[ 4.496000] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[ 4.500006] vgaarb: loaded
[ 4.500766] vgaarb: bridge control possible 0000:00:02.0
[ 4.503760] SCSI subsystem initialized
[ 4.503760] libata version 3.00 loaded.
[ 4.503760] Linux video capture interface: v2.00
[ 4.504051] pps_core: LinuxPPS API ver. 1 registered
[ 4.505342] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@xxxxxxxx>
[ 4.512019] wmi: Mapper loaded
[ 4.513796] PCI: Using ACPI for IRQ routing
[ 4.513796] PCI: pci_cache_line_size set to 32 bytes
[ 4.513826] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
[ 4.516014] e820: reserve RAM buffer [mem 0x13ffe000-0x13ffffff]
[ 4.520006] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[ 4.524256] Switched to clocksource kvm-clock
[ 4.526131] Warning: could not register annotated branches stats
[ 4.559035] FS-Cache: Loaded
[ 4.560427] CacheFiles: Loaded
[ 4.562180] pnp: PnP ACPI init
[ 4.563816] IOAPIC[0]: Set routing entry (0-8 -> 0x38 -> IRQ 8 Mode:0 Active:0 Dest:3)
[ 4.566909] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active)
[ 4.568812] IOAPIC[0]: Set routing entry (0-1 -> 0x31 -> IRQ 1 Mode:0 Active:0 Dest:3)
[ 4.571609] pnp 00:01: Plug and Play ACPI device, IDs PNP0303 (active)
[ 4.573666] IOAPIC[0]: Set routing entry (0-12 -> 0x3c -> IRQ 12 Mode:0 Active:0 Dest:3)
[ 4.576818] pnp 00:02: Plug and Play ACPI device, IDs PNP0f13 (active)
[ 4.579127] IOAPIC[0]: Set routing entry (0-6 -> 0x36 -> IRQ 6 Mode:0 Active:0 Dest:3)
[ 4.582124] pnp 00:03: [dma 2]
[ 4.583358] pnp 00:03: Plug and Play ACPI device, IDs PNP0700 (active)
[ 4.585380] IOAPIC[0]: Set routing entry (0-7 -> 0x37 -> IRQ 7 Mode:0 Active:0 Dest:3)
[ 4.588289] pnp 00:04: Plug and Play ACPI device, IDs PNP0400 (active)
[ 4.590145] IOAPIC[0]: Set routing entry (0-4 -> 0x34 -> IRQ 4 Mode:0 Active:0 Dest:3)
[ 4.593038] pnp 00:05: Plug and Play ACPI device, IDs PNP0501 (active)
[ 4.594796] IOAPIC[0]: Set routing entry (0-3 -> 0x33 -> IRQ 3 Mode:0 Active:0 Dest:3)
[ 4.597599] pnp 00:06: Plug and Play ACPI device, IDs PNP0501 (active)
[ 4.599736] pnp: PnP ACPI: found 7 devices
[ 4.601276] PnPBIOS: Disabled
[ 4.917312] mdacon: MDA with 8K of memory detected.
[ 4.917386] Console: switching consoles 13-16 to MDA-2
[ 4.954225] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7]
[ 4.955804] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff]
[ 4.957612] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff]
[ 4.959741] pci_bus 0000:00: resource 7 [mem 0x80000000-0xfebfffff]
[ 4.961113] NET: Registered protocol family 1
[ 4.962863] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 4.964522] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 4.966146] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 4.967835] pci 0000:00:02.0: Video device with shadowed ROM
[ 4.969488] PCI: CLS 0 bytes, default 32
[ 4.971366] Unpacking initramfs...
[ 5.210049] debug: unmapping init [mem 0xd3c0c000-0xd3feffff]
[ 5.214017] microcode: CPU0 sig=0x663, pf=0x1, revision=0x1
[ 5.215647] microcode: CPU1 sig=0x663, pf=0x1, revision=0x1
[ 5.218526] microcode: Microcode Update Driver: v2.00 <tigran@xxxxxxxxxxxxxxxxxxxx>, Peter Oruba
[ 5.221864] apm: BIOS not found.
[ 5.223636] cryptomgr_test (34) used greatest stack depth: 7432 bytes left
[ 5.226103] cryptomgr_test (35) used greatest stack depth: 7296 bytes left
[ 5.228896] PCLMULQDQ-NI instructions are not detected.
[ 5.230573] NatSemi SCx200 Driver
[ 5.232277] rcu-torture:--- Start of test: nreaders=1 nfakewriters=4 stat_interval=60 verbose=1 test_no_idle_hz=1 shuffle_interval=3 stutter=5 irqreader=1 fqs_duration=0 fqs_holdoff=0 fqs_stutter=3 test_boost=1/0 test_boost_interval=7 test_boost_duration=4 shutdown_secs=0 stall_cpu=0 stall_cpu_holdoff=10 n_barrier_cbs=0 onoff_interval=0 onoff_holdoff=0
[ 5.241658] rcu-torture: Creating rcu_torture_writer task
[ 5.243918] rcu-torture: Creating rcu_torture_fakewriter task
[ 5.245667] rcu-torture: rcu_torture_writer task started
[ 5.247958] rcu-torture: Creating rcu_torture_fakewriter task
[ 5.248002] rcu-torture: rcu_torture_fakewriter task started
[ 5.251828] rcu-torture: Creating rcu_torture_fakewriter task
[ 5.251842] rcu-torture: rcu_torture_fakewriter task started
[ 5.255646] rcu-torture: Creating rcu_torture_fakewriter task
[ 5.257727] rcu-torture: rcu_torture_fakewriter task started
[ 5.259552] rcu-torture: Creating rcu_torture_reader task
[ 5.259568] rcu-torture: rcu_torture_fakewriter task started
[ 5.263590] rcu-torture: Creating rcu_torture_stats task
[ 5.265307] rcu-torture: rcu_torture_reader task started
[ 5.267487] rcu-torture: Creating torture_shuffle task
[ 5.267505] rcu-torture: rcu_torture_stats task started
[ 5.270840] rcu-torture: Creating torture_stutter task
[ 5.272700] rcu-torture: torture_shuffle task started
[ 5.274441] rcu-torture: Creating rcu_torture_cbflood task
[ 5.274459] rcu-torture: torture_stutter task started
[ 5.278549] futex hash table entries: 512 (order: 3, 32768 bytes)
[ 5.280523] Initialise system trusted keyring
[ 5.282783] rcu-torture: rcu_torture_cbflood task started
[ 5.290307] zbud: loaded
[ 5.293817] JFS: nTxBlock = 2235, nTxLock = 17885
[ 5.298046] SGI XFS with ACLs, security attributes, no debug enabled
[ 5.301453] NILFS version 2 loaded
[ 5.304259] gfs2: GFS2 installed
[ 5.305547] msgmni has been set to 558
[ 5.306924] Key type big_key registered
[ 5.316663] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[ 5.319264] io scheduler noop registered
[ 5.320711] io scheduler deadline registered (default)
[ 5.322314] io scheduler cfq registered
[ 5.323792] start plist test
[ 5.330858] end plist test
[ 5.333436] xz_dec_test: module loaded
[ 5.334798] xz_dec_test: Create a device node with 'mknod xz_dec_test c 251 0' and write .xz files to it.
[ 5.338384] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[ 5.340039] cpcihp_generic: Generic port I/O CompactPCI Hot Plug Driver version: 0.1
[ 5.343014] cpcihp_generic: not configured, disabling.
[ 5.344762] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[ 5.346837] Console: switching consoles 13-16 to MDA-2
[ 5.348788] cr_bllcd: INTEL CARILLO RANCH LPC not found.
[ 5.350581] cr_bllcd: Carillo Ranch Backlight Driver Initialized.
[ 5.352802] VIA Graphics Integration Chipset framebuffer 2.4 initializing
[ 5.355111] vmlfb: initializing
[ 5.356493] Could not find Carillo Ranch MCH device.
[ 5.358330] hgafb: HGA card not detected.
[ 5.359742] hgafb: probe of hgafb.0 failed with error -22
[ 5.361820] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 5.364630] ACPI: Power Button [PWRF]
[ 5.366882] isapnp: Scanning for PnP cards...
[ 5.732135] isapnp: No Plug & Play device found
[ 5.734480] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 5.736075] IOAPIC[0]: Set routing entry (0-11 -> 0x3b -> IRQ 11 Mode:1 Active:0 Dest:3)
[ 5.752833] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 5.777202] serial 00:05: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 5.783747] Initializing Nozomi driver 2.1d
[ 5.785527] sonypi: Sony Programmable I/O Controller Driver v1.26.
[ 5.786767] toshiba: not a supported Toshiba laptop
[ 5.787842] scx200_gpio: no SCx200 gpio present
[ 5.788845] platform pc8736x_gpio.0: NatSemi pc8736x GPIO Driver Initializing
[ 5.790129] platform pc8736x_gpio.0: no device found
[ 5.791405] nsc_gpio initializing
[ 5.792347] Linux agpgart interface v0.103
[ 5.793568] SyncLink PC Card driver $Revision: 4.34 $, tty major#246
[ 5.795584] [drm] Initialized drm 1.1.0 20060810
[ 5.796981] [drm] radeon kernel modesetting enabled.
[ 5.798084] drm/i810 does not support SMP
[ 5.799887] [TTM] Zone kernel: Available graphics memory: 143084 kiB
[ 5.801332] [TTM] Initializing pool allocator
[ 5.804161] [drm] fb mappable at 0xFC000000
[ 5.805267] [drm] vram aper at 0xFC000000
[ 5.806461] [drm] size 4194304
[ 5.807369] [drm] fb depth is 24
[ 5.808574] [drm] pitch is 3072
[ 5.810055] fbcon: cirrusdrmfb (fb0) is primary device
[ 5.851820] Console: switching to colour frame buffer device 128x48
[ 5.867220] cirrus 0000:00:02.0: fb0: cirrusdrmfb frame buffer device
[ 5.867836] cirrus 0000:00:02.0: registered panic notifier
[ 5.872078] [drm] Initialized cirrus 1.0.0 20110418 for 0000:00:02.0 on minor 0
[ 5.873637] ibmasm: IBM ASM Service Processor Driver version 1.0 loaded
[ 5.874644] lkdtm: No crash points registered, enable through debugfs
[ 5.875565] Phantom Linux Driver, version n0.9.8, init OK
[ 5.876542] Silicon Labs C2 port support v. 0.51.0 - (C) 2007 Rodolfo Giometti
[ 5.878402] osst :I: Tape driver with OnStream support version 0.99.4
[ 5.878402] osst :I: $Id: osst.c,v 1.73 2005/01/01 21:13:34 wriede Exp $
[ 5.880311] SCSI Media Changer driver v0.25
[ 5.881551] Rounding down aligned max_sectors from 4294967295 to 4294967288
[ 5.883042] I2O subsystem v1.325
[ 5.883502] i2o: max drivers = 8
[ 5.884614] I2O Block Device OSM v1.325
[ 5.885526] I2O SCSI Peripheral OSM v1.316
[ 5.886129] I2O ProcFS OSM v1.316
[ 5.886624] Fusion MPT base driver 3.04.20
[ 5.887196] Copyright (c) 1999-2008 LSI Corporation
[ 5.887880] Fusion MPT SPI Host driver 3.04.20
[ 5.888547] Fusion MPT misc device (ioctl) driver 3.04.20
[ 5.889330] mptctl: Registered with Fusion MPT base driver
[ 5.890115] mptctl: /dev/mptctl @ (major,minor=10,220)
[ 5.894619] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 5.899323] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 5.903028] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 5.969867] mousedev: PS/2 mouse device common for all mice
[ 5.973998] evbug: Connected device: input0 (Power Button at LNXPWRBN/button/input0)
[ 5.978320] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 5.982312] evbug: Connected device: input1 (AT Translated Set 2 keyboard at isa0060/serio0/input0)
[ 5.985224] apanel: Fujitsu BIOS signature 'FJKEYINF' not found...
[ 5.985681] wistron_btns: System unknown
[ 5.985713] ideapad_slidebar: DMI does not match
[ 5.986007] rtc_cmos 00:00: RTC can wake from S4
[ 5.986829] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
[ 5.987127] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram, hpet irqs
[ 5.988075] rtc (null): invalid alarm value: 1900-1-10 0:0:0
[ 5.988125] rtc-test rtc-test.0: rtc core: registered test as rtc1
[ 5.988206] rtc (null): invalid alarm value: 1900-1-10 0:0:0
[ 5.988240] rtc-test rtc-test.1: rtc core: registered test as rtc2
[ 5.988684] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0xb100, revision 0
[ 6.004473] i2c-parport-light: adapter type unspecified
[ 6.004555] isa i2c-pca-isa.0: Please specify I/O base
[ 6.005593] pps_ldisc: PPS line discipline registered
[ 6.212087] tsc: Refined TSC clocksource calibration: 2693.505 MHz
[ 6.850220] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
[ 6.857676] evbug: Connected device: input3 (ImExPS/2 Generic Explorer Mouse at isa0060/serio1/input0)
[ 7.148165] applesmc: supported laptop not found!
[ 7.153100] applesmc: driver init failed (ret=-19)!
[ 7.368111] kpnpbiosd (112) used greatest stack depth: 7144 bytes left
[ 14.536419] intel_powerclamp: Intel powerclamp does not run on family 6 model 6
[ 14.541104] lguest: switcher text too large (4384)
[ 14.544751] cpufreq-nforce2: No nForce2 chipset.
[ 14.548300] wbsd: Winbond W83L51xD SD/MMC card interface driver
[ 14.551966] wbsd: Copyright(c) Pierre Ossman
[ 14.557754] leds_ss4200: no LED devices found
[ 17.756083] (null): enodev DEV ADDR = 0xFF
[ 17.760090] ledtrig-cpu: registered to indicate activity on CPUs
[ 17.764632] cs5535-clockevt: Could not allocate MFGPT timer
[ 17.769936] hidraw: raw HID events driver (C) Jiri Kosina
[ 17.775017] Initializing Realtek PCIE storage driver...
[ 17.779387] input: Speakup as /devices/virtual/input/input4
[ 17.783643] evbug: Connected device: input4 (Speakup at speakup/input0)
[ 17.787766] initialized device: /dev/synth, node (MAJOR 10, MINOR 25)
[ 17.792042] speakup 3.1.6: initialized
[ 17.797309] synth name on entry is: (null)
[ 17.801540] ashmem: initialized
[ 17.805561] logger: created 256K log 'log_main'
[ 17.809829] logger: created 256K log 'log_events'
[ 17.814150] logger: created 256K log 'log_radio'
[ 17.818024] logger: created 256K log 'log_system'
[ 17.821855] dgap: dgap-1.3-16, Digi International Part Number 40002347_C
[ 17.825857] dgap: For the tools package please visit http://www.digi.com
[ 17.829927] FPGA DOWNLOAD --->
[ 17.833563] FPGA image file name: xlinx_fpga_firmware.bit
[ 17.837578] GPIO INIT FAIL!!
[ 17.842384] hdaps: supported laptop not found!
[ 17.845907] hdaps: driver init failed (ret=-19)!
[ 17.850671] fake-fmc-carrier: mezzanine 0
[ 17.854040] Manufacturer: fake-vendor
[ 17.857386] Product name: fake-design-for-testing
[ 17.861022] fmc fake-design-for-testing-f001: Driver has no ID: matches all
[ 17.864877] fmc_trivial: probe of fake-design-for-testing-f001 failed with error -95
[ 17.868781] fmc fake-design-for-testing-f001: Driver has no ID: matches all
[ 17.872683] fmc_write_eeprom fake-design-for-testing-f001: fmc_write_eeprom: no busid passed, refusing all cards
[ 17.876976] fmc fake-design-for-testing-f001: Driver has no ID: matches all
[ 17.881026] fmc_chardev fake-design-for-testing-f001: Created misc device "fake-design-for-testing-f001"
[ 17.886357]
[ 17.886357] printing PIC contents
[ 17.893282] ... PIC IMR: ffff
[ 17.896651] ... PIC IRR: 1113
[ 17.900149] ... PIC ISR: 0000
[ 17.905390] ... PIC ELCR: 0c00
[ 17.908742] printing local APIC contents on CPU#0/0:
[ 17.912025] ... APIC ID: 00000000 (0)
[ 17.912025] ... APIC VERSION: 00050014
[ 17.912025] ... APIC TASKPRI: 00000000 (00)
[ 17.912025] ... APIC PROCPRI: 00000000
[ 17.912025] ... APIC LDR: 01000000
[ 17.912025] ... APIC DFR: ffffffff
[ 17.912025] ... APIC SPIV: 000001ff
[ 17.912025] ... APIC ISR field:
[ 17.912025] 0000000000000000000000000000000000000000000000000000000000000000
[ 17.912025] ... APIC TMR field:
[ 17.912025] 0000000002000000000000000000000000000000000000000000000000000000
[ 17.912025] ... APIC IRR field:
[ 17.912025] 0000000000000000000000000000000000000000000000000000000000008000
[ 17.912025] ... APIC ESR: 00000000
[ 17.912025] ... APIC ICR: 000008fd
[ 17.912025] ... APIC ICR2: 02000000
[ 17.912025] ... APIC LVTT: 000000ef
[ 17.912025] ... APIC LVTPC: 00010000
[ 17.912025] ... APIC LVT0: 00010700
[ 17.912025] ... APIC LVT1: 00000400
[ 17.912025] ... APIC LVTERR: 000000fe
[ 17.912025] ... APIC TMICT: 0003c9b6
[ 17.912025] ... APIC TMCCT: 00000000
[ 17.912025] ... APIC TDCR: 00000003
[ 17.912025]
[ 17.990029] number of MP IRQ sources: 15.
[ 17.992727] number of IO-APIC #0 registers: 24.
[ 17.995311] testing the IO APIC.......................
[ 17.998077] IO APIC #0......
[ 18.000469] .... register #00: 00000000
[ 18.002932] ....... : physical APIC id: 00
[ 18.005568] ....... : Delivery Type: 0
[ 18.008044] ....... : LTS : 0
[ 18.010506] .... register #01: 00170011
[ 18.012939] ....... : max redirection entries: 17
[ 18.015516] ....... : PRQ implemented: 0
[ 18.017958] ....... : IO APIC version: 11
[ 18.020480] .... register #02: 00000000
[ 18.022708] ....... : arbitration: 00
[ 18.024913] .... IRQ redirection table:
[ 18.027063] 1 0 0 0 0 0 0 00
[ 18.029235] 0 0 0 0 0 1 1 31
[ 18.031378] 0 0 0 0 0 1 1 30
[ 18.033513] 0 0 0 0 0 1 1 33
[ 18.035650] 1 0 0 0 0 1 1 34
[ 18.037780] 1 1 0 0 0 1 1 35
[ 18.039855] 0 0 0 0 0 1 1 36
[ 18.041921] 0 0 0 0 0 1 1 37
[ 18.043924] 0 0 0 0 0 1 1 38
[ 18.045955] 0 1 0 0 0 1 1 39
[ 18.047917] 1 1 0 0 0 1 1 3A
[ 18.050006] 1 1 0 0 0 1 1 3B
[ 18.051945] 0 0 0 0 0 1 1 3C
[ 18.053864] 0 0 0 0 0 1 1 3D
[ 18.055738] 0 0 0 0 0 1 1 3E
[ 18.057615] 0 0 0 0 0 1 1 3F
[ 18.059411] 1 0 0 0 0 0 0 00
[ 18.061192] 1 0 0 0 0 0 0 00
[ 18.062875] 1 0 0 0 0 0 0 00
[ 18.064531] 1 0 0 0 0 0 0 00
[ 18.066101] 1 0 0 0 0 0 0 00
[ 18.067678] 1 0 0 0 0 0 0 00
[ 18.069302] 1 0 0 0 0 0 0 00
[ 18.070903] 1 0 0 0 0 0 0 00
[ 18.072509] IRQ to pin mappings:
[ 18.073938] IRQ0 -> 0:2
[ 18.075329] IRQ1 -> 0:1
[ 18.076683] IRQ3 -> 0:3
[ 18.077992] IRQ4 -> 0:4
[ 18.079394] IRQ5 -> 0:5
[ 18.080794] IRQ6 -> 0:6
[ 18.082166] IRQ7 -> 0:7
[ 18.083511] IRQ8 -> 0:8
[ 18.084820] IRQ9 -> 0:9
[ 18.086058] IRQ10 -> 0:10
[ 18.087287] IRQ11 -> 0:11
[ 18.088499] IRQ12 -> 0:12
[ 18.089653] IRQ13 -> 0:13
[ 18.090785] IRQ14 -> 0:14
[ 18.091890] IRQ15 -> 0:15
[ 18.093012] .................................... done.
[ 18.094421] Using IPI No-Shortcut mode
[ 18.095943] Loading compiled-in X.509 certificates
[ 18.097541] Running ring buffer tests...
[ 28.100143] finished
[ 28.101234] CPU 0:
[ 28.101992] events: 459860
[ 28.102969] dropped bytes: 0
[ 28.103860] alloced bytes: 35804532
[ 28.105260] written bytes: 35125202
[ 28.106844] biggest event: 178
[ 28.108286] smallest event: 4
[ 28.115678] read events: 12448
[ 28.117225] lost events: 447412
[ 28.118709] total events: 459860
[ 28.120217] recorded len bytes: 970456
[ 28.121746] recorded size bytes: 951973
[ 28.123283] With dropped events, record len and size may not match
[ 28.123283] alloced and written from above
[ 28.126859] CPU 1:
[ 28.128255] events: 61588
[ 28.129957] dropped bytes: 0
[ 28.131607] alloced bytes: 4794252
[ 28.133373] written bytes: 4703161
[ 28.135114] biggest event: 213
[ 28.136807] smallest event: 4
[ 28.141969] read events: 11744
[ 28.143758] lost events: 49844
[ 28.145071] total events: 61588
[ 28.146394] recorded len bytes: 975928
[ 28.147764] recorded size bytes: 958826
[ 28.149071] With dropped events, record len and size may not match
[ 28.149071] alloced and written from above
[ 28.151867] Ring buffer PASSED!
[ 28.154415] Running tests on trace events:
[ 28.156180] Testing event thermal_apic_exit:
[ 28.172111] test-events (130) used greatest stack depth: 6968 bytes left
[ 28.175843] OK
[ 28.177145] Testing event thermal_apic_entry: OK
[ 28.193628] Testing event threshold_apic_exit: OK
[ 28.209702] Testing event threshold_apic_entry: OK
[ 28.226084] Testing event call_function_single_exit: OK
[ 28.242447] Testing event call_function_single_entry: OK
[ 28.262646] Testing event call_function_exit: OK
[ 28.278226] Testing event call_function_entry: OK
[ 28.293838] Testing event irq_work_exit: OK
[ 28.309945] Testing event irq_work_entry: OK
[ 28.326785] Testing event x86_platform_ipi_exit: OK
[ 28.342200] Testing event x86_platform_ipi_entry: OK
[ 28.358119] Testing event error_apic_exit: OK
[ 28.374107] Testing event error_apic_entry: OK
[ 28.390169] Testing event spurious_apic_exit: OK
[ 28.410178] Testing event spurious_apic_entry: OK
[ 28.427607] Testing event reschedule_exit: OK
[ 28.450309] Testing event reschedule_entry: OK
[ 28.470247] Testing event local_timer_exit: OK
[ 28.491109] Testing event local_timer_entry: OK
[ 28.511202] Testing event nmi_handler: OK
[ 28.530229] Testing event sys_exit: OK
[ 28.546335] Testing event sys_enter: OK
[ 28.562129] Testing event tlb_flush: OK
[ 28.578860] Testing event page_fault_kernel: OK
[ 28.594083] Testing event page_fault_user: OK
[ 28.610084] Testing event task_rename: OK
[ 28.630064] Testing event task_newtask: OK
[ 28.646779] Testing event softirq_raise: OK
[ 28.666423] Testing event softirq_exit: OK
[ 28.682057] Testing event softirq_entry: OK
[ 28.698073] Testing event irq_handler_exit: OK
[ 28.714244] Testing event irq_handler_entry: OK
[ 28.734653] Testing event signal_deliver: OK
[ 28.754259] Testing event signal_generate: OK
[ 28.772062] Testing event workqueue_execute_end: OK
[ 28.790397] Testing event workqueue_execute_start: OK
[ 28.806350] Testing event workqueue_activate_work: OK
[ 28.822359] Testing event workqueue_queue_work: OK
[ 28.838257] Testing event sched_wake_idle_without_ipi: OK
[ 28.854798] Testing event sched_swap_numa: OK
[ 28.870330] Testing event sched_stick_numa: OK
[ 28.890537] Testing event sched_move_numa: OK
[ 28.906255] Testing event sched_pi_setprio: OK
[ 28.922139] Testing event sched_stat_runtime:
[ 28.936147] test-events (175) used greatest stack depth: 6952 bytes left
[ 28.940505] OK
[ 28.942208] Testing event sched_stat_blocked: OK
[ 28.962082] Testing event sched_stat_iowait: OK
[ 28.978200] Testing event sched_stat_sleep: OK
[ 28.994522] Testing event sched_stat_wait: OK
[ 29.010213] Testing event sched_process_exec: OK
[ 29.026149] Testing event sched_process_fork: OK
[ 29.042031] Testing event sched_process_wait: OK
[ 29.058165] Testing event sched_wait_task: OK
[ 29.073559] Testing event sched_process_exit: OK
[ 29.089674] Testing event sched_process_free: OK
[ 29.106927] Testing event sched_migrate_task: OK
[ 29.125639] Testing event sched_switch: OK
[ 29.141874] Testing event sched_wakeup_new: OK
[ 29.161826] Testing event sched_wakeup: OK
[ 29.181966] Testing event sched_kthread_stop_ret: OK
[ 29.199482] Testing event sched_kthread_stop: OK
[ 29.221588] Testing event lock_acquired: OK
[ 29.243218] Testing event lock_contended: OK
[ 29.261868] Testing event lock_release: OK
[ 29.280083] Testing event lock_acquire:
[ 29.281153] test-events (194) used greatest stack depth: 6940 bytes left
[ 29.300152] test-events (195) used greatest stack depth: 6900 bytes left
[ 29.304691] OK
[ 29.306694] Testing event console: OK
[ 29.321614] Testing event rcu_utilization: OK
[ 29.338219] Testing event itimer_expire: OK
[ 29.353888] Testing event itimer_state: OK
[ 29.369945] Testing event hrtimer_cancel: OK
[ 29.389923] Testing event hrtimer_expire_exit: OK
[ 29.406269] Testing event hrtimer_expire_entry: OK
[ 29.422844] Testing event hrtimer_start: OK
[ 29.441763] Testing event hrtimer_init: OK
[ 29.462460] Testing event timer_cancel: OK
[ 29.478107] Testing event timer_expire_exit: OK
[ 29.494136] Testing event timer_expire_entry: OK
[ 29.510277] Testing event timer_start: OK
[ 29.526726] Testing event timer_init: OK
[ 29.542176] Testing event ftrace_test_filter: OK
[ 29.557624] Testing event dev_pm_qos_remove_request: OK
[ 29.574280] Testing event dev_pm_qos_update_request: OK
[ 29.589725] Testing event dev_pm_qos_add_request: OK
[ 29.606431] Testing event pm_qos_update_flags: OK
[ 29.621795] Testing event pm_qos_update_target: OK
[ 29.637593] Testing event pm_qos_update_request_timeout: OK
[ 29.658227] Testing event pm_qos_remove_request: OK
[ 29.674145] Testing event pm_qos_update_request: OK
[ 29.690239] Testing event pm_qos_add_request: OK
[ 29.706104] Testing event power_domain_target: OK
[ 29.721956] Testing event clock_set_rate: OK
[ 29.737628] Testing event clock_disable: OK
[ 29.757798] Testing event clock_enable: OK
[ 29.773507] Testing event wakeup_source_deactivate: OK
[ 29.790063] Testing event wakeup_source_activate: OK
[ 29.806835] Testing event suspend_resume: OK
[ 29.828009] Testing event device_pm_callback_end: OK
[ 29.846150] Testing event device_pm_callback_start: OK
[ 29.861801] Testing event cpu_frequency: OK
[ 29.878656] Testing event pstate_sample: OK
[ 29.897991] Testing event cpu_idle: OK
[ 29.914297] Testing event mm_filemap_add_to_page_cache: OK
[ 29.937280] Testing event mm_filemap_delete_from_page_cache: OK
[ 29.957421] Testing event oom_score_adj_update: OK
[ 29.974315] Testing event mm_lru_activate: OK
[ 29.997063] Testing event mm_lru_insertion: OK
[ 30.020911] Testing event mm_vmscan_lru_shrink_inactive: OK
[ 30.039704] Testing event mm_vmscan_writepage: OK
[ 30.059666] Testing event mm_vmscan_memcg_isolate: OK
[ 30.078261] Testing event mm_vmscan_lru_isolate: OK
[ 30.098257] Testing event mm_shrink_slab_end: OK
[ 30.120240] Testing event mm_shrink_slab_start: OK
[ 30.137700] Testing event mm_vmscan_memcg_softlimit_reclaim_end: OK
[ 30.158781] Testing event mm_vmscan_memcg_reclaim_end: OK
[ 30.174448] Testing event mm_vmscan_direct_reclaim_end: OK
[ 30.190506] Testing event mm_vmscan_memcg_softlimit_reclaim_begin: OK
[ 30.210135] Testing event mm_vmscan_memcg_reclaim_begin: OK
[ 30.230239] Testing event mm_vmscan_direct_reclaim_begin: OK
[ 30.247679] Testing event mm_vmscan_wakeup_kswapd: OK
[ 30.270490] Testing event mm_vmscan_kswapd_wake: OK
[ 30.290355] Testing event mm_vmscan_kswapd_sleep: OK
[ 30.306461] Testing event mm_page_alloc_extfrag: OK
[ 30.322857] Testing event mm_page_pcpu_drain: OK
[ 30.342540] Testing event mm_page_alloc_zone_locked: OK
[ 30.362637] Testing event mm_page_alloc: OK
[ 30.382420] Testing event mm_page_free_batched: OK
[ 30.399057] Testing event mm_page_free: OK
[ 30.422580] Testing event kmem_cache_free: OK
[ 30.438398] Testing event kfree: OK
[ 30.454937] Testing event kmem_cache_alloc_node: OK
[ 30.478569] Testing event kmalloc_node: OK
[ 30.498420] Testing event kmem_cache_alloc: OK
[ 30.514213] Testing event kmalloc: OK
[ 30.532148] Testing event writeback_single_inode: OK
[ 30.550779] Testing event writeback_single_inode_start: OK
[ 30.571187] Testing event writeback_wait_iff_congested: OK
[ 30.590679] Testing event writeback_congestion_wait: OK
[ 30.610582] Testing event writeback_sb_inodes_requeue: OK
[ 30.630462] Testing event balance_dirty_pages: OK
[ 30.646415] Testing event bdi_dirty_ratelimit: OK
[ 30.662194] Testing event global_dirty_state: OK
[ 30.677999] Testing event writeback_queue_io: OK
[ 30.694071] Testing event wbc_writepage: OK
[ 30.710044] Testing event writeback_bdi_unregister: OK
[ 30.726437] Testing event writeback_bdi_register: OK
[ 30.742445] Testing event writeback_wake_background: OK
[ 30.757710] Testing event writeback_nowork: OK
[ 30.774312] Testing event writeback_pages_written: OK
[ 30.790896] Testing event writeback_wait: OK
[ 30.810268] Testing event writeback_written: OK
[ 30.827041] Testing event writeback_start: OK
[ 30.841876] Testing event writeback_exec: OK
[ 30.858173] Testing event writeback_queue: OK
[ 30.874222] Testing event writeback_write_inode: OK
[ 30.890437] Testing event writeback_write_inode_start: OK
[ 30.905824] Testing event writeback_dirty_inode: OK
[ 30.921723] Testing event writeback_dirty_inode_start: OK
[ 30.937818] Testing event writeback_dirty_page: OK
[ 30.954465] Testing event time_out_leases: OK
[ 30.970084] Testing event generic_delete_lease: OK
[ 30.986067] Testing event generic_add_lease: OK
[ 31.006603] Testing event break_lease_unblock: OK
[ 31.022575] Testing event break_lease_block: OK
[ 31.042815] Testing event break_lease_noblock: OK
[ 31.058328] Testing event ext3_load_inode: OK
[ 31.074277] Testing event ext3_get_blocks_exit: OK
[ 31.089917] Testing event ext3_get_blocks_enter: OK
[ 31.106464] Testing event ext3_truncate_exit: OK
[ 31.122379] Testing event ext3_truncate_enter: OK
[ 31.138229] Testing event ext3_unlink_exit: OK
[ 31.154266] Testing event ext3_unlink_enter: OK
[ 31.170266] Testing event ext3_direct_IO_exit: OK
[ 31.186114] Testing event ext3_direct_IO_enter: OK
[ 31.202028] Testing event ext3_read_block_bitmap: OK
[ 31.218207] Testing event ext3_forget: OK
[ 31.234240] Testing event ext3_reserved: OK
[ 31.250041] Testing event ext3_alloc_new_reservation: OK
[ 31.266336] Testing event ext3_discard_reservation: OK
[ 31.282195] Testing event ext3_rsv_window_add: OK
[ 31.298243] Testing event ext3_sync_fs: OK
[ 31.314090] Testing event ext3_sync_file_exit: OK
[ 31.334212] Testing event ext3_sync_file_enter: OK
[ 31.350129] Testing event ext3_free_blocks: OK
[ 31.366371] Testing event ext3_allocate_blocks: OK
[ 31.382234] Testing event ext3_request_blocks: OK
[ 31.398727] Testing event ext3_discard_blocks: OK
[ 31.418521] Testing event ext3_invalidatepage: OK
[ 31.434915] Testing event ext3_releasepage: OK
[ 31.450076] Testing event ext3_readpage: OK
[ 31.466097] Testing event ext3_journalled_writepage: OK
[ 31.482022] Testing event ext3_writeback_writepage: OK
[ 31.497990] Testing event ext3_ordered_writepage: OK
[ 31.514335] Testing event ext3_journalled_write_end: OK
[ 31.530239] Testing event ext3_writeback_write_end: OK
[ 31.546103] Testing event ext3_ordered_write_end: OK
[ 31.562252] Testing event ext3_write_begin: OK
[ 31.578270] Testing event ext3_mark_inode_dirty: OK
[ 31.594027] Testing event ext3_drop_inode: OK
[ 31.614320] Testing event ext3_evict_inode: OK
[ 31.629850] Testing event ext3_allocate_inode: OK
[ 31.646174] Testing event ext3_request_inode: OK
[ 31.662273] Testing event ext3_free_inode: OK
[ 31.678065] Testing event ext4_es_shrink: OK
[ 31.698947] Testing event ext4_collapse_range: OK
[ 31.718545] Testing event ext4_es_shrink_scan_exit: OK
[ 31.733706] Testing event ext4_es_shrink_scan_enter: OK
[ 31.750212] Testing event ext4_es_shrink_count: OK
[ 31.766334] Testing event ext4_es_lookup_extent_exit: OK
[ 31.782101] Testing event ext4_es_lookup_extent_enter: OK
[ 31.797879] Testing event ext4_es_find_delayed_extent_range_exit: OK
[ 31.813915] Testing event ext4_es_find_delayed_extent_range_enter: OK
[ 31.830006] Testing event ext4_es_remove_extent: OK
[ 31.846610] Testing event ext4_es_cache_extent: OK
[ 31.862259] Testing event ext4_es_insert_extent: OK
[ 31.878196] Testing event ext4_ext_remove_space_done: OK
[ 31.900560] Testing event ext4_ext_remove_space: OK
[ 31.918111] Testing event ext4_ext_rm_idx: OK
[ 31.935547] Testing event ext4_ext_rm_leaf: OK
[ 31.954410] Testing event ext4_remove_blocks: OK
[ 31.970141] Testing event ext4_ext_show_extent: OK
[ 31.986348] Testing event ext4_get_reserved_cluster_alloc: OK
[ 32.002432] Testing event ext4_find_delalloc_range: OK
[ 32.018001] Testing event ext4_ext_in_cache: OK
[ 32.034249] Testing event ext4_ext_put_in_cache: OK
[ 32.050210] Testing event ext4_get_implied_cluster_alloc_exit: OK
[ 32.066306] Testing event ext4_ext_handle_unwritten_extents: OK
[ 32.082115] Testing event ext4_trim_all_free: OK
[ 32.098427] Testing event ext4_trim_extent: OK
[ 32.114241] Testing event ext4_journal_start_reserved: OK
[ 32.130903] Testing event ext4_journal_start: OK
[ 32.150755] Testing event ext4_load_inode: OK
[ 32.166408] Testing event ext4_ext_load_extent: OK
[ 32.182134] Testing event ext4_ind_map_blocks_exit: OK
[ 32.198403] Testing event ext4_ext_map_blocks_exit: OK
[ 32.213767] Testing event ext4_ind_map_blocks_enter: OK
[ 32.229829] Testing event ext4_ext_map_blocks_enter: OK
[ 32.246797] Testing event ext4_ext_convert_to_initialized_fastpath: OK
[ 32.266297] Testing event ext4_ext_convert_to_initialized_enter: OK
[ 32.281971] Testing event ext4_truncate_exit: OK
[ 32.298248] Testing event ext4_truncate_enter: OK
[ 32.314223] Testing event ext4_unlink_exit: OK
[ 32.330658] Testing event ext4_unlink_enter: OK
[ 32.346226] Testing event ext4_fallocate_exit: OK
[ 32.362200] Testing event ext4_zero_range: OK
[ 32.378284] Testing event ext4_punch_hole: OK
[ 32.394313] Testing event ext4_fallocate_enter: OK
[ 32.410252] Testing event ext4_direct_IO_exit: OK
[ 32.426194] Testing event ext4_direct_IO_enter: OK
[ 32.442294] Testing event ext4_load_inode_bitmap: OK
[ 32.462129] Testing event ext4_read_block_bitmap_load: OK
[ 32.482198] Testing event ext4_mb_buddy_bitmap_load: OK
[ 32.497983] Testing event ext4_mb_bitmap_load: OK
[ 32.514138] Testing event ext4_da_release_space: OK
[ 32.530263] Testing event ext4_da_reserve_space: OK
[ 32.546979] Testing event ext4_da_update_reserve_space: OK
[ 32.567000] Testing event ext4_forget: OK
[ 32.586217] Testing event ext4_mballoc_free: OK
[ 32.602245] Testing event ext4_mballoc_discard: OK
[ 32.622574] Testing event ext4_mballoc_prealloc: OK
[ 32.639690] Testing event ext4_mballoc_alloc: OK
[ 32.658213] Testing event ext4_alloc_da_blocks: OK
[ 32.673922] Testing event ext4_sync_fs: OK
[ 32.690224] Testing event ext4_sync_file_exit: OK
[ 32.706293] Testing event ext4_sync_file_enter: OK
[ 32.721897] Testing event ext4_free_blocks: OK
[ 32.738124] Testing event ext4_allocate_blocks: OK
[ 32.754213] Testing event ext4_request_blocks: OK
[ 32.769871] Testing event ext4_mb_discard_preallocations: OK
[ 32.785662] Testing event ext4_discard_preallocations: OK
[ 32.801717] Testing event ext4_mb_release_group_pa: OK
[ 32.820639] Testing event ext4_mb_release_inode_pa: OK
[ 32.838315] Testing event ext4_mb_new_group_pa: OK
[ 32.858614] Testing event ext4_mb_new_inode_pa: OK
[ 32.874009] Testing event ext4_discard_blocks: OK
[ 32.894616] Testing event ext4_journalled_invalidatepage: OK
[ 32.913594] Testing event ext4_invalidatepage: OK
[ 32.934321] Testing event ext4_releasepage: OK
[ 32.949935] Testing event ext4_readpage: OK
[ 32.966237] Testing event ext4_writepage: OK
[ 32.982413] Testing event ext4_writepages_result: OK
[ 32.997703] Testing event ext4_da_write_pages_extent: OK
[ 33.013729] Testing event ext4_da_write_pages: OK
[ 33.029975] Testing event ext4_writepages: OK
[ 33.045782] Testing event ext4_da_write_end: OK
[ 33.066423] Testing event ext4_journalled_write_end: OK
[ 33.082508] Testing event ext4_write_end: OK
[ 33.102156] Testing event ext4_da_write_begin: OK
[ 33.117608] Testing event ext4_write_begin: OK
[ 33.133894] Testing event ext4_begin_ordered_truncate: OK
[ 33.150143] Testing event ext4_mark_inode_dirty: OK
[ 33.165686] Testing event ext4_drop_inode: OK
[ 33.181845] Testing event ext4_evict_inode: OK
[ 33.197613] Testing event ext4_allocate_inode: OK
[ 33.214119] Testing event ext4_request_inode: OK
[ 33.229818] Testing event ext4_free_inode: OK
[ 33.246198] Testing event journal_write_superblock: OK
[ 33.262351] Testing event jbd_cleanup_journal_tail: OK
[ 33.277727] Testing event jbd_do_submit_data: OK
[ 33.293839] Testing event jbd_end_commit: OK
[ 33.309790] Testing event jbd_drop_transaction: OK
[ 33.325937] Testing event jbd_commit_logging: OK
[ 33.342085] Testing event jbd_commit_flushing: OK
[ 33.361986] Testing event jbd_commit_locking: OK
[ 33.378031] Testing event jbd_start_commit: OK
[ 33.393906] Testing event jbd_checkpoint: OK
[ 33.409939] Testing event jbd2_lock_buffer_stall: OK
[ 33.430163] Testing event jbd2_write_superblock: OK
[ 33.446087] Testing event jbd2_update_log_tail: OK
[ 33.462332] Testing event jbd2_checkpoint_stats: OK
[ 33.481564] Testing event jbd2_run_stats: OK
[ 33.497924] Testing event jbd2_handle_stats: OK
[ 33.513801] Testing event jbd2_handle_extend: OK
[ 33.531167] Testing event jbd2_handle_start: OK
[ 33.554581] Testing event jbd2_submit_inode_data: OK
[ 33.572178] Testing event jbd2_end_commit: OK
[ 33.594887] Testing event jbd2_drop_transaction: OK
[ 33.610043] Testing event jbd2_commit_logging: OK
[ 33.629885] Testing event jbd2_commit_flushing: OK
[ 33.650107] Testing event jbd2_commit_locking: OK
[ 33.666195] Testing event jbd2_start_commit: OK
[ 33.681900] Testing event jbd2_checkpoint: OK
[ 33.698105] Testing event xfs_discard_busy: OK
[ 33.714218] Testing event xfs_discard_exclude: OK
[ 33.730092] Testing event xfs_discard_toosmall: OK
[ 33.754329] Testing event xfs_discard_extent: OK
[ 33.770106] Testing event xfs_log_recover_inode_skip: OK
[ 33.786007] Testing event xfs_log_recover_inode_cancel: OK
[ 33.802276] Testing event xfs_log_recover_inode_recover: OK
[ 33.818418] Testing event xfs_log_recover_buf_dquot_buf: OK
[ 33.834542] Testing event xfs_log_recover_buf_reg_buf: OK
[ 33.850989] Testing event xfs_log_recover_buf_inode_buf: OK
[ 33.870022] Testing event xfs_log_recover_buf_recover: OK
[ 33.886031] Testing event xfs_log_recover_buf_cancel_ref_inc: OK
[ 33.902169] Testing event xfs_log_recover_buf_cancel_add: OK
[ 33.918253] Testing event xfs_log_recover_buf_cancel: OK
[ 33.933911] Testing event xfs_log_recover_buf_not_cancel: OK
[ 33.949935] Testing event xfs_log_recover_item_recover: OK
[ 33.966435] Testing event xfs_log_recover_item_reorder_tail: OK
[ 33.982112] Testing event xfs_log_recover_item_reorder_head: OK
[ 34.002212] Testing event xfs_log_recover_item_add_cont: OK
[ 34.022234] Testing event xfs_log_recover_item_add: OK
[ 34.042755] Testing event xfs_swap_extent_after: OK
[ 34.057676] Testing event xfs_swap_extent_before: OK
[ 34.073797] Testing event xfs_dir2_leafn_moveents: OK
[ 34.090457] Testing event xfs_dir2_shrink_inode: OK
[ 34.105935] Testing event xfs_dir2_grow_inode: OK
[ 34.121837] Testing event xfs_dir2_leafn_remove: OK
[ 34.139116] Testing event xfs_dir2_leafn_add: OK
[ 34.157824] Testing event xfs_da_path_shift: OK
[ 34.173846] Testing event xfs_da_fixhashpath: OK
[ 34.190074] Testing event xfs_da_shrink_inode: OK
[ 34.205971] Testing event xfs_da_grow_inode: OK
[ 34.227686] Testing event xfs_da_swap_lastblock: OK
[ 34.245823] Testing event xfs_da_node_toosmall: OK
[ 34.269919] Testing event xfs_da_node_unbalance: OK
[ 34.285644] Testing event xfs_da_node_rebalance: OK
[ 34.301859] Testing event xfs_da_node_remove: OK
[ 34.317694] Testing event xfs_da_node_split: OK
[ 34.333715] Testing event xfs_da_node_create: OK
[ 34.349853] Testing event xfs_da_node_add: OK
[ 34.365726] Testing event xfs_da_root_join: OK
[ 34.381683] Testing event xfs_da_root_split: OK
[ 34.397758] Testing event xfs_da_unlink_forward: OK
[ 34.413765] Testing event xfs_da_unlink_back: OK
[ 34.433972] Testing event xfs_da_link_after: OK
[ 34.449507] Testing event xfs_da_link_before: OK
[ 34.465898] Testing event xfs_da_join: OK
[ 34.482302] Testing event xfs_da_split: OK
[ 34.501714] Testing event xfs_attr_rmtval_remove: OK
[ 34.517858] Testing event xfs_attr_rmtval_set: OK
[ 34.533702] Testing event xfs_attr_rmtval_get: OK
[ 34.550821] Testing event xfs_attr_refillstate: OK
[ 34.565999] Testing event xfs_attr_fillstate: OK
[ 34.582511] Testing event xfs_attr_node_removename: OK
[ 34.597863] Testing event xfs_attr_node_replace: OK
[ 34.613781] Testing event xfs_attr_node_lookup: OK
[ 34.629833] Testing event xfs_attr_node_get: OK
[ 34.645782] Testing event xfs_attr_node_addname: OK
[ 34.661725] Testing event xfs_attr_leaf_toosmall: OK
[ 34.677316] Testing event xfs_attr_leaf_unbalance: OK
[ 34.693774] Testing event xfs_attr_leaf_rebalance: OK
[ 34.709985] Testing event xfs_attr_leaf_to_node: OK
[ 34.726185] Testing event xfs_attr_leaf_to_sf: OK
[ 34.745565] Testing event xfs_attr_leaf_flipflags: OK
[ 34.761579] Testing event xfs_attr_leaf_setflag: OK
[ 34.777879] Testing event xfs_attr_leaf_clearflag: OK
[ 34.793702] Testing event xfs_attr_leaf_split_after: OK
[ 34.809943] Testing event xfs_attr_leaf_split_before: OK
[ 34.825637] Testing event xfs_attr_leaf_split: OK
[ 34.841455] Testing event xfs_attr_leaf_removename: OK
[ 34.857602] Testing event xfs_attr_leaf_remove: OK
[ 34.873506] Testing event xfs_attr_leaf_replace: OK
[ 34.889643] Testing event xfs_attr_leaf_lookup: OK
[ 34.905720] Testing event xfs_attr_leaf_get: OK
[ 34.921781] Testing event xfs_attr_leaf_compact: OK
[ 34.937658] Testing event xfs_attr_leaf_create: OK
[ 34.953813] Testing event xfs_attr_leaf_addname: OK
[ 34.973610] Testing event xfs_attr_leaf_add_work: OK
[ 34.990172] Testing event xfs_attr_leaf_add_new: OK
[ 35.005801] Testing event xfs_attr_leaf_add_old: OK
[ 35.021988] Testing event xfs_attr_leaf_add: OK
[ 35.037680] Testing event xfs_attr_sf_to_leaf: OK
[ 35.053569] Testing event xfs_attr_sf_removename: OK
[ 35.069174] Testing event xfs_attr_sf_remove: OK
[ 35.085878] Testing event xfs_attr_sf_lookup: OK
[ 35.101715] Testing event xfs_attr_sf_create: OK
[ 35.117296] Testing event xfs_attr_sf_addname: OK
[ 35.137305] Testing event xfs_attr_sf_add: OK
[ 35.157306] Testing event xfs_dir2_node_to_leaf: OK
[ 35.174200] Testing event xfs_dir2_node_removename: OK
[ 35.190211] Testing event xfs_dir2_node_replace: OK
[ 35.205802] Testing event xfs_dir2_node_lookup: OK
[ 35.221652] Testing event xfs_dir2_node_addname: OK
[ 35.237555] Testing event xfs_dir2_leaf_to_node: OK
[ 35.253930] Testing event xfs_dir2_leaf_to_block: OK
[ 35.269566] Testing event xfs_dir2_leaf_removename: OK
[ 35.285539] Testing event xfs_dir2_leaf_replace: OK
[ 35.301616] Testing event xfs_dir2_leaf_lookup: OK
[ 35.321673] Testing event xfs_dir2_leaf_addname: OK
[ 35.337695] Testing event xfs_dir2_block_to_leaf: OK
[ 35.353965] Testing event xfs_dir2_block_to_sf: OK
[ 35.369702] Testing event xfs_dir2_block_removename: OK
[ 35.385243] Testing event xfs_dir2_block_replace: OK
[ 35.405262] Testing event xfs_dir2_block_lookup: OK
[ 35.421278] Testing event xfs_dir2_block_addname: OK
[ 35.437684] Testing event xfs_dir2_sf_to_block: OK
[ 35.457932] Testing event xfs_dir2_sf_toino8: OK
[ 35.477791] Testing event xfs_dir2_sf_toino4: OK
[ 35.497643] Testing event xfs_dir2_sf_removename: OK
[ 35.517194] Testing event xfs_dir2_sf_replace: OK
[ 35.537148] Testing event xfs_dir2_sf_lookup: OK
[ 35.557175] Testing event xfs_dir2_sf_create: OK
[ 35.573427] Testing event xfs_dir2_sf_addname: OK
[ 35.589239] Testing event xfs_alloc_vextent_allfailed: OK
[ 35.605535] Testing event xfs_alloc_vextent_loopfailed: OK
[ 35.621385] Testing event xfs_alloc_vextent_noagbp: OK
[ 35.637197] Testing event xfs_alloc_vextent_nofix: OK
[ 35.653291] Testing event xfs_alloc_vextent_badargs: OK
[ 35.669161] Testing event xfs_alloc_small_error: OK
[ 35.685183] Testing event xfs_alloc_small_done: OK
[ 35.701218] Testing event xfs_alloc_small_notenough: OK
[ 35.717165] Testing event xfs_alloc_small_freelist: OK
[ 35.733100] Testing event xfs_alloc_size_busy: OK
[ 35.749271] Testing event xfs_alloc_size_error: OK
[ 35.765378] Testing event xfs_alloc_size_done: OK
[ 35.781306] Testing event xfs_alloc_size_nominleft: OK
[ 35.797317] Testing event xfs_alloc_size_noentry: OK
[ 35.813342] Testing event xfs_alloc_size_neither: OK
[ 35.829387] Testing event xfs_alloc_near_busy: OK
[ 35.845472] Testing event xfs_alloc_near_noentry: OK
[ 35.861266] Testing event xfs_alloc_near_error: OK
[ 35.877373] Testing event xfs_alloc_near_lesser: OK
[ 35.893697] Testing event xfs_alloc_near_greater: OK
[ 35.913863] Testing event xfs_alloc_near_first: OK
[ 35.929670] Testing event xfs_alloc_near_nominleft: OK
[ 35.946341] Testing event xfs_alloc_exact_error: OK
[ 35.961284] Testing event xfs_alloc_exact_notfound: OK
[ 35.977636] Testing event xfs_alloc_exact_done: OK
[ 35.993396] Testing event xfs_free_extent: OK
[ 36.009708] Testing event xfs_agf: OK
[ 36.025704] Testing event xfs_trans_commit_lsn: OK
[ 36.041267] Testing event xfs_extent_busy_trim: OK
[ 36.058099] Testing event xfs_extent_busy_clear: OK
[ 36.074033] Testing event xfs_extent_busy_reuse: OK
[ 36.089648] Testing event xfs_extent_busy_force: OK
[ 36.105595] Testing event xfs_extent_busy_enomem: OK
[ 36.121498] Testing event xfs_extent_busy: OK
[ 36.137522] Testing event xfs_bunmap: OK
[ 36.153508] Testing event xfs_pagecache_inval: OK
[ 36.169483] Testing event xfs_itruncate_extents_end: OK
[ 36.185522] Testing event xfs_itruncate_extents_start: OK
[ 36.201981] Testing event xfs_setfilesize: OK
[ 36.217969] Testing event xfs_get_blocks_notfound: OK
[ 36.233899] Testing event xfs_unwritten_convert: OK
[ 36.249669] Testing event xfs_delalloc_enospc: OK
[ 36.266658] Testing event xfs_get_blocks_alloc: OK
[ 36.285823] Testing event xfs_get_blocks_found: OK
[ 36.301798] Testing event xfs_map_blocks_alloc: OK
[ 36.317634] Testing event xfs_map_blocks_found: OK
[ 36.333763] Testing event xfs_invalidatepage: OK
[ 36.349659] Testing event xfs_releasepage: OK
[ 36.365808] Testing event xfs_writepage: OK
[ 36.381720] Testing event xfs_file_splice_read: OK
[ 36.397731] Testing event xfs_file_direct_write: OK
[ 36.413918] Testing event xfs_file_buffered_write: OK
[ 36.429733] Testing event xfs_file_read: OK
[ 36.446028] Testing event xfs_log_assign_tail_lsn: OK
[ 36.466090] Testing event xfs_ail_delete: OK
[ 36.481729] Testing event xfs_ail_move: OK
[ 36.497706] Testing event xfs_ail_insert: OK
[ 36.513824] Testing event xfs_ail_flushing: OK
[ 36.529738] Testing event xfs_ail_locked: OK
[ 36.545867] Testing event xfs_ail_pinned: OK
[ 36.561694] Testing event xfs_ail_push: OK
[ 36.577980] Testing event xfs_log_force: OK
[ 36.594417] Testing event xfs_log_ungrant_sub: OK
[ 36.609810] Testing event xfs_log_ungrant_exit: OK
[ 36.625809] Testing event xfs_log_ungrant_enter: OK
[ 36.641732] Testing event xfs_log_regrant_reserve_sub: OK
[ 36.658031] Testing event xfs_log_regrant_reserve_exit: OK
[ 36.674076] Testing event xfs_log_regrant_reserve_enter: OK
[ 36.689849] Testing event xfs_log_regrant_exit: OK
[ 36.705576] Testing event xfs_log_regrant: OK
[ 36.721681] Testing event xfs_log_reserve_exit: OK
[ 36.737388] Testing event xfs_log_reserve: OK
[ 36.753820] Testing event xfs_log_grant_wake_up: OK
[ 36.770081] Testing event xfs_log_grant_wake: OK
[ 36.790826] Testing event xfs_log_grant_sleep: OK
[ 36.810256] Testing event xfs_log_umount_write: OK
[ 36.825719] Testing event xfs_log_done_perm: OK
[ 36.841341] Testing event xfs_log_done_nonperm: OK
[ 36.857374] Testing event xfs_dqflush_done: OK
[ 36.873493] Testing event xfs_dqflush_force: OK
[ 36.893458] Testing event xfs_dqflush: OK
[ 36.909308] Testing event xfs_dqrele: OK
[ 36.925792] Testing event xfs_dqput_free: OK
[ 36.945673] Testing event xfs_dqput_wait: OK
[ 36.961267] Testing event xfs_dqput: OK
[ 36.977474] Testing event xfs_dqget_dup: OK
[ 36.993388] Testing event xfs_dqget_freeing: OK
[ 37.013453] Testing event xfs_dqget_miss: OK
[ 37.029262] Testing event xfs_dqget_hit: OK
[ 37.045177] Testing event xfs_dqread_fail: OK
[ 37.061194] Testing event xfs_dqread: OK
[ 37.081141] Testing event xfs_dqtobp_read: OK
[ 37.101285] Testing event xfs_dqalloc: OK
[ 37.117146] Testing event xfs_dqattach_get: OK
[ 37.133239] Testing event xfs_dqattach_found: OK
[ 37.149403] Testing event xfs_dqreclaim_done: OK
[ 37.165339] Testing event xfs_dqreclaim_busy: OK
[ 37.181364] Testing event xfs_dqreclaim_dirty: OK
[ 37.197239] Testing event xfs_dqreclaim_want: OK
[ 37.214034] Testing event xfs_dqadjust: OK
[ 37.229655] Testing event xfs_rename: OK
[ 37.245703] Testing event xfs_symlink: OK
[ 37.261511] Testing event xfs_create: OK
[ 37.277549] Testing event xfs_lookup: OK
[ 37.293513] Testing event xfs_link: OK
[ 37.309748] Testing event xfs_remove: OK
[ 37.325752] Testing event xfs_inode_unpin_nowait: OK
[ 37.341685] Testing event xfs_inode_unpin: OK
[ 37.357705] Testing event xfs_inode_pin: OK
[ 37.373769] Testing event xfs_irele: OK
[ 37.390849] Testing event xfs_ihold: OK
[ 37.405482] Testing event xfs_iomap_prealloc_size: OK
[ 37.421600] Testing event xfs_inode_free_eofblocks_invalid: OK
[ 37.438649] Testing event xfs_inode_clear_eofblocks_tag: OK
[ 37.453639] Testing event xfs_inode_set_eofblocks_tag: OK
[ 37.469875] Testing event xfs_dquot_dqdetach: OK
[ 37.485726] Testing event xfs_dquot_dqalloc: OK
[ 37.501547] Testing event xfs_update_time: OK
[ 37.517603] Testing event xfs_evict_inode: OK
[ 37.534496] Testing event xfs_destroy_inode: OK
[ 37.549652] Testing event xfs_file_fsync: OK
[ 37.565719] Testing event xfs_dir_fsync: OK
[ 37.581650] Testing event xfs_ioctl_setattr: OK
[ 37.597767] Testing event xfs_file_compat_ioctl: OK
[ 37.613837] Testing event xfs_file_ioctl: OK
[ 37.629712] Testing event xfs_vm_bmap: OK
[ 37.645883] Testing event xfs_get_acl: OK
[ 37.661855] Testing event xfs_readdir: OK
[ 37.677539] Testing event xfs_collapse_file_space: OK
[ 37.693786] Testing event xfs_zero_file_space: OK
[ 37.709964] Testing event xfs_free_file_space: OK
[ 37.725878] Testing event xfs_alloc_file_space: OK
[ 37.741762] Testing event xfs_inactive_symlink: OK
[ 37.757661] Testing event xfs_readlink: OK
[ 37.773606] Testing event xfs_setattr: OK
[ 37.789724] Testing event xfs_getattr: OK
[ 37.805855] Testing event xfs_iget_miss: OK
[ 37.821839] Testing event xfs_iget_hit: OK
[ 37.837783] Testing event xfs_iget_reclaim_fail: OK
[ 37.853834] Testing event xfs_iget_reclaim: OK
[ 37.869945] Testing event xfs_iget_skip: OK
[ 37.886049] Testing event xfs_iunlock: OK
[ 37.901786] Testing event xfs_ilock_demote: OK
[ 37.917839] Testing event xfs_ilock_nowait: OK
[ 37.934842] Testing event xfs_ilock: OK
[ 37.949763] Testing event xfs_filestream_pick: OK
[ 37.966080] Testing event xfs_filestream_scan: OK
[ 37.985738] Testing event xfs_filestream_lookup: OK
[ 38.001986] Testing event xfs_filestream_free: OK
[ 38.017808] Testing event xfs_trans_buf_ordered: OK
[ 38.033780] Testing event xfs_trans_binval: OK
[ 38.049786] Testing event xfs_trans_bhold_release: OK
[ 38.065767] Testing event xfs_trans_bhold: OK
[ 38.081814] Testing event xfs_trans_bjoin: OK
[ 38.097804] Testing event xfs_trans_brelse: OK
[ 38.117779] Testing event xfs_trans_log_buf: OK
[ 38.133862] Testing event xfs_trans_read_buf_recur: OK
[ 38.149904] Testing event xfs_trans_read_buf: OK
[ 38.165863] Testing event xfs_trans_getsb_recur: OK
[ 38.181778] Testing event xfs_trans_getsb: OK
[ 38.197762] Testing event xfs_trans_get_buf_recur: OK
[ 38.213684] Testing event xfs_trans_get_buf: OK
[ 38.229669] Testing event xfs_buf_item_push: OK
[ 38.245667] Testing event xfs_buf_item_committed: OK
[ 38.262296] Testing event xfs_buf_item_unlock_stale: OK
[ 38.277681] Testing event xfs_buf_item_unlock: OK
[ 38.293763] Testing event xfs_buf_item_unpin_stale: OK
[ 38.309720] Testing event xfs_buf_item_unpin: OK
[ 38.325358] Testing event xfs_buf_item_pin: OK
[ 38.341433] Testing event xfs_buf_item_ordered: OK
[ 38.357340] Testing event xfs_buf_item_format_stale: OK
[ 38.373231] Testing event xfs_buf_item_format_ordered: OK
[ 38.389528] Testing event xfs_buf_item_format: OK
[ 38.405740] Testing event xfs_buf_item_size_stale: OK
[ 38.421517] Testing event xfs_buf_item_size_ordered: OK
[ 38.438085] Testing event xfs_buf_item_size: OK
[ 38.454094] Testing event xfs_buf_ioerror: OK
[ 38.473986] Testing event xfs_buf_read: OK
[ 38.489503] Testing event xfs_buf_get: OK
[ 38.505620] Testing event xfs_buf_find: OK
[ 38.521567] Testing event xfs_inode_item_push: OK
[ 38.537313] Testing event xfs_reset_dqcounts: OK
[ 38.553302] Testing event xfs_da_btree_corrupt: OK
[ 38.569322] Testing event xfs_btree_corrupt: OK
[ 38.585871] Testing event xfs_trans_read_buf_shut: OK
[ 38.601581] Testing event xfs_trans_read_buf_io: OK
[ 38.617396] Testing event xfs_buf_wait_buftarg: OK
[ 38.633388] Testing event xfs_buf_error_relse: OK
[ 38.649531] Testing event xfs_buf_item_iodone_async: OK
[ 38.665398] Testing event xfs_buf_item_iodone: OK
[ 38.681403] Testing event xfs_buf_item_relse: OK
[ 38.697485] Testing event xfs_bdstrat_shut: OK
[ 38.713535] Testing event xfs_buf_get_uncached: OK
[ 38.729715] Testing event xfs_buf_delwri_split: OK
[ 38.745410] Testing event xfs_buf_delwri_queued: OK
[ 38.761332] Testing event xfs_buf_delwri_queue: OK
[ 38.777310] Testing event xfs_buf_iowait_done: OK
[ 38.793586] Testing event xfs_buf_iowait: OK
[ 38.809460] Testing event xfs_buf_unlock: OK
[ 38.825578] Testing event xfs_buf_trylock: OK
[ 38.841336] Testing event xfs_buf_lock_done: OK
[ 38.857308] Testing event xfs_buf_lock: OK
[ 38.873426] Testing event xfs_buf_bawrite: OK
[ 38.889395] Testing event xfs_buf_submit_wait: OK
[ 38.905429] Testing event xfs_buf_submit: OK
[ 38.922189] Testing event xfs_buf_iodone: OK
[ 38.937634] Testing event xfs_buf_rele: OK
[ 38.957411] Testing event xfs_buf_hold: OK
[ 38.973827] Testing event xfs_buf_free: OK
[ 38.989539] Testing event xfs_buf_init: OK
[ 39.005592] Testing event xfs_extlist: OK
[ 39.021561] Testing event xfs_bmap_post_update: OK
[ 39.043997] Testing event xfs_bmap_pre_update: OK
[ 39.063413] Testing event xfs_iext_remove: OK
[ 39.081682] Testing event xfs_iext_insert: OK
[ 39.097785] Testing event xfs_attr_list_node_descend: OK
[ 39.117399] Testing event xfs_ialloc_read_agi: OK
[ 39.133382] Testing event xfs_read_agi: OK
[ 39.149438] Testing event xfs_alloc_read_agf: OK
[ 39.165301] Testing event xfs_read_agf: OK
[ 39.181648] Testing event xfs_perag_clear_eofblocks: OK
[ 39.197885] Testing event xfs_perag_set_eofblocks: OK
[ 39.213445] Testing event xfs_perag_clear_reclaim: OK
[ 39.229775] Testing event xfs_perag_set_reclaim: OK
[ 39.245644] Testing event xfs_perag_put: OK
[ 39.261329] Testing event xfs_perag_get_tag: OK
[ 39.277750] Testing event xfs_perag_get: OK
[ 39.293450] Testing event xfs_attr_node_list: OK
[ 39.310338] Testing event xfs_attr_leaf_list: OK
[ 39.325673] Testing event xfs_attr_list_notfound: OK
[ 39.341283] Testing event xfs_attr_list_wrong_blk: OK
[ 39.357481] Testing event xfs_attr_list_add: OK
[ 39.373420] Testing event xfs_attr_list_full: OK
[ 39.389414] Testing event xfs_attr_list_leaf_end: OK
[ 39.405569] Testing event xfs_attr_list_leaf: OK
[ 39.421291] Testing event xfs_attr_list_sf_all: OK
[ 39.437936] Testing event xfs_attr_list_sf: OK
[ 39.453876] Testing event btrfs_qgroup_record_ref: OK
[ 39.469616] Testing event btrfs_qgroup_account: OK
[ 39.485701] Testing event btrfs_workqueue_destroy: OK
[ 39.501563] Testing event btrfs_workqueue_alloc: OK
[ 39.517659] Testing event btrfs_ordered_sched: OK
[ 39.533382] Testing event btrfs_all_work_done: OK
[ 39.549393] Testing event btrfs_work_sched: OK
[ 39.565233] Testing event btrfs_work_queued: OK
[ 39.582009] Testing event free_extent_state: OK
[ 39.597714] Testing event alloc_extent_state: OK
[ 39.613697] Testing event btrfs_setup_cluster: OK
[ 39.629821] Testing event btrfs_failed_cluster_setup: OK
[ 39.645692] Testing event btrfs_find_cluster: OK
[ 39.661700] Testing event btrfs_reserve_extent_cluster: OK
[ 39.677806] Testing event btrfs_reserve_extent: OK
[ 39.694281] Testing event find_free_extent: OK
[ 39.710042] Testing event btrfs_reserved_extent_free: OK
[ 39.725920] Testing event btrfs_reserved_extent_alloc: OK
[ 39.742010] Testing event btrfs_space_reservation: OK
[ 39.763699] Testing event btrfs_cow_block: OK
[ 39.781637] Testing event btrfs_chunk_free: OK
[ 39.798062] Testing event btrfs_chunk_alloc: OK
[ 39.817955] Testing event run_delayed_ref_head: OK
[ 39.833944] Testing event add_delayed_ref_head: OK
[ 39.849421] Testing event run_delayed_data_ref: OK
[ 39.865359] Testing event add_delayed_data_ref: OK
[ 39.881443] Testing event run_delayed_tree_ref: OK
[ 39.897380] Testing event add_delayed_tree_ref: OK
[ 39.913434] Testing event btrfs_sync_fs: OK
[ 39.929969] Testing event btrfs_sync_file: OK
[ 39.945644] Testing event btrfs_writepage_end_io_hook: OK
[ 39.961938] Testing event __extent_writepage: OK
[ 39.977712] Testing event btrfs_ordered_extent_put: OK
[ 39.993364] Testing event btrfs_ordered_extent_start: OK
[ 40.010136] Testing event btrfs_ordered_extent_remove: OK
[ 40.025831] Testing event btrfs_ordered_extent_add: OK
[ 40.042032] Testing event btrfs_get_extent: OK
[ 40.057453] Testing event btrfs_inode_evict: OK
[ 40.073435] Testing event btrfs_inode_request: OK
[ 40.089420] Testing event btrfs_inode_new: OK
[ 40.105389] Testing event btrfs_transaction_commit: OK
[ 40.121616] Testing event gfs2_rs: OK
[ 40.137563] Testing event gfs2_block_alloc: OK
[ 40.153703] Testing event gfs2_bmap: OK
[ 40.169511] Testing event gfs2_ail_flush: OK
[ 40.185395] Testing event gfs2_log_blocks: OK
[ 40.201802] Testing event gfs2_log_flush: OK
[ 40.217933] Testing event gfs2_pin: OK
[ 40.233897] Testing event gfs2_glock_lock_time: OK
[ 40.249737] Testing event gfs2_glock_queue: OK
[ 40.266435] Testing event gfs2_promote: OK
[ 40.281834] Testing event gfs2_demote_rq: OK
[ 40.297783] Testing event gfs2_glock_put: OK
[ 40.313769] Testing event gfs2_glock_state_change: OK
[ 40.329775] Testing event block_rq_remap: OK
[ 40.345702] Testing event block_bio_remap: OK
[ 40.362171] Testing event block_split: OK
[ 40.377681] Testing event block_unplug: OK
[ 40.393869] Testing event block_plug: OK
[ 40.409981] Testing event block_sleeprq: OK
[ 40.425945] Testing event block_getrq: OK
[ 40.441789] Testing event block_bio_queue: OK
[ 40.457824] Testing event block_bio_frontmerge: OK
[ 40.473775] Testing event block_bio_backmerge: OK
[ 40.489837] Testing event block_bio_complete: OK
[ 40.505672] Testing event block_bio_bounce: OK
[ 40.521637] Testing event block_rq_issue: OK
[ 40.537728] Testing event block_rq_insert: OK
[ 40.553763] Testing event block_rq_complete: OK
[ 40.569789] Testing event block_rq_requeue: OK
[ 40.585853] Testing event block_rq_abort: OK
[ 40.601654] Testing event block_dirty_buffer: OK
[ 40.617757] Testing event block_touch_buffer: OK
[ 40.633804] Testing event gpio_value: OK
[ 40.649929] Testing event gpio_direction: OK
[ 40.665936] Testing event regulator_set_voltage_complete: OK
[ 40.681710] Testing event regulator_set_voltage: OK
[ 40.697707] Testing event regulator_disable_complete: OK
[ 40.713771] Testing event regulator_disable: OK
[ 40.729858] Testing event regulator_enable_complete: OK
[ 40.745710] Testing event regulator_enable_delay: OK
[ 40.761655] Testing event regulator_enable: OK
[ 40.781788] Testing event urandom_read: OK
[ 40.797641] Testing event random_read: OK
[ 40.813719] Testing event extract_entropy_user: OK
[ 40.829705] Testing event extract_entropy: OK
[ 40.845625] Testing event get_random_bytes_arch: OK
[ 40.861295] Testing event get_random_bytes: OK
[ 40.877227] Testing event xfer_secondary_pool: OK
[ 40.893779] Testing event add_disk_randomness: OK
[ 40.909788] Testing event add_input_randomness: OK
[ 40.929996] Testing event debit_entropy: OK
[ 40.945864] Testing event push_to_pool: OK
[ 40.961828] Testing event credit_entropy_bits: OK
[ 40.977721] Testing event mix_pool_bytes_nolock: OK
[ 40.993835] Testing event mix_pool_bytes: OK
[ 41.015476] Testing event add_device_randomness: OK
[ 41.033911] Testing event drm_vblank_event_delivered: OK
[ 41.054095] Testing event drm_vblank_event_queued: OK
[ 41.070186] Testing event drm_vblank_event: OK
[ 41.086179] Testing event radeon_semaphore_wait: OK
[ 41.101744] Testing event radeon_semaphore_signale: OK
[ 41.117916] Testing event radeon_fence_wait_end: OK
[ 41.133767] Testing event radeon_fence_wait_begin: OK
[ 41.149780] Testing event radeon_fence_emit: OK
[ 41.165735] Testing event radeon_vm_flush: OK
[ 41.181761] Testing event radeon_vm_set_page: OK
[ 41.197774] Testing event radeon_vm_bo_update: OK
[ 41.213822] Testing event radeon_vm_grab_id: OK
[ 41.229877] Testing event radeon_cs: OK
[ 41.249806] Testing event radeon_bo_create: OK
[ 41.265975] Testing event regcache_drop_region: OK
[ 41.281891] Testing event regmap_async_complete_done: OK
[ 41.297776] Testing event regmap_async_complete_start: OK
[ 41.313821] Testing event regmap_async_io_complete: OK
[ 41.329951] Testing event regmap_async_write_start: OK
[ 41.345954] Testing event regmap_cache_bypass: OK
[ 41.361856] Testing event regmap_cache_only: OK
[ 41.377862] Testing event regcache_sync: OK
[ 41.394105] Testing event regmap_hw_write_done: OK
[ 41.410051] Testing event regmap_hw_write_start: OK
[ 41.429964] Testing event regmap_hw_read_done: OK
[ 41.445924] Testing event regmap_hw_read_start: OK
[ 41.465940] Testing event regmap_reg_read_cache: OK
[ 41.481820] Testing event regmap_reg_read: OK
[ 41.497818] Testing event regmap_reg_write: OK
[ 41.513822] Testing event fence_wait_end: OK
[ 41.530792] Testing event fence_wait_start: OK
[ 41.547232] Testing event fence_signaled: OK
[ 41.565906] Testing event fence_enable_signal: OK
[ 41.581905] Testing event fence_destroy: OK
[ 41.597767] Testing event fence_init: OK
[ 41.613758] Testing event fence_emit: OK
[ 41.629760] Testing event fence_annotate_wait_on: OK
[ 41.645709] Testing event scsi_eh_wakeup: OK
[ 41.661813] Testing event scsi_dispatch_cmd_timeout: OK
[ 41.677886] Testing event scsi_dispatch_cmd_done: OK
[ 41.693864] Testing event scsi_dispatch_cmd_error: OK
[ 41.709781] Testing event scsi_dispatch_cmd_start: OK
[ 41.725830] Testing event target_cmd_complete: OK
[ 41.742365] Testing event target_sequencer_start: OK
[ 41.757865] Testing event smbus_result: OK
[ 41.773717] Testing event smbus_reply: OK
[ 41.789993] Testing event smbus_read: OK
[ 41.805996] Testing event smbus_write: OK
[ 41.821754] Testing event i2c_result: OK
[ 41.837822] Testing event i2c_reply: OK
[ 41.853828] Testing event i2c_read: OK
[ 41.869996] Testing event i2c_write: OK
[ 41.885858] Testing event v4l2_qbuf: OK
[ 41.901751] Testing event v4l2_dqbuf: OK
[ 41.917701] Testing event thermal_zone_trip: OK
[ 41.934334] Testing event cdev_update: OK
[ 41.950648] Testing event thermal_temperature: OK
[ 41.965750] Testing event binder_return: OK
[ 41.987157] Testing event binder_command: OK
[ 42.005710] Testing event binder_update_page_range: OK
[ 42.021716] Testing event binder_transaction_failed_buffer_release: OK
[ 42.037538] Testing event binder_transaction_buffer_release: OK
[ 42.054159] Testing event binder_transaction_alloc_buf: OK
[ 42.069809] Testing event binder_transaction_fd: OK
[ 42.085756] Testing event binder_transaction_ref_to_ref: OK
[ 42.102527] Testing event binder_transaction_ref_to_node: OK
[ 42.117451] Testing event binder_transaction_node_to_ref: OK
[ 42.134102] Testing event binder_transaction_received: OK
[ 42.153790] Testing event binder_transaction: OK
[ 42.173783] Testing event binder_wait_for_work: OK
[ 42.190607] Testing event binder_read_done: OK
[ 42.205843] Testing event binder_write_done: OK
[ 42.221341] Testing event binder_ioctl_done: OK
[ 42.237193] Testing event binder_unlock: OK
[ 42.255033] Testing event binder_locked: OK
[ 42.274622] Testing event binder_lock: OK
[ 42.289853] Testing event binder_ioctl: OK
[ 42.306248] Testing event udp_fail_queue_rcv_skb: OK
[ 42.322256] Testing event sock_exceed_buf_limit: OK
[ 42.337966] Testing event sock_rcvqueue_full: OK
[ 42.354008] Testing event napi_poll: OK
[ 42.369772] Testing event netif_rx_ni_entry: OK
[ 42.386516] Testing event netif_rx_entry: OK
[ 42.401288] Testing event netif_receive_skb_entry: OK
[ 42.418649] Testing event napi_gro_receive_entry: OK
[ 42.433653] Testing event napi_gro_frags_entry: OK
[ 42.449444] Testing event netif_rx: OK
[ 42.465810] Testing event netif_receive_skb: OK
[ 42.481393] Testing event net_dev_queue: OK
[ 42.498219] Testing event net_dev_xmit: OK
[ 42.513900] Testing event net_dev_start_xmit: OK
[ 42.529849] Testing event skb_copy_datagram_iovec: OK
[ 42.545868] Testing event consume_skb: OK
[ 42.561767] Testing event kfree_skb: OK
[ 42.577899] Running tests on trace event systems:
[ 42.579685] Testing event system skb: OK
[ 42.599049] Testing event system net: OK
[ 42.619070] Testing event system napi: OK
[ 42.633887] Testing event system sock: OK
[ 42.649779] Testing event system udp: OK
[ 42.666269] Testing event system binder: OK
[ 42.689350] Testing event system thermal: OK
[ 42.706566] Testing event system v4l2: OK
[ 42.722569] Testing event system i2c: OK
[ 42.746451] Testing event system target: OK
[ 42.763363] Testing event system scsi: OK
[ 42.783517] Testing event system fence: OK
[ 42.803304] Testing event system regmap: OK
[ 42.826239] Testing event system radeon: OK
[ 42.847169] Testing event system drm: OK
[ 42.866075] Testing event system random: OK
[ 42.883576] Testing event system regulator: OK
[ 42.902514] Testing event system gpio: OK
[ 42.922341] Testing event system block: OK
[ 42.944762] Testing event system gfs2: OK
[ 42.968585] Testing event system btrfs: OK
[ 42.995876] Testing event system xfs: OK
[ 43.077215] Testing event system jbd2: OK
[ 43.096492] Testing event system jbd: OK
[ 43.115518] Testing event system ext4: OK
[ 43.151111] Testing event system ext3: OK
[ 43.173457] Testing event system filelock: OK
[ 43.190486] Testing event system writeback: OK
[ 43.211722] Testing event system kmem: OK
[ 43.230313] Testing event system vmscan: OK
[ 43.247545] Testing event system pagemap: OK
[ 43.265841] Testing event system oom: OK
[ 43.281788] Testing event system filemap: OK
[ 43.297764] Testing event system power: OK
[ 43.321934] Testing event system test: OK
[ 43.337853] Testing event system timer: OK
[ 43.360058] Testing event system rcu: OK
[ 43.380143] Testing event system printk: OK
[ 43.398835] Testing event system lock: OK
[ 43.418908] Testing event system sched:
[ 43.436154] test-events (1031) used greatest stack depth: 6712 bytes left
[ 43.441347] OK
[ 43.444090] Testing event system workqueue: OK
[ 43.462841] Testing event system signal: OK
[ 43.482160] Testing event system irq: OK
[ 43.498014] Testing event system task: OK
[ 43.514028] Testing event system exceptions: OK
[ 43.530448] Testing event system tlb: OK
[ 43.546923] Testing event system raw_syscalls: OK
[ 43.566277] Testing event system nmi: OK
[ 43.581993] Testing event system irq_vectors: OK
[ 43.603099] Running tests on all trace events:
[ 43.604758] Testing all events: OK
[ 44.006129] Running tests again, along with the function tracer
[ 44.010451] Running tests on trace events:
[ 44.014327] Testing event thermal_apic_exit:
[ 44.028678] test-events (1042) used greatest stack depth: 6680 bytes left
[ 44.039967] OK
[ 44.044796] Testing event thermal_apic_entry:
[ 44.060706] test-events (1043) used greatest stack depth: 6640 bytes left
[ 44.071902] OK
[ 44.075512] Testing event threshold_apic_exit: OK
[ 44.099112] Testing event threshold_apic_entry: OK
[ 44.123325] Testing event call_function_single_exit: OK
[ 44.146529] Testing event call_function_single_entry: OK
[ 44.174872] Testing event call_function_exit: OK
[ 44.203521] Testing event call_function_entry: OK
[ 44.228695] Testing event irq_work_exit: OK
[ 44.250316] Testing event irq_work_entry: OK
[ 44.275191] Testing event x86_platform_ipi_exit: OK
[ 44.299798] Testing event x86_platform_ipi_entry: OK
[ 44.329080] Testing event error_apic_exit: OK
[ 44.356582] Testing event error_apic_entry: OK
[ 44.378650] Testing event spurious_apic_exit: OK
[ 44.404742] Testing event spurious_apic_entry: OK
[ 44.427199] Testing event reschedule_exit: OK
[ 44.451108] Testing event reschedule_entry: OK
[ 44.474540] Testing event local_timer_exit: OK
[ 44.501192] Testing event local_timer_entry: OK
[ 44.531426] Testing event nmi_handler: OK
[ 44.555552] Testing event sys_exit: OK
[ 44.578570] Testing event sys_enter: OK
[ 44.606298] Testing event tlb_flush: OK
[ 44.635529] Testing event page_fault_kernel: OK
[ 44.659370] Testing event page_fault_user: OK
[ 44.683357] Testing event task_rename: OK
[ 44.707951] Testing event task_newtask: OK
[ 44.732402] Testing event softirq_raise: OK
[ 44.759468] Testing event softirq_exit: OK
[ 44.782243] Testing event softirq_entry: OK
[ 44.805282] Testing event irq_handler_exit: OK
[ 44.828927] Testing event irq_handler_entry: OK
[ 44.854563] Testing event signal_deliver: OK
[ 44.878602] Testing event signal_generate: OK
[ 44.904892] Testing event workqueue_execute_end: OK
[ 44.927939] Testing event workqueue_execute_start: OK
[ 44.950673] Testing event workqueue_activate_work: OK
[ 44.980952] Testing event workqueue_queue_work: OK
[ 45.009432] Testing event sched_wake_idle_without_ipi: OK
[ 45.036231] Testing event sched_swap_numa: OK
[ 45.059456] Testing event sched_stick_numa: OK
[ 45.082970] Testing event sched_move_numa: OK
[ 45.106859] Testing event sched_pi_setprio: OK
[ 45.132467] Testing event sched_stat_runtime: OK
[ 45.160936] Testing event sched_stat_blocked: OK
[ 45.183686] Testing event sched_stat_iowait: OK
[ 45.208874] Testing event sched_stat_sleep: OK
[ 45.231929] Testing event sched_stat_wait: OK
[ 45.255820] Testing event sched_process_exec: OK
[ 45.285050] Testing event sched_process_fork: OK
[ 45.306546] Testing event sched_process_wait: OK
[ 45.329582] Testing event sched_wait_task: OK
[ 45.350471] Testing event sched_process_exit: OK
[ 45.375529] Testing event sched_process_free: OK
[ 45.398308] Testing event sched_migrate_task: OK
[ 45.423795] Testing event sched_switch: OK
[ 45.445776] Testing event sched_wakeup_new: OK
[ 45.469493] Testing event sched_wakeup: OK
[ 45.491282] Testing event sched_kthread_stop_ret: OK
[ 45.515386] Testing event sched_kthread_stop: OK
[ 45.538038] Testing event lock_acquired: OK
[ 45.562096] Testing event lock_contended: OK
[ 45.590068] Testing event lock_release: OK
[ 45.614689] Testing event lock_acquire: OK
[ 45.639403] Testing event console: OK
[ 45.663013] Testing event rcu_utilization: OK
[ 45.692530] Testing event itimer_expire: OK
[ 45.722719] Testing event itimer_state:
[ 45.723709] test-events (1109) used greatest stack depth: 6636 bytes left
[ 45.759424] OK
[ 45.765544] Testing event hrtimer_cancel: OK
[ 45.791954] Testing event hrtimer_expire_exit: OK
[ 45.815621] Testing event hrtimer_expire_entry: OK
[ 45.839289] Testing event hrtimer_start: OK
[ 45.863212] Testing event hrtimer_init: OK
[ 45.890652] Testing event timer_cancel: OK
[ 45.915671] Testing event timer_expire_exit: OK
[ 45.937674] Testing event timer_expire_entry: OK
[ 45.958466] Testing event timer_start: OK
[ 45.986696] Testing event timer_init: OK
[ 46.010497] Testing event ftrace_test_filter: OK
[ 46.034761] Testing event dev_pm_qos_remove_request: OK
[ 46.059516] Testing event dev_pm_qos_update_request: OK
[ 46.083284] Testing event dev_pm_qos_add_request: OK
[ 46.104703] Testing event pm_qos_update_flags: OK
[ 46.124457] Testing event pm_qos_update_target: OK
[ 46.146407] Testing event pm_qos_update_request_timeout: OK
[ 46.170391] Testing event pm_qos_remove_request: OK
[ 46.194614] Testing event pm_qos_update_request: OK
[ 46.220562] Testing event pm_qos_add_request: OK
[ 46.246473] Testing event power_domain_target: OK
[ 46.273741] Testing event clock_set_rate: OK
[ 46.305829] Testing event clock_disable: OK
[ 46.330892] Testing event clock_enable: OK
[ 46.358148] Testing event wakeup_source_deactivate: OK
[ 46.381574] Testing event wakeup_source_activate: OK
[ 46.402127] Testing event suspend_resume: OK
[ 46.434513] Testing event device_pm_callback_end: OK
[ 46.458979] Testing event device_pm_callback_start: OK
[ 46.483328] Testing event cpu_frequency: OK
[ 46.506033] Testing event pstate_sample: OK
[ 46.537636] Testing event cpu_idle: OK
[ 46.565846] Testing event mm_filemap_add_to_page_cache: OK
[ 46.590583] Testing event mm_filemap_delete_from_page_cache: OK
[ 46.613783] Testing event oom_score_adj_update: OK
[ 46.635465] Testing event mm_lru_activate: OK
[ 46.658682] Testing event mm_lru_insertion: OK
[ 46.684177] Testing event mm_vmscan_lru_shrink_inactive: OK
[ 46.706881] Testing event mm_vmscan_writepage: OK
[ 46.731465] Testing event mm_vmscan_memcg_isolate: OK
[ 46.754810] Testing event mm_vmscan_lru_isolate: OK
[ 46.784490] Testing event mm_shrink_slab_end: OK
[ 46.807172] Testing event mm_shrink_slab_start: OK
[ 46.833676] Testing event mm_vmscan_memcg_softlimit_reclaim_end: OK
[ 46.854744] Testing event mm_vmscan_memcg_reclaim_end: OK
[ 46.878533] Testing event mm_vmscan_direct_reclaim_end: OK
[ 46.902849] Testing event mm_vmscan_memcg_softlimit_reclaim_begin: OK
[ 46.926545] Testing event mm_vmscan_memcg_reclaim_begin: OK
[ 46.951069] Testing event mm_vmscan_direct_reclaim_begin: OK
[ 46.975758] Testing event mm_vmscan_wakeup_kswapd: OK
[ 46.998965] Testing event mm_vmscan_kswapd_wake: OK
[ 47.022508] Testing event mm_vmscan_kswapd_sleep: OK
[ 47.046277] Testing event mm_page_alloc_extfrag: OK
[ 47.072043] Testing event mm_page_pcpu_drain: OK
[ 47.094960] Testing event mm_page_alloc_zone_locked: OK
[ 47.117710] Testing event mm_page_alloc: OK
[ 47.138921] Testing event mm_page_free_batched: OK
[ 47.162527] Testing event mm_page_free: OK
[ 47.188429] Testing event kmem_cache_free: OK
[ 47.211308] Testing event kfree: OK
[ 47.234938] Testing event kmem_cache_alloc_node: OK
[ 47.259579] Testing event kmalloc_node: OK
[ 47.287599] Testing event kmem_cache_alloc: OK
[ 47.318269] Testing event kmalloc: OK
[ 47.343331] Testing event writeback_single_inode: OK
[ 47.367797] Testing event writeback_single_inode_start: OK
[ 47.391426] Testing event writeback_wait_iff_congested: OK
[ 47.415928] Testing event writeback_congestion_wait: OK
[ 47.439172] Testing event writeback_sb_inodes_requeue: OK
[ 47.463035] Testing event balance_dirty_pages: OK
[ 47.491640] Testing event bdi_dirty_ratelimit: OK
[ 47.514435] Testing event global_dirty_state: OK
[ 47.540263] Testing event writeback_queue_io: OK
[ 47.563420] Testing event wbc_writepage: OK
[ 47.588188] Testing event writeback_bdi_unregister: OK
[ 47.611375] Testing event writeback_bdi_register: OK
[ 47.635112] Testing event writeback_wake_background: OK
[ 47.660837] Testing event writeback_nowork: OK
[ 47.684815] Testing event writeback_pages_written: OK
[ 47.706905] Testing event writeback_wait: OK
[ 47.731213] Testing event writeback_written: OK
[ 47.756275] Testing event writeback_start: OK
[ 47.779677] Testing event writeback_exec: OK
[ 47.804324] Testing event writeback_queue: OK
[ 47.827672] Testing event writeback_write_inode: OK
[ 47.851359] Testing event writeback_write_inode_start: OK
[ 47.875541] Testing event writeback_dirty_inode: OK
[ 47.899948] Testing event writeback_dirty_inode_start: OK
[ 47.924232] Testing event writeback_dirty_page: OK
[ 47.947106] Testing event time_out_leases: OK
[ 47.970787] Testing event generic_delete_lease: OK
[ 47.994420] Testing event generic_add_lease: OK
[ 48.018272] Testing event break_lease_unblock: OK
[ 48.043313] Testing event break_lease_block: OK
[ 48.066824] Testing event break_lease_noblock: OK
[ 48.090187] Testing event ext3_load_inode: OK
[ 48.114972] Testing event ext3_get_blocks_exit: OK
[ 48.140812] Testing event ext3_get_blocks_enter: OK
[ 48.167980] Testing event ext3_truncate_exit: OK
[ 48.194898] Testing event ext3_truncate_enter: OK
[ 48.220281] Testing event ext3_unlink_exit: OK
[ 48.243729] Testing event ext3_unlink_enter: OK
[ 48.267460] Testing event ext3_direct_IO_exit: OK
[ 48.291705] Testing event ext3_direct_IO_enter: OK
[ 48.314845] Testing event ext3_read_block_bitmap: OK
[ 48.338386] Testing event ext3_forget: OK
[ 48.363532] Testing event ext3_reserved: OK
[ 48.391252] Testing event ext3_alloc_new_reservation: OK
[ 48.413935] Testing event ext3_discard_reservation: OK
[ 48.438604] Testing event ext3_rsv_window_add: OK
[ 48.466895] Testing event ext3_sync_fs: OK
[ 48.490584] Testing event ext3_sync_file_exit: OK
[ 48.515070] Testing event ext3_sync_file_enter: OK
[ 48.539560] Testing event ext3_free_blocks: OK
[ 48.569214] Testing event ext3_allocate_blocks: OK
[ 48.589753] Testing event ext3_request_blocks: OK
[ 48.611809] Testing event ext3_discard_blocks: OK
[ 48.639597] Testing event ext3_invalidatepage: OK
[ 48.662664] Testing event ext3_releasepage: OK
[ 48.687953] Testing event ext3_readpage: OK
[ 48.711258] Testing event ext3_journalled_writepage: OK
[ 48.736972] Testing event ext3_writeback_writepage: OK
[ 48.761212] Testing event ext3_ordered_writepage: OK
[ 48.787187] Testing event ext3_journalled_write_end: OK
[ 48.810434] Testing event ext3_writeback_write_end: OK
[ 48.839301] Testing event ext3_ordered_write_end: OK
[ 48.862209] Testing event ext3_write_begin: OK
[ 48.892264] Testing event ext3_mark_inode_dirty: OK
[ 48.914651] Testing event ext3_drop_inode: OK
[ 48.938512] Testing event ext3_evict_inode: OK
[ 48.962285] Testing event ext3_allocate_inode: OK
[ 48.986301] Testing event ext3_request_inode: OK
[ 49.010747] Testing event ext3_free_inode: OK
[ 49.035074] Testing event ext4_es_shrink: OK
[ 49.060651] Testing event ext4_collapse_range: OK
[ 49.084408] Testing event ext4_es_shrink_scan_exit: OK
[ 49.113229] Testing event ext4_es_shrink_scan_enter: OK
[ 49.134413] Testing event ext4_es_shrink_count: OK
[ 49.158305] Testing event ext4_es_lookup_extent_exit: OK
[ 49.184214] Testing event ext4_es_lookup_extent_enter: OK
[ 49.207469] Testing event ext4_es_find_delayed_extent_range_exit: OK
[ 49.230419] Testing event ext4_es_find_delayed_extent_range_enter: OK
[ 49.254636] Testing event ext4_es_remove_extent: OK
[ 49.286206] Testing event ext4_es_cache_extent: OK
[ 49.314409] Testing event ext4_es_insert_extent: OK
[ 49.340404] Testing event ext4_ext_remove_space_done: OK
[ 49.362684] Testing event ext4_ext_remove_space: OK
[ 49.385978] Testing event ext4_ext_rm_idx: OK
[ 49.410945] Testing event ext4_ext_rm_leaf: OK
[ 49.439621] Testing event ext4_remove_blocks: OK
[ 49.465072] Testing event ext4_ext_show_extent: OK
[ 49.485969] Testing event ext4_get_reserved_cluster_alloc: OK
[ 49.509705] Testing event ext4_find_delalloc_range: OK
[ 49.534485] Testing event ext4_ext_in_cache: OK
[ 49.559880] Testing event ext4_ext_put_in_cache: OK
[ 49.582767] Testing event ext4_get_implied_cluster_alloc_exit: OK
[ 49.611463] Testing event ext4_ext_handle_unwritten_extents: OK
[ 49.634528] Testing event ext4_trim_all_free: OK
[ 49.659933] Testing event ext4_trim_extent: OK
[ 49.683928] Testing event ext4_journal_start_reserved: OK
[ 49.707288] Testing event ext4_journal_start: OK
[ 49.730897] Testing event ext4_load_inode: OK
[ 49.758641] Testing event ext4_ext_load_extent: OK
[ 49.786568] Testing event ext4_ind_map_blocks_exit: OK
[ 49.811018] Testing event ext4_ext_map_blocks_exit: OK
[ 49.835006] Testing event ext4_ind_map_blocks_enter: OK
[ 49.859533] Testing event ext4_ext_map_blocks_enter: OK
[ 49.880946] Testing event ext4_ext_convert_to_initialized_fastpath: OK
[ 49.907678] Testing event ext4_ext_convert_to_initialized_enter: OK
[ 49.931261] Testing event ext4_truncate_exit: OK
[ 49.954417] Testing event ext4_truncate_enter: OK
[ 49.983648] Testing event ext4_unlink_exit: OK
[ 50.007933] Testing event ext4_unlink_enter: OK
[ 50.031004] Testing event ext4_fallocate_exit: OK
[ 50.054478] Testing event ext4_zero_range: OK
[ 50.078687] Testing event ext4_punch_hole: OK
[ 50.103112] Testing event ext4_fallocate_enter: OK
[ 50.126334] Testing event ext4_direct_IO_exit: OK
[ 50.150522] Testing event ext4_direct_IO_enter: OK
[ 50.178485] Testing event ext4_load_inode_bitmap: OK
[ 50.203988] Testing event ext4_read_block_bitmap_load: OK
[ 50.228728] Testing event ext4_mb_buddy_bitmap_load: OK
[ 50.251689] Testing event ext4_mb_bitmap_load: OK
[ 50.275092] Testing event ext4_da_release_space: OK
[ 50.298889] Testing event ext4_da_reserve_space: OK
[ 50.322843] Testing event ext4_da_update_reserve_space: OK
[ 50.346858] Testing event ext4_forget: OK
[ 50.371060] Testing event ext4_mballoc_free: OK
[ 50.394794] Testing event ext4_mballoc_discard: OK
[ 50.422912] Testing event ext4_mballoc_prealloc: OK
[ 50.447607] Testing event ext4_mballoc_alloc: OK
[ 50.473019] Testing event ext4_alloc_da_blocks: OK
[ 50.497560] Testing event ext4_sync_fs: OK
[ 50.523368] Testing event ext4_sync_file_exit: OK
[ 50.548590] Testing event ext4_sync_file_enter: OK
[ 50.571225] Testing event ext4_free_blocks: OK
[ 50.595289] Testing event ext4_allocate_blocks: OK
[ 50.624362] Testing event ext4_request_blocks: OK
[ 50.648894] Testing event ext4_mb_discard_preallocations: OK
[ 50.670697] Testing event ext4_discard_preallocations: OK
[ 50.695016] Testing event ext4_mb_release_group_pa: OK
[ 50.719202] Testing event ext4_mb_release_inode_pa: OK
[ 50.743117] Testing event ext4_mb_new_group_pa: OK
[ 50.770760] Testing event ext4_mb_new_inode_pa: OK
[ 50.797404] Testing event ext4_discard_blocks: OK
[ 50.819162] Testing event ext4_journalled_invalidatepage: OK
[ 50.843088] Testing event ext4_invalidatepage: OK
[ 50.869847] Testing event ext4_releasepage: OK
[ 50.895797] Testing event ext4_readpage: OK
[ 50.918695] Testing event ext4_writepage: OK
[ 50.946426] Testing event ext4_writepages_result: OK
[ 50.971412] Testing event ext4_da_write_pages_extent: OK
[ 50.995445] Testing event ext4_da_write_pages: OK
[ 51.020814] Testing event ext4_writepages: OK
[ 51.043851] Testing event ext4_da_write_end: OK
[ 51.066626] Testing event ext4_journalled_write_end: OK
[ 51.091271] Testing event ext4_write_end: OK
[ 51.114750] Testing event ext4_da_write_begin: OK
[ 51.141305] Testing event ext4_write_begin: OK
[ 51.166652] Testing event ext4_begin_ordered_truncate: OK
[ 51.189926] Testing event ext4_mark_inode_dirty: OK
[ 51.217178] Testing event ext4_drop_inode: OK
[ 51.245294] Testing event ext4_evict_inode: OK
[ 51.269052] Testing event ext4_allocate_inode: OK
[ 51.291548] Testing event ext4_request_inode: OK
[ 51.317042] Testing event ext4_free_inode: OK
[ 51.339398] Testing event journal_write_superblock: OK
[ 51.368280] Testing event jbd_cleanup_journal_tail: OK
[ 51.390976] Testing event jbd_do_submit_data: OK
[ 51.418736] Testing event jbd_end_commit: OK
[ 51.444643] Testing event jbd_drop_transaction: OK
[ 51.469333] Testing event jbd_commit_logging: OK
[ 51.491123] Testing event jbd_commit_flushing: OK
[ 51.516621] Testing event jbd_commit_locking: OK
[ 51.541072] Testing event jbd_start_commit: OK
[ 51.563676] Testing event jbd_checkpoint: OK
[ 51.586355] Testing event jbd2_lock_buffer_stall: OK
[ 51.611836] Testing event jbd2_write_superblock: OK
[ 51.639734] Testing event jbd2_update_log_tail: OK
[ 51.663290] Testing event jbd2_checkpoint_stats: OK
[ 51.687421] Testing event jbd2_run_stats: OK
[ 51.710842] Testing event jbd2_handle_stats: OK
[ 51.740241] Testing event jbd2_handle_extend: OK
[ 51.767701] Testing event jbd2_handle_start: OK
[ 51.792390] Testing event jbd2_submit_inode_data: OK
[ 51.815365] Testing event jbd2_end_commit: OK
[ 51.838997] Testing event jbd2_drop_transaction: OK
[ 51.862574] Testing event jbd2_commit_logging: OK
[ 51.886343] Testing event jbd2_commit_flushing: OK
[ 51.910502] Testing event jbd2_commit_locking: OK
[ 51.934549] Testing event jbd2_start_commit: OK
[ 51.959130] Testing event jbd2_checkpoint: OK
[ 51.981424] Testing event xfs_discard_busy: OK
[ 52.000233] Testing event xfs_discard_exclude: OK
[ 52.022483] Testing event xfs_discard_toosmall: OK
[ 52.048124] Testing event xfs_discard_extent: OK
[ 52.070022] Testing event xfs_log_recover_inode_skip: OK
[ 52.095297] Testing event xfs_log_recover_inode_cancel: OK
[ 52.118629] Testing event xfs_log_recover_inode_recover: OK
[ 52.142988] Testing event xfs_log_recover_buf_dquot_buf: OK
[ 52.166563] Testing event xfs_log_recover_buf_reg_buf: OK
[ 52.192814] Testing event xfs_log_recover_buf_inode_buf: OK
[ 52.217381] Testing event xfs_log_recover_buf_recover: OK
[ 52.243147] Testing event xfs_log_recover_buf_cancel_ref_inc: OK
[ 52.268595] Testing event xfs_log_recover_buf_cancel_add: OK
[ 52.297265] Testing event xfs_log_recover_buf_cancel: OK
[ 52.324339] Testing event xfs_log_recover_buf_not_cancel: OK
[ 52.351280] Testing event xfs_log_recover_item_recover: OK
[ 52.382426] Testing event xfs_log_recover_item_reorder_tail: OK
[ 52.409175] Testing event xfs_log_recover_item_reorder_head: OK
[ 52.435665] Testing event xfs_log_recover_item_add_cont: OK
[ 52.459789] Testing event xfs_log_recover_item_add: OK
[ 52.484875] Testing event xfs_swap_extent_after: OK
[ 52.509228] Testing event xfs_swap_extent_before: OK
[ 52.534757] Testing event xfs_dir2_leafn_moveents: OK
[ 52.559742] Testing event xfs_dir2_shrink_inode: OK
[ 52.584861] Testing event xfs_dir2_grow_inode: OK
[ 52.612981] Testing event xfs_dir2_leafn_remove: OK
[ 52.633720] Testing event xfs_dir2_leafn_add: OK
[ 52.657601] Testing event xfs_da_path_shift:
[ 52.673264] test-events (1390) used greatest stack depth: 6588 bytes left
[ 52.686949] OK
[ 52.691396] Testing event xfs_da_fixhashpath: OK
[ 52.714493] Testing event xfs_da_shrink_inode: OK
[ 52.737243] Testing event xfs_da_grow_inode: OK
[ 52.758300] Testing event xfs_da_swap_lastblock: OK
[ 52.785857] Testing event xfs_da_node_toosmall: OK
[ 52.810295] Testing event xfs_da_node_unbalance: OK
[ 52.835419] Testing event xfs_da_node_rebalance: OK
[ 52.859134] Testing event xfs_da_node_remove: OK
[ 52.882367] Testing event xfs_da_node_split: OK
[ 52.907344] Testing event xfs_da_node_create: OK
[ 52.931338] Testing event xfs_da_node_add: OK
[ 52.954681] Testing event xfs_da_root_join: OK
[ 52.979132] Testing event xfs_da_root_split: OK
[ 53.002251] Testing event xfs_da_unlink_forward: OK
[ 53.026750] Testing event xfs_da_unlink_back: OK
[ 53.050143] Testing event xfs_da_link_after: OK
[ 53.081136] Testing event xfs_da_link_before: OK
[ 53.102648] Testing event xfs_da_join: OK
[ 53.126696] Testing event xfs_da_split: OK
[ 53.150758] Testing event xfs_attr_rmtval_remove: OK
[ 53.174609] Testing event xfs_attr_rmtval_set: OK
[ 53.200511] Testing event xfs_attr_rmtval_get: OK
[ 53.222529] Testing event xfs_attr_refillstate: OK
[ 53.246525] Testing event xfs_attr_fillstate: OK
[ 53.272866] Testing event xfs_attr_node_removename: OK
[ 53.298477] Testing event xfs_attr_node_replace: OK
[ 53.322733] Testing event xfs_attr_node_lookup: OK
[ 53.347653] Testing event xfs_attr_node_get: OK
[ 53.375157] Testing event xfs_attr_node_addname: OK
[ 53.399482] Testing event xfs_attr_leaf_toosmall: OK
[ 53.423247] Testing event xfs_attr_leaf_unbalance: OK
[ 53.446133] Testing event xfs_attr_leaf_rebalance: OK
[ 53.475525] Testing event xfs_attr_leaf_to_node: OK
[ 53.503750] Testing event xfs_attr_leaf_to_sf: OK
[ 53.530974] Testing event xfs_attr_leaf_flipflags: OK
[ 53.556383] Testing event xfs_attr_leaf_setflag: OK
[ 53.584365] Testing event xfs_attr_leaf_clearflag: OK
[ 53.606895] Testing event xfs_attr_leaf_split_after: OK
[ 53.632447] Testing event xfs_attr_leaf_split_before: OK
[ 53.655423] Testing event xfs_attr_leaf_split: OK
[ 53.679003] Testing event xfs_attr_leaf_removename: OK
[ 53.702283] Testing event xfs_attr_leaf_remove: OK
[ 53.726888] Testing event xfs_attr_leaf_replace: OK
[ 53.751558] Testing event xfs_attr_leaf_lookup: OK
[ 53.774949] Testing event xfs_attr_leaf_get: OK
[ 53.799424] Testing event xfs_attr_leaf_compact: OK
[ 53.822273] Testing event xfs_attr_leaf_create: OK
[ 53.846987] Testing event xfs_attr_leaf_addname: OK
[ 53.870482] Testing event xfs_attr_leaf_add_work: OK
[ 53.896175] Testing event xfs_attr_leaf_add_new: OK
[ 53.919615] Testing event xfs_attr_leaf_add_old: OK
[ 53.942283] Testing event xfs_attr_leaf_add: OK
[ 53.967339] Testing event xfs_attr_sf_to_leaf: OK
[ 53.991285] Testing event xfs_attr_sf_removename: OK
[ 54.015670] Testing event xfs_attr_sf_remove: OK
[ 54.039767] Testing event xfs_attr_sf_lookup: OK
[ 54.064662] Testing event xfs_attr_sf_create: OK
[ 54.085658] Testing event xfs_attr_sf_addname: OK
[ 54.105925] Testing event xfs_attr_sf_add: OK
[ 54.130597] Testing event xfs_dir2_node_to_leaf: OK
[ 54.156279] Testing event xfs_dir2_node_removename: OK
[ 54.185761] Testing event xfs_dir2_node_replace: OK
[ 54.210334] Testing event xfs_dir2_node_lookup: OK
[ 54.235194] Testing event xfs_dir2_node_addname: OK
[ 54.258378] Testing event xfs_dir2_leaf_to_node: OK
[ 54.282109] Testing event xfs_dir2_leaf_to_block: OK
[ 54.306464] Testing event xfs_dir2_leaf_removename: OK
[ 54.330673] Testing event xfs_dir2_leaf_replace: OK
[ 54.354732] Testing event xfs_dir2_leaf_lookup: OK
[ 54.378537] Testing event xfs_dir2_leaf_addname: OK
[ 54.402278] Testing event xfs_dir2_block_to_leaf: OK
[ 54.426165] Testing event xfs_dir2_block_to_sf: OK
[ 54.450134] Testing event xfs_dir2_block_removename: OK
[ 54.474339] Testing event xfs_dir2_block_replace: OK
[ 54.498889] Testing event xfs_dir2_block_lookup: OK
[ 54.522783] Testing event xfs_dir2_block_addname: OK
[ 54.546979] Testing event xfs_dir2_sf_to_block: OK
[ 54.571432] Testing event xfs_dir2_sf_toino8: OK
[ 54.594972] Testing event xfs_dir2_sf_toino4: OK
[ 54.616973] Testing event xfs_dir2_sf_removename: OK
[ 54.637215] Testing event xfs_dir2_sf_replace: OK
[ 54.658297] Testing event xfs_dir2_sf_lookup: OK
[ 54.682513] Testing event xfs_dir2_sf_create: OK
[ 54.706145] Testing event xfs_dir2_sf_addname: OK
[ 54.729624] Testing event xfs_alloc_vextent_allfailed: OK
[ 54.753671] Testing event xfs_alloc_vextent_loopfailed: OK
[ 54.781273] Testing event xfs_alloc_vextent_noagbp: OK
[ 54.802775] Testing event xfs_alloc_vextent_nofix: OK
[ 54.830775] Testing event xfs_alloc_vextent_badargs: OK
[ 54.855877] Testing event xfs_alloc_small_error: OK
[ 54.877605] Testing event xfs_alloc_small_done: OK
[ 54.897412] Testing event xfs_alloc_small_notenough: OK
[ 54.920170] Testing event xfs_alloc_small_freelist: OK
[ 54.945530] Testing event xfs_alloc_size_busy: OK
[ 54.970929] Testing event xfs_alloc_size_error: OK
[ 54.993068] Testing event xfs_alloc_size_done: OK
[ 55.014493] Testing event xfs_alloc_size_nominleft: OK
[ 55.038140] Testing event xfs_alloc_size_noentry: OK
[ 55.060688] Testing event xfs_alloc_size_neither: OK
[ 55.081544] Testing event xfs_alloc_near_busy: OK
[ 55.101199] Testing event xfs_alloc_near_noentry: OK
[ 55.122066] Testing event xfs_alloc_near_error: OK
[ 55.146238] Testing event xfs_alloc_near_lesser: OK
[ 55.174369] Testing event xfs_alloc_near_greater: OK
[ 55.198925] Testing event xfs_alloc_near_first: OK
[ 55.223713] Testing event xfs_alloc_near_nominleft: OK
[ 55.250795] Testing event xfs_alloc_exact_error: OK
[ 55.275750] Testing event xfs_alloc_exact_notfound: OK
[ 55.300640] Testing event xfs_alloc_exact_done: OK
[ 55.322139] Testing event xfs_free_extent: OK
[ 55.346396] Testing event xfs_agf: OK
[ 55.376564] Testing event xfs_trans_commit_lsn: OK
[ 55.401977] Testing event xfs_extent_busy_trim: OK
[ 55.427665] Testing event xfs_extent_busy_clear: OK
[ 55.450275] Testing event xfs_extent_busy_reuse: OK
[ 55.474689] Testing event xfs_extent_busy_force: OK
[ 55.496273] Testing event xfs_extent_busy_enomem: OK
[ 55.516567] Testing event xfs_extent_busy: OK
[ 55.537009] Testing event xfs_bunmap: OK
[ 55.556901] Testing event xfs_pagecache_inval: OK
[ 55.580264] Testing event xfs_itruncate_extents_end: OK
[ 55.600390] Testing event xfs_itruncate_extents_start: OK
[ 55.620084] Testing event xfs_setfilesize: OK
[ 55.640968] Testing event xfs_get_blocks_notfound: OK
[ 55.666966] Testing event xfs_unwritten_convert: OK
[ 55.690141] Testing event xfs_delalloc_enospc: OK
[ 55.714677] Testing event xfs_get_blocks_alloc: OK
[ 55.742839] Testing event xfs_get_blocks_found: OK
[ 55.766899] Testing event xfs_map_blocks_alloc: OK
[ 55.794721] Testing event xfs_map_blocks_found: OK
[ 55.818692] Testing event xfs_invalidatepage: OK
[ 55.840277] Testing event xfs_releasepage: OK
[ 55.861057] Testing event xfs_writepage: OK
[ 55.883061] Testing event xfs_file_splice_read: OK
[ 55.910291] Testing event xfs_file_direct_write: OK
[ 55.933782] Testing event xfs_file_buffered_write: OK
[ 55.963581] Testing event xfs_file_read: OK
[ 55.986057] Testing event xfs_log_assign_tail_lsn: OK
[ 56.010047] Testing event xfs_ail_delete: OK
[ 56.034136] Testing event xfs_ail_move: OK
[ 56.058624] Testing event xfs_ail_insert: OK
[ 56.082226] Testing event xfs_ail_flushing: OK
[ 56.105870] Testing event xfs_ail_locked: OK
[ 56.126264] Testing event xfs_ail_pinned: OK
[ 56.150140] Testing event xfs_ail_push: OK
[ 56.174898] Testing event xfs_log_force: OK
[ 56.199102] Testing event xfs_log_ungrant_sub: OK
[ 56.222562] Testing event xfs_log_ungrant_exit: OK
[ 56.247882] Testing event xfs_log_ungrant_enter: OK
[ 56.272923] Testing event xfs_log_regrant_reserve_sub: OK
[ 56.294346] Testing event xfs_log_regrant_reserve_exit: OK
[ 56.317274] Testing event xfs_log_regrant_reserve_enter: OK
[ 56.339001] Testing event xfs_log_regrant_exit: OK
[ 56.362768] Testing event xfs_log_regrant: OK
[ 56.384176] Testing event xfs_log_reserve_exit: OK
[ 56.403871] Testing event xfs_log_reserve: OK
[ 56.425566] Testing event xfs_log_grant_wake_up: OK
[ 56.445384] Testing event xfs_log_grant_wake: OK
[ 56.466044] Testing event xfs_log_grant_sleep: OK
[ 56.490529] Testing event xfs_log_umount_write: OK
[ 56.513313] Testing event xfs_log_done_perm: OK
[ 56.534575] Testing event xfs_log_done_nonperm: OK
[ 56.558847] Testing event xfs_dqflush_done: OK
[ 56.580069] Testing event xfs_dqflush_force: OK
[ 56.599939] Testing event xfs_dqflush: OK
[ 56.620186] Testing event xfs_dqrele: OK
[ 56.642142] Testing event xfs_dqput_free: OK
[ 56.666636] Testing event xfs_dqput_wait: OK
[ 56.690354] Testing event xfs_dqput: OK
[ 56.714283] Testing event xfs_dqget_dup: OK
[ 56.738522] Testing event xfs_dqget_freeing: OK
[ 56.761913] Testing event xfs_dqget_miss: OK
[ 56.782433] Testing event xfs_dqget_hit: OK
[ 56.806244] Testing event xfs_dqread_fail: OK
[ 56.829551] Testing event xfs_dqread: OK
[ 56.854065] Testing event xfs_dqtobp_read: OK
[ 56.877605] Testing event xfs_dqalloc: OK
[ 56.902056] Testing event xfs_dqattach_get: OK
[ 56.926992] Testing event xfs_dqattach_found: OK
[ 56.950095] Testing event xfs_dqreclaim_done: OK
[ 56.973829] Testing event xfs_dqreclaim_busy: OK
[ 56.995090] Testing event xfs_dqreclaim_dirty: OK
[ 57.016338] Testing event xfs_dqreclaim_want: OK
[ 57.037782] Testing event xfs_dqadjust: OK
[ 57.057918] Testing event xfs_rename: OK
[ 57.080598] Testing event xfs_symlink: OK
[ 57.105956] Testing event xfs_create: OK
[ 57.128864] Testing event xfs_lookup: OK
[ 57.148981] Testing event xfs_link: OK
[ 57.168936] Testing event xfs_remove: OK
[ 57.188734] Testing event xfs_inode_unpin_nowait: OK
[ 57.209239] Testing event xfs_inode_unpin: OK
[ 57.228495] Testing event xfs_inode_pin: OK
[ 57.254355] Testing event xfs_irele: OK
[ 57.279573] Testing event xfs_ihold: OK
[ 57.301438] Testing event xfs_iomap_prealloc_size: OK
[ 57.321328] Testing event xfs_inode_free_eofblocks_invalid: OK
[ 57.341646] Testing event xfs_inode_clear_eofblocks_tag: OK
[ 57.366149] Testing event xfs_inode_set_eofblocks_tag: OK
[ 57.390012] Testing event xfs_dquot_dqdetach: OK
[ 57.409765] Testing event xfs_dquot_dqalloc: OK
[ 57.429633] Testing event xfs_update_time: OK
[ 57.447946] Testing event xfs_evict_inode: OK
[ 57.471162] Testing event xfs_destroy_inode: OK
[ 57.493975] Testing event xfs_file_fsync: OK
[ 57.513163] Testing event xfs_dir_fsync: OK
[ 57.535918] Testing event xfs_ioctl_setattr: OK
[ 57.557353] Testing event xfs_file_compat_ioctl: OK
[ 57.582395] Testing event xfs_file_ioctl: OK
[ 57.605355] Testing event xfs_vm_bmap: OK
[ 57.625193] Testing event xfs_get_acl: OK
[ 57.645313] Testing event xfs_readdir: OK
[ 57.665467] Testing event xfs_collapse_file_space: OK
[ 57.686553] Testing event xfs_zero_file_space: OK
[ 57.714539] Testing event xfs_free_file_space: OK
[ 57.741386] Testing event xfs_alloc_file_space: OK
[ 57.765825] Testing event xfs_inactive_symlink: OK
[ 57.794548] Testing event xfs_readlink: OK
[ 57.819280] Testing event xfs_setattr: OK
[ 57.841555] Testing event xfs_getattr: OK
[ 57.860916] Testing event xfs_iget_miss: OK
[ 57.880665] Testing event xfs_iget_hit: OK
[ 57.900611] Testing event xfs_iget_reclaim_fail: OK
[ 57.922412] Testing event xfs_iget_reclaim: OK
[ 57.947763] Testing event xfs_iget_skip: OK
[ 57.970351] Testing event xfs_iunlock: OK
[ 57.990681] Testing event xfs_ilock_demote: OK
[ 58.014065] Testing event xfs_ilock_nowait: OK
[ 58.042861] Testing event xfs_ilock: OK
[ 58.065858] Testing event xfs_filestream_pick: OK
[ 58.090123] Testing event xfs_filestream_scan: OK
[ 58.117410] Testing event xfs_filestream_lookup: OK
[ 58.143460] Testing event xfs_filestream_free: OK
[ 58.165047] Testing event xfs_trans_buf_ordered: OK
[ 58.186040] Testing event xfs_trans_binval: OK
[ 58.210325] Testing event xfs_trans_bhold_release: OK
[ 58.234453] Testing event xfs_trans_bhold: OK
[ 58.257353] Testing event xfs_trans_bjoin: OK
[ 58.280418] Testing event xfs_trans_brelse: OK
[ 58.303087] Testing event xfs_trans_log_buf: OK
[ 58.327120] Testing event xfs_trans_read_buf_recur: OK
[ 58.349993] Testing event xfs_trans_read_buf: OK
[ 58.378080] Testing event xfs_trans_getsb_recur: OK
[ 58.402119] Testing event xfs_trans_getsb: OK
[ 58.427769] Testing event xfs_trans_get_buf_recur: OK
[ 58.451129] Testing event xfs_trans_get_buf: OK
[ 58.474730] Testing event xfs_buf_item_push: OK
[ 58.498168] Testing event xfs_buf_item_committed: OK
[ 58.526893] Testing event xfs_buf_item_unlock_stale: OK
[ 58.550154] Testing event xfs_buf_item_unlock: OK
[ 58.574292] Testing event xfs_buf_item_unpin_stale: OK
[ 58.598216] Testing event xfs_buf_item_unpin: OK
[ 58.622352] Testing event xfs_buf_item_pin: OK
[ 58.644696] Testing event xfs_buf_item_ordered: OK
[ 58.665720] Testing event xfs_buf_item_format_stale: OK
[ 58.687931] Testing event xfs_buf_item_format_ordered: OK
[ 58.710262] Testing event xfs_buf_item_format: OK
[ 58.730426] Testing event xfs_buf_item_size_stale: OK
[ 58.758923] Testing event xfs_buf_item_size_ordered: OK
[ 58.779868] Testing event xfs_buf_item_size: OK
[ 58.799508] Testing event xfs_buf_ioerror: OK
[ 58.820161] Testing event xfs_buf_read: OK
[ 58.839435] Testing event xfs_buf_get: OK
[ 58.859534] Testing event xfs_buf_find: OK
[ 58.880439] Testing event xfs_inode_item_push: OK
[ 58.899868] Testing event xfs_reset_dqcounts: OK
[ 58.920128] Testing event xfs_da_btree_corrupt: OK
[ 58.940682] Testing event xfs_btree_corrupt: OK
[ 58.961801] Testing event xfs_trans_read_buf_shut: OK
[ 58.981988] Testing event xfs_trans_read_buf_io: OK
[ 59.006119] Testing event xfs_buf_wait_buftarg: OK
[ 59.029299] Testing event xfs_buf_error_relse: OK
[ 59.049880] Testing event xfs_buf_item_iodone_async: OK
[ 59.074370] Testing event xfs_buf_item_iodone: OK
[ 59.106636] Testing event xfs_buf_item_relse: OK
[ 59.130164] Testing event xfs_bdstrat_shut: OK
[ 59.154025] Testing event xfs_buf_get_uncached: OK
[ 59.177834] Testing event xfs_buf_delwri_split: OK
[ 59.202012] Testing event xfs_buf_delwri_queued: OK
[ 59.230676] Testing event xfs_buf_delwri_queue: OK
[ 59.254460] Testing event xfs_buf_iowait_done: OK
[ 59.278136] Testing event xfs_buf_iowait: OK
[ 59.301978] Testing event xfs_buf_unlock: OK
[ 59.326962] Testing event xfs_buf_trylock: OK
[ 59.352518] Testing event xfs_buf_lock_done: OK
[ 59.377997] Testing event xfs_buf_lock: OK
[ 59.401986] Testing event xfs_buf_bawrite: OK
[ 59.425656] Testing event xfs_buf_submit_wait: OK
[ 59.446011] Testing event xfs_buf_submit: OK
[ 59.471442] Testing event xfs_buf_iodone: OK
[ 59.494138] Testing event xfs_buf_rele: OK
[ 59.517637] Testing event xfs_buf_hold: OK
[ 59.537975] Testing event xfs_buf_free: OK
[ 59.556927] Testing event xfs_buf_init: OK
[ 59.577721] Testing event xfs_extlist: OK
[ 59.597349] Testing event xfs_bmap_post_update: OK
[ 59.630757] Testing event xfs_bmap_pre_update: OK
[ 59.666270] Testing event xfs_iext_remove: OK
[ 59.689750] Testing event xfs_iext_insert: OK
[ 59.709697] Testing event xfs_attr_list_node_descend: OK
[ 59.735502] Testing event xfs_ialloc_read_agi: OK
[ 59.758187] Testing event xfs_read_agi: OK
[ 59.781646] Testing event xfs_alloc_read_agf: OK
[ 59.801714] Testing event xfs_read_agf: OK
[ 59.821582] Testing event xfs_perag_clear_eofblocks: OK
[ 59.841674] Testing event xfs_perag_set_eofblocks: OK
[ 59.861714] Testing event xfs_perag_clear_reclaim: OK
[ 59.882258] Testing event xfs_perag_set_reclaim: OK
[ 59.905941] Testing event xfs_perag_put: OK
[ 59.925683] Testing event xfs_perag_get_tag: OK
[ 59.945649] Testing event xfs_perag_get: OK
[ 59.967971] Testing event xfs_attr_node_list: OK
[ 59.990187] Testing event xfs_attr_leaf_list: OK
[ 60.012977] Testing event xfs_attr_list_notfound: OK
[ 60.032390] Testing event xfs_attr_list_wrong_blk: OK
[ 60.052158] Testing event xfs_attr_list_add: OK
[ 60.073933] Testing event xfs_attr_list_full: OK
[ 60.094195] Testing event xfs_attr_list_leaf_end: OK
[ 60.118319] Testing event xfs_attr_list_leaf: OK
[ 60.141547] Testing event xfs_attr_list_sf_all: OK
[ 60.161763] Testing event xfs_attr_list_sf: OK
[ 60.190305] Testing event btrfs_qgroup_record_ref: OK
[ 60.209760] Testing event btrfs_qgroup_account: OK
[ 60.229395] Testing event btrfs_workqueue_destroy: OK
[ 60.254599] Testing event btrfs_workqueue_alloc: OK
[ 60.280592] Testing event btrfs_ordered_sched: OK
[ 60.303081] Testing event btrfs_all_work_done: OK
[ 60.332511] Testing event btrfs_work_sched: OK
[ 60.354423] Testing event btrfs_work_queued: OK
[ 60.378881] Testing event free_extent_state: OK
[ 60.407088] Testing event alloc_extent_state: OK
[ 60.430387] Testing event btrfs_setup_cluster: OK
[ 60.454845] Testing event btrfs_failed_cluster_setup: OK
[ 60.479044] Testing event btrfs_find_cluster: OK
[ 60.502636] Testing event btrfs_reserve_extent_cluster: OK
[ 60.527136] Testing event btrfs_reserve_extent: OK
[ 60.549905] Testing event find_free_extent: OK
[ 60.570177] Testing event btrfs_reserved_extent_free: OK
[ 60.595951] Testing event btrfs_reserved_extent_alloc: OK
[ 60.622040] Testing event btrfs_space_reservation: OK
[ 60.653467] Testing event btrfs_cow_block: OK
[ 60.676928] Testing event btrfs_chunk_free: OK
[ 60.696697] Testing event btrfs_chunk_alloc: OK
[ 60.718051] Testing event run_delayed_ref_head: OK
[ 60.742763] Testing event add_delayed_ref_head: OK
[ 60.768620] Testing event run_delayed_data_ref: OK
[ 60.791411] Testing event add_delayed_data_ref: OK
[ 60.814926] Testing event run_delayed_tree_ref: OK
[ 60.838769] Testing event add_delayed_tree_ref: OK
[ 60.862347] Testing event btrfs_sync_fs: OK
[ 60.886412] Testing event btrfs_sync_file: OK
[ 60.910856] Testing event btrfs_writepage_end_io_hook: OK
[ 60.934096] Testing event __extent_writepage: OK
[ 60.960606] Testing event btrfs_ordered_extent_put: OK
[ 60.983256] Testing event btrfs_ordered_extent_start: OK
[ 61.006648] Testing event btrfs_ordered_extent_remove: OK
[ 61.031108] Testing event btrfs_ordered_extent_add: OK
[ 61.055277] Testing event btrfs_get_extent: OK
[ 61.079182] Testing event btrfs_inode_evict: OK
[ 61.104576] Testing event btrfs_inode_request: OK
[ 61.127675] Testing event btrfs_inode_new: OK
[ 61.149279] Testing event btrfs_transaction_commit: OK
[ 61.173834] Testing event gfs2_rs: OK
[ 61.201474] Testing event gfs2_block_alloc: OK
[ 61.221324] Testing event gfs2_bmap: OK
[ 61.241104] Testing event gfs2_ail_flush: OK
[ 61.261397] Testing event gfs2_log_blocks: OK
[ 61.286646] Testing event gfs2_log_flush: OK
[ 61.310149] Testing event gfs2_pin: OK
[ 61.333362] Testing event gfs2_glock_lock_time: OK
[ 61.353771] Testing event gfs2_glock_queue: OK
[ 61.382667] Testing event gfs2_promote: OK
[ 61.404266] Testing event gfs2_demote_rq: OK
[ 61.424572] Testing event gfs2_glock_put: OK
[ 61.446062] Testing event gfs2_glock_state_change: OK
[ 61.470300] Testing event block_rq_remap: OK
[ 61.493710] Testing event block_bio_remap: OK
[ 61.513433] Testing event block_split: OK
[ 61.532480] Testing event block_unplug: OK
[ 61.552980] Testing event block_plug: OK
[ 61.572324] Testing event block_sleeprq: OK
[ 61.593481] Testing event block_getrq: OK
[ 61.617218] Testing event block_bio_queue: OK
[ 61.641963] Testing event block_bio_frontmerge: OK
[ 61.666163] Testing event block_bio_backmerge: OK
[ 61.690326] Testing event block_bio_complete: OK
[ 61.714096] Testing event block_bio_bounce: OK
[ 61.739189] Testing event block_rq_issue: OK
[ 61.763533] Testing event block_rq_insert: OK
[ 61.792735] Testing event block_rq_complete: OK
[ 61.814737] Testing event block_rq_requeue: OK
[ 61.838058] Testing event block_rq_abort: OK
[ 61.862414] Testing event block_dirty_buffer: OK
[ 61.887268] Testing event block_touch_buffer: OK
[ 61.909778] Testing event gpio_value: OK
[ 61.935267] Testing event gpio_direction: OK
[ 61.960654] Testing event regulator_set_voltage_complete: OK
[ 61.983933] Testing event regulator_set_voltage: OK
[ 62.006768] Testing event regulator_disable_complete: OK
[ 62.030515] Testing event regulator_disable: OK
[ 62.054606] Testing event regulator_enable_complete: OK
[ 62.079411] Testing event regulator_enable_delay: OK
[ 62.102724] Testing event regulator_enable: OK
[ 62.126235] Testing event urandom_read: OK
[ 62.150669] Testing event random_read: OK
[ 62.174156] Testing event extract_entropy_user: OK
[ 62.200574] Testing event extract_entropy: OK
[ 62.222806] Testing event get_random_bytes_arch: OK
[ 62.246961] Testing event get_random_bytes: OK
[ 62.270004] Testing event xfer_secondary_pool: OK
[ 62.295886] Testing event add_disk_randomness: OK
[ 62.321570] Testing event add_input_randomness: OK
[ 62.349114] Testing event debit_entropy: OK
[ 62.370304] Testing event push_to_pool: OK
[ 62.398914] Testing event credit_entropy_bits: OK
[ 62.422682] Testing event mix_pool_bytes_nolock: OK
[ 62.447218] Testing event mix_pool_bytes: OK
[ 62.470645] Testing event add_device_randomness: OK
[ 62.494723] Testing event drm_vblank_event_delivered: OK
[ 62.522540] Testing event drm_vblank_event_queued: OK
[ 62.548520] Testing event drm_vblank_event: OK
[ 62.571846] Testing event radeon_semaphore_wait: OK
[ 62.594867] Testing event radeon_semaphore_signale: OK
[ 62.620398] Testing event radeon_fence_wait_end: OK
[ 62.644595] Testing event radeon_fence_wait_begin: OK
[ 62.667216] Testing event radeon_fence_emit: OK
[ 62.691230] Testing event radeon_vm_flush: OK
[ 62.715827] Testing event radeon_vm_set_page: OK
[ 62.739607] Testing event radeon_vm_bo_update: OK
[ 62.762400] Testing event radeon_vm_grab_id: OK
[ 62.787540] Testing event radeon_cs: OK
[ 62.810458] Testing event radeon_bo_create: OK
[ 62.834426] Testing event regcache_drop_region: OK
[ 62.857876] Testing event regmap_async_complete_done: OK
[ 62.881057] Testing event regmap_async_complete_start: OK
[ 62.901347] Testing event regmap_async_io_complete: OK
[ 62.921967] Testing event regmap_async_write_start: OK
[ 62.951359] Testing event regmap_cache_bypass: OK
[ 62.973441] Testing event regmap_cache_only: OK
[ 62.994957] Testing event regcache_sync: OK
[ 63.019222] Testing event regmap_hw_write_done: OK
[ 63.041763] Testing event regmap_hw_write_start: OK
[ 63.067773] Testing event regmap_hw_read_done: OK
[ 63.091498] Testing event regmap_hw_read_start: OK
[ 63.115162] Testing event regmap_reg_read_cache: OK
[ 63.140839] Testing event regmap_reg_read: OK
[ 63.168657] Testing event regmap_reg_write: OK
[ 63.192589] Testing event fence_wait_end: OK
[ 63.215594] Testing event fence_wait_start: OK
[ 63.239356] Testing event fence_signaled: OK
[ 63.264591] Testing event fence_enable_signal: OK
[ 63.289795] Testing event fence_destroy: OK
[ 63.310146] Testing event fence_init: OK
[ 63.339125] Testing event fence_emit: OK
[ 63.362919] Testing event fence_annotate_wait_on: OK
[ 63.386158] Testing event scsi_eh_wakeup: OK
[ 63.410170] Testing event scsi_dispatch_cmd_timeout: OK
[ 63.435433] Testing event scsi_dispatch_cmd_done: OK
[ 63.460740] Testing event scsi_dispatch_cmd_error: OK
[ 63.487717] Testing event scsi_dispatch_cmd_start: OK
[ 63.510303] Testing event target_cmd_complete: OK
[ 63.542851] Testing event target_sequencer_start: OK
[ 63.567631] Testing event smbus_result: OK
[ 63.595572] Testing event smbus_reply: OK
[ 63.617851] Testing event smbus_read: OK
[ 63.643473] Testing event smbus_write: OK
[ 63.671515] Testing event i2c_result: OK
[ 63.695216] Testing event i2c_reply: OK
[ 63.718352] Testing event i2c_read: OK
[ 63.742449] Testing event i2c_write: OK
[ 63.767424] Testing event v4l2_qbuf: OK
[ 63.789124] Testing event v4l2_dqbuf: OK
[ 63.808733] Testing event thermal_zone_trip: OK
[ 63.829235] Testing event cdev_update: OK
[ 63.850531] Testing event thermal_temperature: OK
[ 63.873656] Testing event binder_return: OK
[ 63.893945] Testing event binder_command: OK
[ 63.922682] Testing event binder_update_page_range: OK
[ 63.947147] Testing event binder_transaction_failed_buffer_release: OK
[ 63.971367] Testing event binder_transaction_buffer_release: OK
[ 63.996426] Testing event binder_transaction_alloc_buf: OK
[ 64.019037] Testing event binder_transaction_fd: OK
[ 64.043455] Testing event binder_transaction_ref_to_ref: OK
[ 64.066577] Testing event binder_transaction_ref_to_node: OK
[ 64.091249] Testing event binder_transaction_node_to_ref: OK
[ 64.115319] Testing event binder_transaction_received: OK
[ 64.139727] Testing event binder_transaction: OK
[ 64.162515] Testing event binder_wait_for_work: OK
[ 64.191674] Testing event binder_read_done: OK
[ 64.214825] Testing event binder_write_done: OK
[ 64.236768] Testing event binder_ioctl_done: OK
[ 64.257137] Testing event binder_unlock: OK
[ 64.282016] Testing event binder_locked: OK
[ 64.309169] Testing event binder_lock: OK
[ 64.334318] Testing event binder_ioctl: OK
[ 64.358301] Testing event udp_fail_queue_rcv_skb: OK
[ 64.388565] Testing event sock_exceed_buf_limit: OK
[ 64.410308] Testing event sock_rcvqueue_full: OK
[ 64.434811] Testing event napi_poll: OK
[ 64.458570] Testing event netif_rx_ni_entry: OK
[ 64.481699] Testing event netif_rx_entry: OK
[ 64.506969] Testing event netif_receive_skb_entry: OK
[ 64.530182] Testing event napi_gro_receive_entry: OK
[ 64.553843] Testing event napi_gro_frags_entry: OK
[ 64.573187] Testing event netif_rx: OK
[ 64.595147] Testing event netif_receive_skb: OK
[ 64.619635] Testing event net_dev_queue: OK
[ 64.642648] Testing event net_dev_xmit: OK
[ 64.666209] Testing event net_dev_start_xmit: OK
[ 64.690102] Testing event skb_copy_datagram_iovec: OK
[ 64.712565] Testing event consume_skb: OK
[ 64.734152] Testing event kfree_skb: OK
[ 64.758935] Running tests on trace event systems:
[ 64.764987] Testing event system skb: OK
[ 64.790022] Testing event system net: OK
[ 64.819404] Testing event system napi: OK
[ 64.842948] Testing event system sock: OK
[ 64.868388] Testing event system udp: OK
[ 64.892333] Testing event system binder: OK
[ 64.932583] Testing event system thermal: OK
[ 64.959656] Testing event system v4l2: OK
[ 64.986193] Testing event system i2c: OK
[ 65.013939] Testing event system target: OK
[ 65.041087] Testing event system scsi: OK
[ 65.067888] Testing event system fence: OK
[ 65.100287] Testing event system regmap: OK
[ 65.137831] Testing event system radeon: OK
[ 65.168667] Testing event system drm: OK
[ 65.193634] Testing event system random: OK
[ 65.227205] Testing event system regulator: OK
[ 65.253274] Testing event system gpio:
[ 65.264935] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 65.285062] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 65.292829] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 65.299948] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 65.318983] OK
[ 65.326374] Testing event system block: OK
[ 65.360262] Testing event system gfs2: OK
[ 65.397320] Testing event system btrfs: OK
[ 65.455383] Testing event system xfs: OK
[ 65.678477] Testing event system jbd2: OK
[ 65.709781] Testing event system jbd: OK
[ 65.737389] Testing event system ext4: OK
[ 65.803731] Testing event system ext3: OK
[ 65.849037] Testing event system filelock: OK
[ 65.879102] Testing event system writeback: OK
[ 65.919685] Testing event system kmem: OK
[ 65.953211] Testing event system vmscan: OK
[ 65.985984] Testing event system pagemap:
[ 66.008763] Testing event system oom: OK
OK
[ 66.040818] Testing event system filemap: OK
[ 66.062919] Testing event system power: OK
[ 66.113627] Testing event system test: OK
[ 66.137050] Testing event system timer: OK
[ 66.176430] Testing event system rcu: OK
[ 66.204116] Testing event system printk: OK
[ 66.227220] Testing event system lock: OK
[ 66.254687] Testing event system sched: OK
[ 66.287918] Testing event system workqueue: OK
[ 66.315133] Testing event system signal: OK
[ 66.342582] Testing event system irq: OK
[ 66.371582] Testing event system task: OK
[ 66.396742] Testing event system exceptions: OK
[ 66.424716] Testing event system tlb: OK
[ 66.454333] Testing event system raw_syscalls: OK
[ 66.479138] Testing event system nmi: OK
[ 66.503022] Testing event system irq_vectors: OK
[ 66.536626] Running tests on all trace events:
[ 66.543900] Testing all events: OK
[ 67.208766] Testing ftrace filter: OK
[ 67.214565] Btrfs loaded, debug=on, integrity-checker=on
[ 67.217243] BTRFS: selftest: Running btrfs free space cache tests
[ 67.219782] BTRFS: selftest: Running extent only tests
[ 67.222296] BTRFS: selftest: Running bitmap only tests
[ 67.225013] BTRFS: selftest: Running bitmap and extent tests
[ 67.227513] BTRFS: selftest: Running space stealing from bitmap to extent
[ 67.230515] BTRFS: selftest: Free space cache tests finished
[ 67.233257] BTRFS: selftest: Running extent buffer operation tests
[ 67.234207] BTRFS: selftest: Running btrfs_split_item tests
[ 67.238390] BTRFS: selftest: Running find delalloc tests
[ 125.304040] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 125.310278] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 125.313089] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 125.315892] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 125.318978] ??? Writer stall state 8 g4722 c4722 f0x0
[ 125.320727] rcu_sched: wait state: 1 ->state: 0x1
[ 125.322335] rcu_bh: wait state: 1 ->state: 0x1
[ 125.323931] Dumping ftrace buffer:
[ 125.324717] ---------------------------------
[ 125.324717] CPU:1 [LOST 9422718 EVENTS]
[ 125.324717] <idle>-0 1d.s2 63426492us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426492us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426493us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426493us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426494us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426496us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426497us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426497us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426498us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426498us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426499us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426500us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426501us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426501us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426502us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426503us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426503us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426504us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426505us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426506us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426506us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426507us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426508us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426509us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426531us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426532us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426532us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426533us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426533us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426533us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426534us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426534us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426534us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426535us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426535us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426536us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426536us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426538us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426539us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426540us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426540us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426540us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426541us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426542us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426543us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426544us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426544us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426545us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426546us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426547us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426548us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426548us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426549us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426550us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426551us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426551us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426590us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426591us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426591us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426592us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426592us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426592us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426593us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426593us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426594us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426594us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426595us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426595us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426596us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426598us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426598us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426599us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426599us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426600us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426601us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426601us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426602us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426603us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426604us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426604us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426605us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426606us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426606us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426607us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426608us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426608us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426609us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426610us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426632us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426633us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426633us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426634us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426634us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426634us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426635us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426635us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426636us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426636us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426636us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426637us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426637us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426639us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426640us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426641us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426641us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426641us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426642us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426643us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426644us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426644us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426645us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426646us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426646us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426647us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426648us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426648us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426649us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426650us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426651us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426651us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426674us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426675us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426676us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426676us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426676us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426677us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426677us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426677us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426678us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426678us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426679us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426679us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426680us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426682us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426682us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426683us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426683us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426684us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426685us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426686us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426686us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426687us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426688us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426688us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426689us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426690us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426690us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426691us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426692us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426693us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426693us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426694us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426724us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426725us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426725us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426726us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426726us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426726us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426727us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426727us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426728us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426728us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426729us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426729us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426729us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426731us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426732us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426733us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426733us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426734us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426735us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426735us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426736us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426737us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426737us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426738us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426739us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426739us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426740us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426741us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426742us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426742us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426743us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426744us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426766us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426767us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426767us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426768us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426768us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426769us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426769us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426770us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426770us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426770us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426771us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426771us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426772us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426774us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426774us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426775us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426776us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426776us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426777us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426778us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426779us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426780us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426780us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426781us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426782us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426782us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426783us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426784us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426785us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426785us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426786us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426787us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63426809us : smp_call_function_single_interrupt <-call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426810us : kvm_guest_apic_eoi_write <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426810us : irq_enter <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426811us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63426811us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63426811us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426812us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426812us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63426813us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63426813us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63426813us : generic_smp_call_function_single_interrupt <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426814us : flush_smp_call_function_queue <-generic_smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d.h2 63426814us : do_sync_core <-flush_smp_call_function_queue
[ 125.324717] <idle>-0 1d.h2 63426816us : irq_exit <-smp_call_function_single_interrupt
[ 125.324717] <idle>-0 1d..2 63426817us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63426818us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63426818us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426818us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63426819us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426820us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63426821us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426821us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426822us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426823us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426824us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426824us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426825us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63426826us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426826us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63426827us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426828us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63426828us : default_idle <-arch_cpu_idle
[ 125.324717] <idle>-0 1d..2 63430503us : smp_apic_timer_interrupt <-apic_timer_interrupt
[ 125.324717] <idle>-0 1d..2 63430509us : kvm_guest_apic_eoi_write <-smp_apic_timer_interrupt
[ 125.324717] <idle>-0 1d..2 63430511us : irq_enter <-smp_apic_timer_interrupt
[ 125.324717] <idle>-0 1d..2 63430512us : rcu_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d..2 63430515us : rcu_eqs_exit_common <-rcu_irq_enter
[ 125.324717] <idle>-0 1d..2 63430516us : __local_bh_disable_ip <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63430518us : tick_irq_enter <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63430520us : tick_check_oneshot_broadcast_this_cpu <-tick_irq_enter
[ 125.324717] <idle>-0 1d.s2 63430522us : _local_bh_enable <-irq_enter
[ 125.324717] <idle>-0 1d.s2 63430523us : __local_bh_enable <-_local_bh_enable
[ 125.324717] <idle>-0 1d.h2 63430525us : local_apic_timer_interrupt <-smp_apic_timer_interrupt
[ 125.324717] <idle>-0 1d.h2 63430527us : hrtimer_interrupt <-local_apic_timer_interrupt
[ 125.324717] <idle>-0 1d.h2 63430529us : _raw_spin_lock <-hrtimer_interrupt
[ 125.324717] <idle>-0 1d.h3 63430532us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] <idle>-0 1d.h3 63430535us : ktime_get_update_offsets_now <-hrtimer_interrupt
[ 125.324717] <idle>-0 1d.h3 63430538us : __run_hrtimer <-hrtimer_interrupt
[ 125.324717] <idle>-0 1d.h3 63430539us : __remove_hrtimer <-__run_hrtimer
[ 125.324717] <idle>-0 1d.h3 63430542us : _raw_spin_unlock <-__run_hrtimer
[ 125.324717] <idle>-0 1d.h3 63430543us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] <idle>-0 1d.h2 63430546us : tick_sched_timer <-__run_hrtimer
[ 125.324717] <idle>-0 1d.h2 63430547us : ktime_get <-tick_sched_timer
[ 125.324717] <idle>-0 1d.h2 63430550us : update_process_times <-tick_sched_timer
[ 125.324717] <idle>-0 1d.h2 63430552us : account_process_tick <-update_process_times
[ 125.324717] <idle>-0 1d.h2 63430553us : kvm_steal_clock <-account_process_tick
[ 125.324717] <idle>-0 1d.h2 63430554us : nsecs_to_jiffies <-account_process_tick
[ 125.324717] <idle>-0 1d.h2 63430555us : nsecs_to_jiffies64 <-nsecs_to_jiffies
[ 125.324717] <idle>-0 1d.h2 63430557us : jiffies_to_usecs <-account_process_tick
[ 125.324717] <idle>-0 1d.h2 63430558us : account_steal_time <-account_process_tick
[ 125.324717] <idle>-0 1d.h2 63430561us : account_idle_time <-account_process_tick
[ 125.324717] <idle>-0 1d.h2 63430562us : run_local_timers <-update_process_times
[ 125.324717] <idle>-0 1d.h2 63430564us : hrtimer_run_queues <-run_local_timers
[ 125.324717] <idle>-0 1d.h2 63430566us : raise_softirq <-run_local_timers
[ 125.324717] <idle>-0 1d.h2 63430567us : __raise_softirq_irqoff <-raise_softirq
[ 125.324717] <idle>-0 1d.h2 63430569us : rcu_check_callbacks <-update_process_times
[ 125.324717] <idle>-0 1d.h2 63430570us : rcu_sched_qs <-rcu_check_callbacks
[ 125.324717] <idle>-0 1d.h2 63430572us : rcu_bh_qs <-rcu_check_callbacks
[ 125.324717] <idle>-0 1d.h2 63430574us : cpu_needs_another_gp <-rcu_check_callbacks
[ 125.324717] <idle>-0 1d.h2 63430575us : cpu_needs_another_gp <-rcu_check_callbacks
[ 125.324717] <idle>-0 1d.h2 63430577us : scheduler_tick <-update_process_times
[ 125.324717] <idle>-0 1d.h2 63430578us : ktime_get <-sched_clock_tick
[ 125.324717] <idle>-0 1d.h2 63430578us : _raw_spin_lock <-scheduler_tick
[ 125.324717] <idle>-0 1d.h3 63430579us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] <idle>-0 1d.h3 63430580us : update_rq_clock <-scheduler_tick
[ 125.324717] <idle>-0 1d.h3 63430581us : task_tick_idle <-scheduler_tick
[ 125.324717] <idle>-0 1d.h3 63430581us : update_cpu_load_active <-scheduler_tick
[ 125.324717] <idle>-0 1d.h3 63430581us : sched_avg_update <-update_cpu_load_active
[ 125.324717] <idle>-0 1d.h3 63430582us : _raw_spin_unlock <-scheduler_tick
[ 125.324717] <idle>-0 1d.h3 63430582us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] <idle>-0 1d.h2 63430583us : idle_cpu <-scheduler_tick
[ 125.324717] <idle>-0 1d.h2 63430584us : trigger_load_balance <-scheduler_tick
[ 125.324717] <idle>-0 1d.h2 63430586us : run_posix_cpu_timers <-update_process_times
[ 125.324717] <idle>-0 1d.h2 63430588us : profile_tick <-tick_sched_timer
[ 125.324717] <idle>-0 1d.h2 63430591us : hrtimer_forward <-tick_sched_timer
[ 125.324717] <idle>-0 1d.h2 63430591us : ktime_add_safe <-hrtimer_forward
[ 125.324717] <idle>-0 1d.h2 63430592us : ktime_add_safe <-hrtimer_forward
[ 125.324717] <idle>-0 1d.h2 63430592us : _raw_spin_lock <-__run_hrtimer
[ 125.324717] <idle>-0 1d.h3 63430593us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] <idle>-0 1d.h3 63430593us : enqueue_hrtimer <-__run_hrtimer
[ 125.324717] <idle>-0 1d.h3 63430594us : _raw_spin_unlock <-hrtimer_interrupt
[ 125.324717] <idle>-0 1d.h3 63430595us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] <idle>-0 1d.h2 63430595us : tick_program_event <-hrtimer_interrupt
[ 125.324717] <idle>-0 1d.h2 63430596us : clockevents_program_event <-tick_program_event
[ 125.324717] <idle>-0 1d.h2 63430596us : ktime_get <-clockevents_program_event
[ 125.324717] <idle>-0 1d.h2 63430597us : lapic_next_event <-clockevents_program_event
[ 125.324717] <idle>-0 1d.h2 63430607us : irq_exit <-smp_apic_timer_interrupt
[ 125.324717] <idle>-0 1d..2 63430608us : do_softirq_own_stack <-irq_exit
[ 125.324717] <idle>-0 1d..2 63430609us : __do_softirq <-do_softirq_own_stack
[ 125.324717] <idle>-0 1d..2 63430609us : msecs_to_jiffies <-__do_softirq
[ 125.324717] <idle>-0 1d..2 63430610us : __local_bh_disable_ip <-__do_softirq
[ 125.324717] <idle>-0 1..s2 63430611us : run_timer_softirq <-__do_softirq
[ 125.324717] <idle>-0 1..s2 63430611us : hrtimer_run_pending <-run_timer_softirq
[ 125.324717] <idle>-0 1..s2 63430612us : rcu_bh_qs <-__do_softirq
[ 125.324717] <idle>-0 1d.s2 63430612us : __local_bh_enable <-__do_softirq
[ 125.324717] <idle>-0 1d..2 63430613us : rcu_irq_exit <-irq_exit
[ 125.324717] <idle>-0 1d..2 63430613us : rcu_eqs_enter_common <-rcu_irq_exit
[ 125.324717] <idle>-0 1d..2 63430614us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63430615us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1...2 63430617us : rcu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430618us : rcu_eqs_exit_common <-rcu_idle_exit
[ 125.324717] <idle>-0 1...2 63430618us : arch_cpu_idle_exit <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430619us : arch_cpu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430619us : local_touch_nmi <-arch_cpu_idle_enter
[ 125.324717] <idle>-0 1d..2 63430620us : tick_check_broadcast_expired <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430620us : cpuidle_get_cpu_driver <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430621us : rcu_idle_enter <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430621us : rcu_eqs_enter_common <-rcu_idle_enter
[ 125.324717] <idle>-0 1d..2 63430622us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63430622us : do_nocb_deferred_wakeup <-rcu_eqs_enter_common
[ 125.324717] <idle>-0 1d..2 63430623us : cpuidle_select <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430623us : arch_cpu_idle <-cpu_idle_loop
[ 125.324717] <idle>-0 1d..2 63430626us : default_idle <-arch_cpu_idle
[ 125.324717] CPU:0 [LOST 9092864 EVENTS]
[ 125.324717] swapper/-1 0d..3 63431861us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431861us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431861us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431862us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431862us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431862us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431863us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431863us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431863us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431864us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431864us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431864us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431865us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431865us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431865us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431866us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431866us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431866us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431866us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431867us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431867us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431867us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431868us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431868us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431868us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431869us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431869us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431869us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431870us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431870us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431870us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431871us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431871us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431871us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431872us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431872us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431872us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431873us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431873us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431873us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431873us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431874us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431874us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431874us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431875us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431875us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431875us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431876us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431876us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431876us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431877us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431877us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431877us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431878us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431878us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431878us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431879us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431879us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431879us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431879us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431880us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431880us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431880us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431881us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431881us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431881us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431882us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431882us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431882us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431883us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431883us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431883us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431884us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431884us : console_conditional_schedule <-fbcon_redraw
[ 125.324717] swapper/-1 0d..3 63431885us : fbcon_clear <-fbcon_scroll
[ 125.324717] swapper/-1 0d..3 63431885us : bit_clear <-fbcon_clear
[ 125.324717] swapper/-1 0d..3 63431886us : cirrus_fillrect <-bit_clear
[ 125.324717] swapper/-1 0d..3 63431886us : sys_fillrect <-cirrus_fillrect
[ 125.324717] swapper/-1 0d..3 63431887us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431890us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431893us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431896us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431898us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431901us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431904us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431907us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431909us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431912us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431915us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431918us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431920us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431923us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431926us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431929us : bitfill_unaligned <-sys_fillrect
[ 125.324717] swapper/-1 0d..3 63431931us : cirrus_dirty_update <-cirrus_fillrect
[ 125.324717] swapper/-1 0d..3 63431932us : _raw_spin_lock_irqsave <-cirrus_dirty_update
[ 125.324717] swapper/-1 0d..4 63431932us : do_raw_spin_trylock <-_raw_spin_lock_irqsave
[ 125.324717] swapper/-1 0d..4 63431933us : _raw_spin_unlock_irqrestore <-cirrus_dirty_update
[ 125.324717] swapper/-1 0d..4 63431933us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0d..3 63431934us : notify_write <-lf
[ 125.324717] swapper/-1 0d..3 63431934us : atomic_notifier_call_chain <-notify_write
[ 125.324717] swapper/-1 0d..3 63431934us : __atomic_notifier_call_chain <-atomic_notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431935us : notifier_call_chain <-__atomic_notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431935us : vt_notifier_call <-notifier_call_chain
[ 125.324717] swapper/-1 0d..3 63431936us : notify_write <-vt_console_print
[ 125.324717] swapper/-1 0d..3 63431936us : atomic_notifier_call_chain <-notify_write
[ 125.324717] swapper/-1 0d..3 63431936us : __atomic_notifier_call_chain <-atomic_notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431937us : notifier_call_chain <-__atomic_notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431937us : vt_notifier_call <-notifier_call_chain
[ 125.324717] swapper/-1 0d..3 63431938us : set_cursor <-vt_console_print
[ 125.324717] swapper/-1 0d..3 63431938us : add_softcursor <-set_cursor
[ 125.324717] swapper/-1 0d..3 63431938us : fbcon_cursor <-set_cursor
[ 125.324717] swapper/-1 0d..3 63431939us : fbcon_add_cursor_timer <-fbcon_cursor
[ 125.324717] swapper/-1 0d..3 63431939us : get_color <-fbcon_cursor
[ 125.324717] swapper/-1 0d..3 63431940us : fb_get_color_depth <-get_color
[ 125.324717] swapper/-1 0d..3 63431940us : get_color <-fbcon_cursor
[ 125.324717] swapper/-1 0d..3 63431940us : fb_get_color_depth <-get_color
[ 125.324717] swapper/-1 0d..3 63431940us : bit_cursor <-fbcon_cursor
[ 125.324717] swapper/-1 0d..3 63431941us : fb_get_color_depth <-bit_cursor
[ 125.324717] swapper/-1 0d..3 63431941us : soft_cursor <-bit_cursor
[ 125.324717] swapper/-1 0d..3 63431942us : fb_get_buffer_offset <-soft_cursor
[ 125.324717] swapper/-1 0d..3 63431942us : fb_pad_aligned_buffer <-soft_cursor
[ 125.324717] swapper/-1 0d..3 63431943us : cirrus_imageblit <-soft_cursor
[ 125.324717] swapper/-1 0d..3 63431943us : sys_imageblit <-cirrus_imageblit
[ 125.324717] swapper/-1 0d..3 63431944us : cirrus_dirty_update <-cirrus_imageblit
[ 125.324717] swapper/-1 0d..3 63431945us : _raw_spin_lock_irqsave <-cirrus_dirty_update
[ 125.324717] swapper/-1 0d..4 63431945us : do_raw_spin_trylock <-_raw_spin_lock_irqsave
[ 125.324717] swapper/-1 0d..4 63431945us : _raw_spin_unlock_irqrestore <-cirrus_dirty_update
[ 125.324717] swapper/-1 0d..4 63431946us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0d..3 63431946us : notify_update <-vt_console_print
[ 125.324717] swapper/-1 0d..3 63431947us : atomic_notifier_call_chain <-notify_update
[ 125.324717] swapper/-1 0d..3 63431947us : __atomic_notifier_call_chain <-atomic_notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431947us : notifier_call_chain <-__atomic_notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431947us : vt_notifier_call <-notifier_call_chain
[ 125.324717] swapper/-1 0d..4 63431948us : _raw_spin_trylock <-vt_notifier_call
[ 125.324717] swapper/-1 0d..5 63431948us : do_raw_spin_trylock <-_raw_spin_trylock
[ 125.324717] swapper/-1 0d..5 63431949us : speakup_date <-vt_notifier_call
[ 125.324717] swapper/-1 0d..5 63431949us : _raw_spin_unlock_irqrestore <-vt_notifier_call
[ 125.324717] swapper/-1 0d..5 63431949us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0d..3 63431950us : _raw_spin_unlock <-vt_console_print
[ 125.324717] swapper/-1 0d..3 63431950us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] swapper/-1 0d..2 63431951us : serial8250_console_write <-call_console_drivers
[ 125.324717] swapper/-1 0d..2 63431951us : touch_nmi_watchdog <-serial8250_console_write
[ 125.324717] swapper/-1 0d..2 63431952us : _raw_spin_lock_irqsave <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63431952us : do_raw_spin_trylock <-_raw_spin_lock_irqsave
[ 125.324717] swapper/-1 0d..3 63431953us : io_serial_in <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63431974us : io_serial_out <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63431983us : uart_console_write <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63431983us : serial8250_console_putchar <-uart_console_write
[ 125.324717] swapper/-1 0d..3 63431984us : wait_for_xmitr <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63431984us : io_serial_in <-wait_for_xmitr
[ 125.324717] swapper/-1 0d..3 63431990us : io_serial_out <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432009us : serial8250_console_putchar <-uart_console_write
[ 125.324717] swapper/-1 0d..3 63432010us : wait_for_xmitr <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432010us : io_serial_in <-wait_for_xmitr
[ 125.324717] swapper/-1 0d..3 63432016us : io_serial_out <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432022us : serial8250_console_putchar <-uart_console_write
[ 125.324717] swapper/-1 0d..3 63432023us : wait_for_xmitr <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432023us : io_serial_in <-wait_for_xmitr
[ 125.324717] swapper/-1 0d..3 63432028us : io_serial_out <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432035us : serial8250_console_putchar <-uart_console_write
[ 125.324717] swapper/-1 0d..3 63432035us : wait_for_xmitr <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432035us : io_serial_in <-wait_for_xmitr
[ 125.324717] swapper/-1 0d..3 63432041us : io_serial_out <-serial8250_console_putchar
[ 125.324717] swapper/-1 0d..3 63432047us : wait_for_xmitr <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63432048us : io_serial_in <-wait_for_xmitr
[ 125.324717] swapper/-1 0d..3 63432053us : io_serial_out <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63432057us : _raw_spin_unlock_irqrestore <-serial8250_console_write
[ 125.324717] swapper/-1 0d..3 63432058us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0d..2 63432060us : smp_apic_timer_interrupt <-apic_timer_interrupt
[ 125.324717] swapper/-1 0d..2 63432061us : kvm_guest_apic_eoi_write <-smp_apic_timer_interrupt
[ 125.324717] swapper/-1 0d..2 63432061us : irq_enter <-smp_apic_timer_interrupt
[ 125.324717] swapper/-1 0d..2 63432062us : rcu_irq_enter <-irq_enter
[ 125.324717] swapper/-1 0d.h2 63432062us : local_apic_timer_interrupt <-smp_apic_timer_interrupt
[ 125.324717] swapper/-1 0d.h2 63432063us : hrtimer_interrupt <-local_apic_timer_interrupt
[ 125.324717] swapper/-1 0d.h2 63432063us : _raw_spin_lock <-hrtimer_interrupt
[ 125.324717] swapper/-1 0d.h3 63432064us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] swapper/-1 0d.h3 63432064us : ktime_get_update_offsets_now <-hrtimer_interrupt
[ 125.324717] swapper/-1 0d.h3 63432065us : __run_hrtimer <-hrtimer_interrupt
[ 125.324717] swapper/-1 0d.h3 63432065us : __remove_hrtimer <-__run_hrtimer
[ 125.324717] swapper/-1 0d.h3 63432066us : _raw_spin_unlock <-__run_hrtimer
[ 125.324717] swapper/-1 0d.h3 63432066us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] swapper/-1 0d.h2 63432067us : tick_sched_timer <-__run_hrtimer
[ 125.324717] swapper/-1 0d.h2 63432067us : ktime_get <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h2 63432083us : _raw_spin_lock <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h3 63432083us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] swapper/-1 0d.h3 63432084us : do_timer <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h3 63432084us : calc_global_load <-do_timer
[ 125.324717] swapper/-1 0d.h3 63432085us : _raw_spin_unlock <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h3 63432085us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] swapper/-1 0d.h2 63432086us : update_wall_time <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h2 63432086us : _raw_spin_lock_irqsave <-update_wall_time
[ 125.324717] swapper/-1 0d.h3 63432086us : do_raw_spin_trylock <-_raw_spin_lock_irqsave
[ 125.324717] swapper/-1 0d.h3 63432087us : ntp_tick_length <-update_wall_time
[ 125.324717] swapper/-1 0d.h3 63432088us : ntp_tick_length <-update_wall_time
[ 125.324717] swapper/-1 0d.h3 63432088us : ntp_tick_length <-update_wall_time
[ 125.324717] swapper/-1 0d.h3 63432089us : timekeeping_update <-update_wall_time
[ 125.324717] swapper/-1 0d.h3 63432089us : update_vsyscall <-timekeeping_update
[ 125.324717] swapper/-1 0d.h3 63432090us : raw_notifier_call_chain <-timekeeping_update
[ 125.324717] swapper/-1 0d.h3 63432090us : notifier_call_chain <-raw_notifier_call_chain
[ 125.324717] swapper/-1 0d.h3 63432090us : _raw_spin_unlock_irqrestore <-update_wall_time
[ 125.324717] swapper/-1 0d.h3 63432091us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0d.h2 63432091us : update_process_times <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h2 63432092us : account_process_tick <-update_process_times
[ 125.324717] swapper/-1 0d.h2 63432092us : kvm_steal_clock <-account_process_tick
[ 125.324717] swapper/-1 0d.h2 63432093us : nsecs_to_jiffies <-account_process_tick
[ 125.324717] swapper/-1 0d.h2 63432093us : nsecs_to_jiffies64 <-nsecs_to_jiffies
[ 125.324717] swapper/-1 0d.h2 63432094us : jiffies_to_usecs <-account_process_tick
[ 125.324717] swapper/-1 0d.h2 63432094us : account_steal_time <-account_process_tick
[ 125.324717] swapper/-1 0d.h2 63432095us : account_system_time <-account_process_tick
[ 125.324717] swapper/-1 0d.h2 63432095us : run_local_timers <-update_process_times
[ 125.324717] swapper/-1 0d.h2 63432095us : hrtimer_run_queues <-run_local_timers
[ 125.324717] swapper/-1 0d.h2 63432096us : raise_softirq <-run_local_timers
[ 125.324717] swapper/-1 0d.h2 63432096us : __raise_softirq_irqoff <-raise_softirq
[ 125.324717] swapper/-1 0d.h2 63432097us : rcu_check_callbacks <-update_process_times
[ 125.324717] swapper/-1 0d.h2 63432097us : rcu_bh_qs <-rcu_check_callbacks
[ 125.324717] swapper/-1 0d.h2 63432098us : cpu_needs_another_gp <-rcu_check_callbacks
[ 125.324717] swapper/-1 0d.h2 63432098us : cpu_needs_another_gp <-rcu_check_callbacks
[ 125.324717] swapper/-1 0d.h2 63432099us : scheduler_tick <-update_process_times
[ 125.324717] swapper/-1 0d.h2 63432099us : ktime_get <-sched_clock_tick
[ 125.324717] swapper/-1 0d.h2 63432100us : _raw_spin_lock <-scheduler_tick
[ 125.324717] swapper/-1 0d.h3 63432101us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] swapper/-1 0d.h3 63432101us : update_rq_clock <-scheduler_tick
[ 125.324717] swapper/-1 0d.h3 63432102us : task_tick_fair <-scheduler_tick
[ 125.324717] swapper/-1 0d.h3 63432102us : update_curr <-task_tick_fair
[ 125.324717] swapper/-1 0d.h3 63432103us : update_min_vruntime <-update_curr
[ 125.324717] swapper/-1 0d.h3 63432103us : __compute_runnable_contrib <-task_tick_fair
[ 125.324717] swapper/-1 0d.h3 63432104us : __update_entity_load_avg_contrib <-task_tick_fair
[ 125.324717] swapper/-1 0d.h3 63432104us : update_cfs_rq_blocked_load <-task_tick_fair
[ 125.324717] swapper/-1 0d.h3 63432105us : update_cfs_shares <-task_tick_fair
[ 125.324717] swapper/-1 0d.h3 63432105us : __compute_runnable_contrib <-task_tick_fair
[ 125.324717] swapper/-1 0d.h3 63432105us : update_cpu_load_active <-scheduler_tick
[ 125.324717] swapper/-1 0d.h3 63432106us : sched_avg_update <-update_cpu_load_active
[ 125.324717] swapper/-1 0d.h3 63432106us : _raw_spin_unlock <-scheduler_tick
[ 125.324717] swapper/-1 0d.h3 63432107us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] swapper/-1 0d.h2 63432107us : idle_cpu <-scheduler_tick
[ 125.324717] swapper/-1 0d.h2 63432108us : trigger_load_balance <-scheduler_tick
[ 125.324717] swapper/-1 0d.h2 63432108us : run_posix_cpu_timers <-update_process_times
[ 125.324717] swapper/-1 0d.h2 63432109us : profile_tick <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h2 63432109us : hrtimer_forward <-tick_sched_timer
[ 125.324717] swapper/-1 0d.h2 63432110us : ktime_add_safe <-hrtimer_forward
[ 125.324717] swapper/-1 0d.h2 63432110us : ktime_add_safe <-hrtimer_forward
[ 125.324717] swapper/-1 0d.h2 63432110us : _raw_spin_lock <-__run_hrtimer
[ 125.324717] swapper/-1 0d.h3 63432111us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] swapper/-1 0d.h3 63432111us : enqueue_hrtimer <-__run_hrtimer
[ 125.324717] swapper/-1 0d.h3 63432112us : _raw_spin_unlock <-hrtimer_interrupt
[ 125.324717] swapper/-1 0d.h3 63432112us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] swapper/-1 0d.h2 63432113us : tick_program_event <-hrtimer_interrupt
[ 125.324717] swapper/-1 0d.h2 63432113us : clockevents_program_event <-tick_program_event
[ 125.324717] swapper/-1 0d.h2 63432114us : ktime_get <-clockevents_program_event
[ 125.324717] swapper/-1 0d.h2 63432114us : lapic_next_event <-clockevents_program_event
[ 125.324717] swapper/-1 0d.h2 63432120us : irq_exit <-smp_apic_timer_interrupt
[ 125.324717] swapper/-1 0d..2 63432121us : do_softirq_own_stack <-irq_exit
[ 125.324717] swapper/-1 0d..2 63432121us : __do_softirq <-do_softirq_own_stack
[ 125.324717] swapper/-1 0d..2 63432122us : msecs_to_jiffies <-__do_softirq
[ 125.324717] swapper/-1 0d..2 63432122us : __local_bh_disable_ip <-__do_softirq
[ 125.324717] swapper/-1 0..s2 63432123us : run_timer_softirq <-__do_softirq
[ 125.324717] swapper/-1 0..s2 63432123us : hrtimer_run_pending <-run_timer_softirq
[ 125.324717] swapper/-1 0..s2 63432124us : _raw_spin_lock_irq <-run_timer_softirq
[ 125.324717] swapper/-1 0d.s3 63432124us : do_raw_spin_trylock <-_raw_spin_lock_irq
[ 125.324717] swapper/-1 0d.s3 63432124us : _raw_spin_unlock_irq <-run_timer_softirq
[ 125.324717] swapper/-1 0d.s3 63432125us : do_raw_spin_unlock <-_raw_spin_unlock_irq
[ 125.324717] swapper/-1 0..s2 63432125us : rcu_bh_qs <-__do_softirq
[ 125.324717] swapper/-1 0d.s2 63432126us : __local_bh_enable <-__do_softirq
[ 125.324717] swapper/-1 0d..2 63432126us : rcu_irq_exit <-irq_exit
[ 125.324717] swapper/-1 0...2 63432127us : _raw_spin_lock_irqsave <-console_unlock
[ 125.324717] swapper/-1 0d..3 63432127us : do_raw_spin_trylock <-_raw_spin_lock_irqsave
[ 125.324717] swapper/-1 0d..3 63432128us : log_from_idx <-console_unlock
[ 125.324717] swapper/-1 0d..3 63432128us : log_next <-console_unlock
[ 125.324717] swapper/-1 0d..3 63432129us : _raw_spin_unlock <-console_unlock
[ 125.324717] swapper/-1 0d..3 63432129us : do_raw_spin_unlock <-_raw_spin_unlock
[ 125.324717] swapper/-1 0d..2 63432130us : up <-console_unlock
[ 125.324717] swapper/-1 0d..2 63432130us : _raw_spin_lock_irqsave <-up
[ 125.324717] swapper/-1 0d..3 63432130us : do_raw_spin_trylock <-_raw_spin_lock_irqsave
[ 125.324717] swapper/-1 0d..3 63432131us : _raw_spin_unlock_irqrestore <-up
[ 125.324717] swapper/-1 0d..3 63432131us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0d..2 63432132us : _raw_spin_lock <-console_unlock
[ 125.324717] swapper/-1 0d..3 63432132us : do_raw_spin_trylock <-_raw_spin_lock
[ 125.324717] swapper/-1 0d..3 63432132us : _raw_spin_unlock_irqrestore <-console_unlock
[ 125.324717] swapper/-1 0d..3 63432133us : do_raw_spin_unlock <-_raw_spin_unlock_irqrestore
[ 125.324717] swapper/-1 0...2 63432133us : wake_up_klogd <-console_unlock
[ 125.324717] swapper/-1 0...1 63432134us : mutex_lock_nested <-unregister_ftrace_function
[ 125.324717] swapper/-1 0...1 63432134us : __might_sleep <-mutex_lock_nested
[ 125.324717] swapper/-1 0...1 63432135us : _cond_resched <-mutex_lock_nested
[ 125.324717] ---------------------------------
[ 187.060106] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 187.068476] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 187.072041] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 187.075717] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 187.079654] ??? Writer stall state 8 g4722 c4722 f0x0
[ 187.082797] rcu_sched: wait state: 1 ->state: 0x1
[ 187.086045] rcu_bh: wait state: 1 ->state: 0x1
[ 247.088054] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 247.095358] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 247.097933] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 247.100823] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 247.104652] ??? Writer stall state 8 g4722 c4722 f0x0
[ 247.107894] rcu_sched: wait state: 1 ->state: 0x1
[ 247.111131] rcu_bh: wait state: 1 ->state: 0x1
[ 307.112081] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 307.118333] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 307.121226] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 307.123908] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 307.126903] ??? Writer stall state 8 g4722 c4722 f0x0
[ 307.129564] rcu_sched: wait state: 1 ->state: 0x1
[ 307.132169] rcu_bh: wait state: 1 ->state: 0x1
[ 367.136055] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 367.146491] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 367.150962] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 367.157202] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 367.162692] ??? Writer stall state 8 g4726 c4726 f0x0
[ 367.166644] rcu_sched: wait state: 1 ->state: 0x1
[ 367.172189] rcu_bh: wait state: 1 ->state: 0x1
[ 427.176110] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 427.185423] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 427.190218] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 427.196403] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 427.200948] ??? Writer stall state 8 g4726 c4726 f0x0
[ 427.204845] rcu_sched: wait state: 1 ->state: 0x1
[ 427.208730] rcu_bh: wait state: 1 ->state: 0x1
[ 487.212085] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 487.222200] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 487.226971] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 487.231682] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 487.236502] ??? Writer stall state 8 g4726 c4726 f0x0
[ 487.240752] rcu_sched: wait state: 1 ->state: 0x1
[ 487.244977] rcu_bh: wait state: 1 ->state: 0x1
[ 547.252045] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 547.261827] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 547.266499] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 547.271123] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 547.275879] ??? Writer stall state 8 g4726 c4726 f0x0
[ 547.280033] rcu_sched: wait state: 1 ->state: 0x1
[ 547.284205] rcu_bh: wait state: 1 ->state: 0x1
[ 607.284918] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 607.295088] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 607.299847] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 607.304487] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 607.309282] ??? Writer stall state 8 g4726 c4726 f0x0
[ 607.313460] rcu_sched: wait state: 1 ->state: 0x1
[ 607.317667] rcu_bh: wait state: 1 ->state: 0x1
[ 667.320068] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 667.329475] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 667.333852] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 667.338232] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 667.342662] ??? Writer stall state 8 g4726 c4726 f0x0
[ 667.346614] rcu_sched: wait state: 1 ->state: 0x1
[ 667.350504] rcu_bh: wait state: 1 ->state: 0x1
[ 727.352049] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 727.361559] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 727.365918] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 727.370278] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 727.374717] ??? Writer stall state 8 g4726 c4726 f0x0
[ 727.378665] rcu_sched: wait state: 1 ->state: 0x1
[ 727.382552] rcu_bh: wait state: 1 ->state: 0x1
[ 787.384049] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 787.392540] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 787.397114] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 787.401630] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 787.406235] ??? Writer stall state 8 g4726 c4726 f0x0
[ 787.410326] rcu_sched: wait state: 1 ->state: 0x1
[ 787.413386] rcu_bh: wait state: 1 ->state: 0x1
[ 847.416068] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 847.422370] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 847.425378] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 847.428571] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 847.431963] ??? Writer stall state 8 g4726 c4726 f0x0
[ 847.435005] rcu_sched: wait state: 1 ->state: 0x1
[ 847.437707] rcu_bh: wait state: 1 ->state: 0x1
[ 907.440040] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 907.446532] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 907.449418] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 907.452380] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 907.455333] ??? Writer stall state 8 g4726 c4726 f0x0
[ 907.457946] rcu_sched: wait state: 1 ->state: 0x1
[ 907.460533] rcu_bh: wait state: 1 ->state: 0x1
[ 967.460073] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 967.470975] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 967.477720] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 967.482706] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 967.487414] ??? Writer stall state 8 g4726 c4726 f0x0
[ 967.491582] rcu_sched: wait state: 1 ->state: 0x1
[ 967.495460] rcu_bh: wait state: 1 ->state: 0x1
[ 1027.496080] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1027.506706] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1027.511718] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1027.516531] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1027.521526] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1027.525830] rcu_sched: wait state: 1 ->state: 0x1
[ 1027.530151] rcu_bh: wait state: 1 ->state: 0x1
[ 1087.532066] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1087.542253] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1087.547062] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1087.551764] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1087.556631] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1087.560942] rcu_sched: wait state: 1 ->state: 0x1
[ 1087.565209] rcu_bh: wait state: 1 ->state: 0x1
[ 1147.568045] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1147.577601] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1147.582030] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1147.586439] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1147.590948] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1147.594940] rcu_sched: wait state: 1 ->state: 0x1
[ 1147.598901] rcu_bh: wait state: 1 ->state: 0x1
[ 1207.600071] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1207.607759] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1207.610906] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1207.613920] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1207.617302] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1207.620383] rcu_sched: wait state: 1 ->state: 0x1
[ 1207.623586] rcu_bh: wait state: 1 ->state: 0x1
[ 1267.624044] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1267.631902] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1267.635240] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1267.640162] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1267.645480] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1267.649256] rcu_sched: wait state: 1 ->state: 0x1
[ 1267.652699] rcu_bh: wait state: 1 ->state: 0x1
[ 1327.652070] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1327.659862] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1327.664299] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1327.668771] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1327.673290] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1327.677327] rcu_sched: wait state: 1 ->state: 0x1
[ 1327.681337] rcu_bh: wait state: 1 ->state: 0x1
[ 1387.684076] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1387.690869] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1387.693788] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1387.698084] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1387.701230] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1387.703849] rcu_sched: wait state: 1 ->state: 0x1
[ 1387.706548] rcu_bh: wait state: 1 ->state: 0x1
[ 1447.712036] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1447.721897] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1447.726465] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1447.731086] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1447.735870] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1447.740138] rcu_sched: wait state: 1 ->state: 0x1
[ 1447.744334] rcu_bh: wait state: 1 ->state: 0x1
[ 1507.748075] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1507.754227] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1507.758388] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1507.761510] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1507.765405] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1507.769042] rcu_sched: wait state: 1 ->state: 0x1
[ 1507.772717] rcu_bh: wait state: 1 ->state: 0x1
[ 1567.772077] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1567.782368] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1567.787010] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1567.791491] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1567.797769] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1567.803318] rcu_sched: wait state: 1 ->state: 0x1
[ 1567.808331] rcu_bh: wait state: 1 ->state: 0x1
[ 1627.812066] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1627.822956] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1627.828712] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1627.835089] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1627.841095] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1627.845634] rcu_sched: wait state: 1 ->state: 0x1
[ 1627.850029] rcu_bh: wait state: 1 ->state: 0x1
[ 1687.852046] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1687.860990] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1687.865168] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1687.869354] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1687.873739] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1687.877628] rcu_sched: wait state: 1 ->state: 0x1
[ 1687.881390] rcu_bh: wait state: 1 ->state: 0x1
[ 1747.884083] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1747.893152] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1747.897533] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1747.901854] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1747.906280] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1747.910218] rcu_sched: wait state: 1 ->state: 0x1
[ 1747.914188] rcu_bh: wait state: 1 ->state: 0x1
[ 1807.920044] rcu-torture: rtc: c2c58b30 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 1
[ 1807.929306] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 1807.933765] rcu-torture: Reader Batch: 2 0 0 0 0 0 0 0 0 0 0
[ 1807.938189] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 1807.942772] ??? Writer stall state 8 g4726 c4726 f0x0
[ 1807.946864] rcu_sched: wait state: 1 ->state: 0x1
[ 1807.950864] rcu_bh: wait state: 1 ->state: 0x1

BUG: kernel boot hang
Elapsed time: 1810
qemu-system-i386 -enable-kvm -kernel /kernel/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/vmlinuz-3.18.0-rc2-g05da589 -append 'user=lkp job=/lkp/scheduled/vm-kbuild-yocto-i386-62/rand_boot-1-yocto-minimal-i386.cgz-i386-randconfig-ha2-1109-05da5898a96c05e32aa9850c9cd89eef29471b13-1.yaml ARCH=i386 BOOT_IMAGE=/kernel/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/vmlinuz-3.18.0-rc2-g05da589 kconfig=i386-randconfig-ha2-1109 commit=05da5898a96c05e32aa9850c9cd89eef29471b13 branch=pshelar-openvswitch/net_next_ovs root=/dev/ram0 max_uptime=3600 RESULT_ROOT=/result/vm-kbuild-yocto-i386/boot/1/yocto-minimal-i386.cgz/i386-randconfig-ha2-1109/05da5898a96c05e32aa9850c9cd89eef29471b13/0 ip=::::vm-kbuild-yocto-i386-62::dhcp earlyprintk=ttyS0,115200 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8' -initrd /fs/sde1/initrd-vm-kbuild-yocto-i386-62 -m 320 -smp 2 -net nic,vlan=1,model=e1000 -net user,vlan=1 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/sde1/disk0-vm-kbuild-yocto-i386-62,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-i386-62 -serial file:/dev/shm/kboot/serial-vm-kbuild-yocto-i386-62 -daemonize -display none -monitor null

Next message: Yuanhan Liu: "[LKP] [net] 4ed2d765dfa:"
Previous message: Arnd Bergmann: "Re: [PATCH v2 1/5] misc: sensorhub: Add sensorhub driver"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]