early console in setup code
[    0.000000] Linux version 4.12.0-02191-gde8a3b1 (kbuild@lkp-wsm-ep1) (gcc version 6.2.0 20160901 (Debian 6.2.0-3) ) #1 PREEMPT Fri Jul 14 05:51:39 CST 2017
[    0.000000] Command line: ip=::::vm-kbuild-yocto-ia32-26::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.yaml ARCH=x86_64 kconfig=x86_64-randconfig-r0-07132314 branch=linux-devel/devel-catchup-201707140302 commit=de8a3b1249d6d6eb910e271dc0d18bafd032172d BOOT_IMAGE=/pkg/linux/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/vmlinuz-4.12.0-02191-gde8a3b1 max_uptime=1500 RESULT_ROOT=/result/trinity/300s/vm-kbuild-yocto-ia32/yocto-tiny-i386-2016-04-22.cgz/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/0 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 console=ttyS
[    0.000000] KERNEL supported cpus:
[    0.000000]   Centaur CentaurHauls
[    0.000000] CPU: vendor_id 'GenuineIntel' unknown, using generic init.
[    0.000000] CPU: Your system may be unstable.
[    0.000000] x86/fpu: x87 FPU will use FXSAVE
[    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-0x000000001ffddfff] usable
[    0.000000] BIOS-e820: [mem 0x000000001ffde000-0x000000001fffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] debug: ignoring loglevel setting.
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] Hypervisor detected: KVM
[    0.000000] tsc: Fast TSC calibration failed
[    0.000000] tsc: Using PIT calibration value
[    0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] e820: last_pfn = 0x1ffde max_arch_pfn = 0x400000000
[    0.000000] Base memory trampoline at [ffff880000099000] 99000 size 24576
[    0.000000] BRK [0x03afa000, 0x03afafff] PGTABLE
[    0.000000] BRK [0x03afb000, 0x03afbfff] PGTABLE
[    0.000000] BRK [0x03afc000, 0x03afcfff] PGTABLE
[    0.000000] BRK [0x03afd000, 0x03afdfff] PGTABLE
[    0.000000] RAMDISK: [mem 0x1f45c000-0x1ffcffff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F69B0 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x000000001FFE18DC 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x000000001FFE17B8 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x000000001FFE0040 001778 (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x000000001FFE0000 000040
[    0.000000] ACPI: APIC 0x000000001FFE182C 000078 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] ACPI: HPET 0x000000001FFE18A4 000038 (v01 BOCHS  BXPCHPET 00000001 BXPC 00000001)
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] mapped APIC to ffffffffff5fc000 (        fee00000)
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:1ffdd001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 1165010910 cycles
[    0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] Zone ranges:
[    0.000000]   DMA32    [mem 0x0000000000001000-0x000000001ffddfff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.000000]   node   0: [mem 0x0000000000100000-0x000000001ffddfff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001ffddfff]
[    0.000000] On node 0 totalpages: 130940
[    0.000000]   DMA32 zone: 1792 pages used for memmap
[    0.000000]   DMA32 zone: 21 pages reserved
[    0.000000]   DMA32 zone: 130940 pages, LIFO batch:31
[    0.000000] ACPI: PM-Timer IO Port: 0x608
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    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] mapped IOAPIC to ffffffffff5fb000 (fec00000)
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 1a2ea40
[    0.000000] e820: [mem 0x20000000-0xfeffbfff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 129127
[    0.000000] Kernel command line: ip=::::vm-kbuild-yocto-ia32-26::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.yaml ARCH=x86_64 kconfig=x86_64-randconfig-r0-07132314 branch=linux-devel/devel-catchup-201707140302 commit=de8a3b1249d6d6eb910e271dc0d18bafd032172d BOOT_IMAGE=/pkg/linux/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/vmlinuz-4.12.0-02191-gde8a3b1 max_uptime=1500 RESULT_ROOT=/result/trinity/300s/vm-kbuild-yocto-ia32/yocto-tiny-i386-2016-04-22.cgz/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/0 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 conso
[    0.000000] sysrq: sysrq always enabled.
[    0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.000000] Memory: 458876K/523760K available (4620K kernel code, 2635K rwdata, 2832K rodata, 664K init, 30416K bss, 64884K reserved, 0K cma-reserved)
[    0.004000] Running RCU self tests
[    0.004000] Preemptible hierarchical RCU implementation.
[    0.004000] 	RCU event tracing is enabled.
[    0.004000] 	RCU lockdep checking is enabled.
[    0.004000] 	RCU priority boosting: priority 1 delay 500 ms.
[    0.004000] 	RCU CPU stall warnings timeout set to 100 (rcu_cpu_stall_timeout).
[    0.004000] 	Tasks RCU enabled.
[    0.004000] NR_IRQS: 4352, nr_irqs: 48, preallocated irqs: 16
[    0.004000] console [ttyS0] enabled
[    0.004000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.004000] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.004000] ... MAX_LOCK_DEPTH:          48
[    0.004000] ... MAX_LOCKDEP_KEYS:        8191
[    0.004000] ... CLASSHASH_SIZE:          4096
[    0.004000] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.004000] ... MAX_LOCKDEP_CHAINS:      65536
[    0.004000] ... CHAINHASH_SIZE:          32768
[    0.004000]  memory used by lock dependency info: 8671 kB
[    0.004000]  per task-struct memory footprint: 2688 bytes
[    0.004000] ------------------------
[    0.004000] | Locking API testsuite:
[    0.004000] ----------------------------------------------------------------------------
[    0.004000]                                  | spin |wlock |rlock |mutex | wsem | rsem |
[    0.004000]   --------------------------------------------------------------------------
[    0.004000]                      A-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]                  A-B-B-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]              A-B-B-C-C-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]              A-B-C-A-B-C deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]          A-B-B-C-C-D-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]          A-B-C-D-B-D-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]          A-B-C-D-B-C-D-A deadlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]                     double unlock:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]                   initialize held:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]   --------------------------------------------------------------------------
[    0.004000]               recursive read-lock:             |  ok  |             |  ok  |
[    0.004000]            recursive read-lock #2:             |  ok  |             |  ok  |
[    0.004000]             mixed read-write-lock:             |  ok  |             |  ok  |
[    0.004000]             mixed write-read-lock:             |  ok  |             |  ok  |
[    0.004000]   --------------------------------------------------------------------------
[    0.004000]      hard-irqs-on + irq-safe-A/12:  ok  |  ok  |  ok  |
[    0.004000]      soft-irqs-on + irq-safe-A/12:  ok  |  ok  |  ok  |
[    0.004000]      hard-irqs-on + irq-safe-A/21:  ok  |  ok  |  ok  |
[    0.004000]      soft-irqs-on + irq-safe-A/21:  ok  |  ok  |  ok  |
[    0.004000]        sirq-safe-A => hirqs-on/12:  ok  |  ok  |  ok  |
[    0.004000]        sirq-safe-A => hirqs-on/21:  ok  |  ok  |  ok  |
[    0.004000]          hard-safe-A + irqs-on/12:  ok  |  ok  |  ok  |
[    0.004000]          soft-safe-A + irqs-on/12:  ok  |  ok  |  ok  |
[    0.004000]          hard-safe-A + irqs-on/21:  ok  |  ok  |  ok  |
[    0.004000]          soft-safe-A + irqs-on/21:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #1/123:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #1/123:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #1/132:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #1/132:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #1/213:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #1/213:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #1/231:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #1/231:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #1/312:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #1/312:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #1/321:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #1/321:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #2/123:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #2/123:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #2/132:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #2/132:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #2/213:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #2/213:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #2/231:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #2/231:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #2/312:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #2/312:  ok  |  ok  |  ok  |
[    0.004000]     hard-safe-A + unsafe-B #2/321:  ok  |  ok  |  ok  |
[    0.004000]     soft-safe-A + unsafe-B #2/321:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq lock-inversion/123:  ok  |  ok  |  ok  |
[    0.004000]       soft-irq lock-inversion/123:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq lock-inversion/132:  ok  |  ok  |  ok  |
[    0.004000]       soft-irq lock-inversion/132:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq lock-inversion/213:  ok  |  ok  |  ok  |
[    0.004000]       soft-irq lock-inversion/213:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq lock-inversion/231:  ok  |  ok  |  ok  |
[    0.004000]       soft-irq lock-inversion/231:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq lock-inversion/312:  ok  |  ok  |  ok  |
[    0.004000]       soft-irq lock-inversion/312:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq lock-inversion/321:  ok  |  ok  |  ok  |
[    0.004000]       soft-irq lock-inversion/321:  ok  |  ok  |  ok  |
[    0.004000]       hard-irq read-recursion/123:  ok  |
[    0.004000]       soft-irq read-recursion/123:  ok  |
[    0.004000]       hard-irq read-recursion/132:  ok  |
[    0.004000]       soft-irq read-recursion/132:  ok  |
[    0.004000]       hard-irq read-recursion/213:  ok  |
[    0.004000]       soft-irq read-recursion/213:  ok  |
[    0.004000]       hard-irq read-recursion/231:  ok  |
[    0.004000]       soft-irq read-recursion/231:  ok  |
[    0.004000]       hard-irq read-recursion/312:  ok  |
[    0.004000]       soft-irq read-recursion/312:  ok  |
[    0.004000]       hard-irq read-recursion/321:  ok  |
[    0.004000]       soft-irq read-recursion/321:  ok  |
[    0.004000]   --------------------------------------------------------------------------
[    0.004000]   | Wound/wait tests |
[    0.004000]   ---------------------
[    0.004000]                   ww api failures:  ok  |  ok  |  ok  |
[    0.004000]                ww contexts mixing:  ok  |  ok  |
[    0.004000]              finishing ww context:  ok  |  ok  |  ok  |  ok  |
[    0.004000]                locking mismatches:  ok  |  ok  |  ok  |
[    0.004000]                  EDEADLK handling:  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |  ok  |
[    0.004000]            spinlock nest unlocked:  ok  |
[    0.004000]   -----------------------------------------------------
[    0.004000]                                  |block | try  |context|
[    0.004000]   -----------------------------------------------------
[    0.004000]                           context:  ok  |  ok  |  ok  |
[    0.004000]                               try:  ok  |  ok  |  ok  |
[    0.004000]                             block:  ok  |  ok  |  ok  |
[    0.004000]                          spinlock:  ok  |  ok  |  ok  |
[    0.004000] -------------------------------------------------------
[    0.004000] Good, all 256 testcases passed! |
[    0.004000] ---------------------------------
[    0.004000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.004000] hpet clockevent registered
[    0.004016] tsc: Detected 2693.504 MHz processor
[    0.004707] Calibrating delay loop (skipped) preset value.. 5387.00 BogoMIPS (lpj=10774016)
[    0.005210] pid_max: default: 4096 minimum: 301
[    0.008027] ACPI: Core revision 20170303
[    0.020957] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.021924] Security Framework initialized
[    0.022533] Yama: becoming mindful.
[    0.023076] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)
[    0.024024] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)
[    0.026017] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.027008] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.028014] CPU: GenuineIntel Westmere E56xx/L56xx/X56xx (Nehalem-C) (family: 0x6, model: 0x2c, stepping: 0x1)
[    0.030790] Performance Events: no PMU driver, software events only.
[    0.032185] Hierarchical SRCU implementation.
[    0.033341] enabled ExtINT on CPU#0
[    0.034763] ENABLING IO-APIC IRQs
[    0.035284] init IO_APIC IRQs
[    0.036020]  apic 0 pin 0 not connected
[    0.036859] IOAPIC[0]: Set routing entry (0-1 -> 0x31 -> IRQ 1 Mode:0 Active:0 Dest:1)
[    0.038336] IOAPIC[0]: Set routing entry (0-2 -> 0x30 -> IRQ 0 Mode:0 Active:0 Dest:1)
[    0.039793] IOAPIC[0]: Set routing entry (0-3 -> 0x33 -> IRQ 3 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-4 -> 0x34 -> IRQ 4 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-5 -> 0x35 -> IRQ 5 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-6 -> 0x36 -> IRQ 6 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-7 -> 0x37 -> IRQ 7 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-8 -> 0x38 -> IRQ 8 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-9 -> 0x39 -> IRQ 9 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-10 -> 0x3a -> IRQ 10 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-11 -> 0x3b -> IRQ 11 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-12 -> 0x3c -> IRQ 12 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-13 -> 0x3d -> IRQ 13 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-14 -> 0x3e -> IRQ 14 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-15 -> 0x3f -> IRQ 15 Mode:0 Active:0 Dest:1)
[    0.040000]  apic 0 pin 16 not connected
[    0.040000]  apic 0 pin 17 not connected
[    0.040000]  apic 0 pin 18 not connected
[    0.040000]  apic 0 pin 19 not connected
[    0.040000]  apic 0 pin 20 not connected
[    0.040000]  apic 0 pin 21 not connected
[    0.040000]  apic 0 pin 22 not connected
[    0.040000]  apic 0 pin 23 not connected
[    0.040000] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.040000] Using local APIC timer interrupts.
[    0.040000] calibrating APIC timer ...
[    0.040000] ... lapic delta = 8999643
[    0.040000] ... PM-Timer delta = 515437
[    0.040000] APIC calibration not consistent with PM-Timer: 143ms instead of 100ms
[    0.040000] APIC delta adjusted to PM-Timer: 6249955 (8999643)
[    0.040000] TSC delta adjusted to PM-Timer: 269351899 (387854124)
[    0.040000] ..... delta 6249955
[    0.040000] ..... mult: 268433523
[    0.040000] ..... calibration result: 3999971
[    0.040000] ..... CPU clock speed is 2693.2075 MHz.
[    0.040000] ..... host bus clock speed is 999.3971 MHz.
[    0.040580] devtmpfs: initialized
[    0.042673] workqueue: round-robin CPU selection forced, expect performance impact
[    0.044256] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.045993] futex hash table entries: 16 (order: -2, 1536 bytes)
[    0.047325] pinctrl core: initialized pinctrl subsystem
[    0.048460] regulator-dummy: no parameters
[    0.049781] NET: Registered protocol family 16
[    0.057203] cpuidle: using governor menu
[    0.060365] ACPI: bus type PCI registered
[    0.061245] PCI: Using configuration type 1 for base access
[    0.086815] ACPI: Added _OSI(Module Device)
[    0.087613] ACPI: Added _OSI(Processor Device)
[    0.088044] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.088816] ACPI: Added _OSI(Processor Aggregator Device)
[    0.105463] ACPI: Interpreter enabled
[    0.106220] ACPI: (supports S0 S3 S5)
[    0.108036] ACPI: Using IOAPIC for interrupt routing
[    0.109033] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.157233] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.158389] acpi PNP0A03:00: _OSC: OS supports [Segments]
[    0.159416] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    0.165851] PCI host bridge to bus 0000:00
[    0.166451] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.167418] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.168020] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.169265] pci_bus 0000:00: root bus resource [mem 0x20000000-0xfebfffff window]
[    0.172023] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.176106] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
[    0.184711] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
[    0.186786] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
[    0.200011] pci 0000:00:01.1: reg 0x20: [io  0xc080-0xc08f]
[    0.202925] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
[    0.204020] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
[    0.208009] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
[    0.209288] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
[    0.216111] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
[    0.220151] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
[    0.224027] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
[    0.226247] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000
[    0.236023] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref]
[    0.248023] pci 0000:00:02.0: reg 0x18: [mem 0xfebf0000-0xfebf0fff]
[    0.272019] pci 0000:00:02.0: reg 0x30: [mem 0xfebe0000-0xfebeffff pref]
[    0.273924] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000
[    0.280016] pci 0000:00:03.0: reg 0x10: [mem 0xfebc0000-0xfebdffff]
[    0.282791] pci 0000:00:03.0: reg 0x14: [io  0xc000-0xc03f]
[    0.298646] pci 0000:00:03.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref]
[    0.304632] pci 0000:00:04.0: [1af4:1001] type 00 class 0x010000
[    0.312015] pci 0000:00:04.0: reg 0x10: [io  0xc040-0xc07f]
[    0.320016] pci 0000:00:04.0: reg 0x14: [mem 0xfebf1000-0xfebf1fff]
[    0.341396] pci 0000:00:04.0: reg 0x20: [mem 0xfe000000-0xfe7fffff 64bit pref]
[    0.350671] pci 0000:00:05.0: [8086:25ab] type 00 class 0x088000
[    0.353059] pci 0000:00:05.0: reg 0x10: [mem 0xfebf2000-0xfebf200f]
[    0.369022] pci_bus 0000:00: on NUMA node 0
[    0.376460] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    0.377752] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    0.380318] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    0.381562] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    0.382560] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    0.388947] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[    0.389807] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[    0.392017] pci 0000:00:02.0: vgaarb: bridge control possible
[    0.392847] vgaarb: loaded
[    0.393844] ACPI: bus type USB registered
[    0.396136] usbcore: registered new interface driver usbfs
[    0.396984] usbcore: registered new interface driver hub
[    0.397811] usbcore: registered new device driver usb
[    0.398856] FPGA manager framework
[    0.399520] PCI: Using ACPI for IRQ routing
[    0.400015] PCI: pci_cache_line_size set to 64 bytes
[    0.400895] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
[    0.401748] e820: reserve RAM buffer [mem 0x1ffde000-0x1fffffff]
[    0.405125] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[    0.408011] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[    0.414886] clocksource: Switched to clocksource kvm-clock
[    0.415687] VFS: Disk quotas dquot_6.6.0
[    0.415687] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.416578] FS-Cache: Loaded
[    0.417069] pnp: PnP ACPI init
[    0.417755] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active)
[    0.418842] pnp 00:01: Plug and Play ACPI device, IDs PNP0303 (active)
[    0.424028] pnp 00:02: Plug and Play ACPI device, IDs PNP0f13 (active)
[    0.425316] pnp 00:03: [dma 2]
[    0.426005] pnp 00:03: Plug and Play ACPI device, IDs PNP0700 (active)
[    0.427438] pnp 00:04: Plug and Play ACPI device, IDs PNP0400 (active)
[    0.436891] pnp 00:05: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.438026] pnp 00:06: Plug and Play ACPI device, IDs PNP0501 (active)
[    0.445330] pnp: PnP ACPI: found 7 devices
[    0.460889] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.462201] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    0.463068] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
[    0.468070] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[    0.469324] pci_bus 0000:00: resource 7 [mem 0x20000000-0xfebfffff window]
[    0.470865] NET: Registered protocol family 1
[    0.471672] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.476682] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    0.477518] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    0.478436] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    0.479640] PCI: CLS 0 bytes, default 64
[    0.487470] Unpacking initramfs...
[    3.740103] Freeing initrd memory: 11728K
[    3.751613] cryptomgr_test (22) used greatest stack depth: 14968 bytes left
[    3.754291] AVX or AES-NI instructions are not detected.
[    3.755271] CPU feature 'AVX registers' is not supported.
[    3.756275] CPU feature 'AVX registers' is not supported.
[    3.757249] AVX2 or AES-NI instructions are not detected.
[    3.758219] AVX2 instructions are not detected.
[    3.760740] 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/1 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
[    3.774936] cryptomgr_test (23) used greatest stack depth: 14792 bytes left
[    3.776229] rcu-torture: Creating rcu_torture_writer task
[    3.777305] rcu-torture: rcu_torture_writer task started
[    3.786961] rcu-torture: GP expediting controlled from boot/sysfs for rcu,
[    3.788108] rcu-torture: Disabled dynamic grace-period expediting.
[    3.789294] rcu-torture: Creating rcu_torture_fakewriter task
[    3.790233] rcu-torture: rcu_torture_fakewriter task started
[    3.791238] rcu-torture: Creating rcu_torture_fakewriter task
[    3.792313] rcu-torture: Creating rcu_torture_fakewriter task
[    3.793407] rcu-torture: Creating rcu_torture_fakewriter task
[    3.794502] rcu-torture: rcu_torture_fakewriter task started
[    3.795539] rcu-torture: rcu_torture_fakewriter task started
[    3.808116] rcu-torture: Creating rcu_torture_reader task
[    3.808181] rcu-torture: rcu_torture_fakewriter task started
[    3.808217] rcu-torture: Creating rcu_torture_stats task
[    3.808259] rcu-torture: rcu_torture_reader task started
[    3.808276] rcu-torture: Creating torture_shuffle task
[    3.808312] rcu-torture: rcu_torture_stats task started
[    3.808332] rcu-torture: Creating torture_stutter task
[    3.808370] rcu-torture: torture_shuffle task started
[    3.808405] rcu-torture: Creating rcu_torture_boost task
[    3.808489] rcu-torture: Creating rcu_torture_cbflood task
[    3.809689] Initialise system trusted keyrings
[    3.809742] Key type blacklist registered
[    3.809817] workingset: timestamp_bits=62 max_order=17 bucket_order=0
[    3.816323] Key type asymmetric registered
[    3.816336] Asymmetric key parser 'x509' registered
[    3.816341] start plist test
[    3.818296] end plist test
[    3.818299] test_string_helpers: Running tests...
[    3.821479] test_hexdump: all 1184 tests passed
[    3.821647] test_firmware: interface ready
[    3.822610] Running rhashtable test nelem=8, max_size=0, shrinking=0
[    3.822612] Test 00:
[    3.826315] rcu-torture: rcu_torture_cbflood task started
[    3.826322] rcu-torture: torture_stutter task started
[    3.826328] rcu-torture: rcu_torture_boost started
[    3.827207]   Adding 50000 keys
[    3.956827] ------------[ cut here ]------------
[    3.957710] WARNING: CPU: 0 PID: 1 at kernel/rcu/tree_plugin.h:508 rcu_read_unlock_special+0x1ef/0x2a4
[    3.959690] Modules linked in:
[    3.960199] CPU: 0 PID: 1 Comm: swapper Not tainted 4.12.0-02191-gde8a3b1 #1
[    3.960199] task: ffff88000002c000 task.stack: ffff880000030000
[    3.960199] RIP: 0010:rcu_read_unlock_special+0x1ef/0x2a4
[    3.960199] RSP: 0000:ffff880000033d10 EFLAGS: 00010017
[    3.960199] RAX: ffff88000002c2d8 RBX: 0000000000000202 RCX: ffffffff81c060c8
[    3.960199] RDX: 0000000000000000 RSI: ffffffff81c060c8 RDI: ffffffff81c06020
[    3.960199] RBP: ffff880000033d40 R08: 00000001eff822d2 R09: 0000000000000000
[    3.960199] R10: 0000000000000001 R11: 0000000000000000 R12: ffff88000002c000
[    3.960199] R13: ffff88000002c000 R14: ffffffff81c06020 R15: 0000000000000000
[    3.960199] FS:  0000000000000000(0000) GS:ffffffff81a2a000(0000) knlGS:0000000000000000
[    3.960199] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    3.960199] CR2: 0000000000000000 CR3: 0000000001a17000 CR4: 00000000000006b0
[    3.960199] Call Trace:
[    3.960199]  __rcu_read_unlock+0x3e/0x5f
[    3.960199]  insert_retry+0x1fa/0x4cb
[    3.960199]  test_rhashtable+0x75/0x7ed
[    3.960199]  ? lockdep_init_map+0xbb/0x1bd
[    3.960199]  test_rht_init+0xdd/0x3d4
[    3.960199]  ? test_rhashtable+0x7ed/0x7ed
[    3.960199]  ? set_debug_rodata+0x12/0x12
[    3.960199]  do_one_initcall+0x89/0x132
[    3.960199]  ? set_debug_rodata+0x12/0x12
[    3.960199]  kernel_init_freeable+0x107/0x185
[    3.960199]  ? rest_init+0x221/0x221
[    3.960199]  kernel_init+0x9/0xe6
[    3.960199]  ret_from_fork+0x2a/0x40
[    3.960199] Code: 00 00 49 3b 86 c0 00 00 00 75 07 49 89 96 c0 00 00 00 4d 8b ae 28 01 00 00 49 83 e5 fe 4d 39 ec 75 0b 49 39 86 c8 00 00 00 74 02 <0f> ff 49 3b 86 c8 00 00 00 75 07 49 89 96 c8 00 00 00 4c 89 f7 
[    3.960199] ---[ end trace 88baba44f97303e0 ]---
[    3.990019] 
[    3.990267] =====================================
[    3.991105] WARNING: bad unlock balance detected!
[    3.991922] 4.12.0-02191-gde8a3b1 #1 Tainted: G        W      
[    3.992884] -------------------------------------
[    3.993612] swapper/1 is trying to release lock (rcu_preempt_state) at:
[    3.994002] [<ffffffff810ad79a>] rcu_read_unlock_special+0x24b/0x2a4
[    3.994002] but there are no more locks to release!
[    3.994002] 
[    3.994002] other info that might help us debug this:
[    3.994002] 1 lock held by swapper/1:
[    3.994002]  #0:  (rcu_read_lock){......}, at: [<ffffffff811e61f9>] insert_retry+0x33/0x4cb
[    3.994002] 
[    3.994002] stack backtrace:
[    3.994002] CPU: 0 PID: 1 Comm: swapper Tainted: G        W       4.12.0-02191-gde8a3b1 #1
[    3.994002] Call Trace:
[    3.994002]  dump_stack+0x19/0x1b
[    3.994002]  print_unlock_imbalance_bug+0xd1/0xda
[    3.994002]  lock_release+0x13e/0x27c
[    3.994002]  rt_mutex_unlock+0x29/0x8d
[    3.994002]  rcu_read_unlock_special+0x24b/0x2a4
[    3.994002]  __rcu_read_unlock+0x3e/0x5f
[    3.994002]  insert_retry+0x1fa/0x4cb
[    3.994002]  test_rhashtable+0x75/0x7ed
[    3.994002]  ? lockdep_init_map+0xbb/0x1bd
[    3.994002]  test_rht_init+0xdd/0x3d4
[    3.994002]  ? test_rhashtable+0x7ed/0x7ed
[    3.994002]  ? set_debug_rodata+0x12/0x12
[    3.994002]  do_one_initcall+0x89/0x132
[    3.994002]  ? set_debug_rodata+0x12/0x12
[    3.994002]  kernel_init_freeable+0x107/0x185
[    3.994002]  ? rest_init+0x221/0x221
[    3.994002]  kernel_init+0x9/0xe6
[    3.994002]  ret_from_fork+0x2a/0x40
[    4.044617]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.069526]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.070859]   Deleting 50000 keys
[    4.093871]   Duration of test: 266657374 ns
[    4.094703] Test 01:
[    4.097383]   Adding 50000 keys
[    4.218594] Info: encountered resize
[    4.221705]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=1
[    4.287448]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.288867]   Deleting 50000 keys
[    4.312928]   Duration of test: 214974234 ns
[    4.313727] Test 02:
[    4.316558]   Adding 50000 keys
[    4.378490]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.403545]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.404997]   Deleting 50000 keys
[    4.434260]   Duration of test: 117159047 ns
[    4.435114] Test 03:
[    4.437813]   Adding 50000 keys
[    4.500614]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.529124]   Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[    4.530624]   Deleting 50000 keys
[    4.554010]   Duration of test: 115580432 ns
[    4.554858] Average test time: 178592771
[    4.555561] Testing concurrent rhashtable access from 10 threads
[    5.224284] tsc: Refined TSC clocksource calibration: 2693.502 MHz
[    5.225519] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x26d34404bd2, max_idle_ns: 440795222183 ns
[    9.473862] Started 10 threads, 0 failed
[    9.478548] crc32: CRC_LE_BITS = 8, CRC_BE BITS = 8
[    9.479370] crc32: self tests passed, processed 225944 bytes in 694785 nsec
[    9.481465] crc32c: CRC_LE_BITS = 8
[    9.481987] crc32c: self tests passed, processed 225944 bytes in 340423 nsec
[    9.519677] crc32_combine: 8373 self tests passed
[    9.565333] crc32c_combine: 8373 self tests passed
[    9.566336] xz_dec_test: module loaded
[    9.567027] xz_dec_test: Create a device node with 'mknod xz_dec_test c 251 0' and write .xz files to it.
[    9.568989] gpio-mockup: probe of gpio-mockup failed with error -22
[    9.570618] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    9.571949] ACPI: Power Button [PWRF]
[    9.572717] button: probe of LNXPWRBN:00 failed with error -22
[    9.575271] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    9.615188] 00:05: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    9.649340] 00:06: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    9.651750] Initializing Nozomi driver 2.1d
[    9.652826] Non-volatile memory driver v1.3
[    9.653706] telclk_interrupt = 0xf non-mcpbl0010 hw.
[    9.656144] usbcore: registered new interface driver rtsx_usb
[    9.657534] usbcore: registered new interface driver viperboard
[    9.659703] usbcore: registered new interface driver hwa-rc
[    9.660873] usbcore: registered new interface driver hwa-hc
[    9.662094] usbcore: registered new interface driver cdc_acm
[    9.663120] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    9.664579] usbcore: registered new interface driver adutux
[    9.665602] usbcore: registered new interface driver emi62 - firmware loader
[    9.666977] usbcore: registered new interface driver isight_firmware
[    9.668215] usbcore: registered new interface driver legousbtower
[    9.669342] usbcore: registered new interface driver rio500
[    9.670518] usbcore: registered new interface driver chaoskey
[    9.671711] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    9.674276] serio: i8042 KBD port at 0x60,0x64 irq 1
[    9.675323] serio: i8042 AUX port at 0x60,0x64 irq 12
[    9.676957] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    9.679035] usbcore: registered new interface driver xpad
[    9.680032] usbcore: registered new interface driver usb_acecad
[    9.681361] mk712: device not present
[    9.682864] rtc rtc0: alarm rollover: day
[    9.683665] rtc rtc0: test: dev (0:0)
[    9.684370] rtc-test rtc-test.0: rtc core: registered test as rtc0
[    9.685552] rtc rtc1: alarm rollover: day
[    9.686530] rtc rtc1: test: dev (0:1)
[    9.687207] rtc-test rtc-test.1: rtc core: registered test as rtc1
[    9.688604] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
[    9.844604] usbcore: registered new interface driver RobotFuzz Open Source InterFace, OSIF
[    9.846149] Driver for 1-wire Dallas network protocol.
[    9.847204] DS1WM w1 busmaster driver - (c) 2004 Szabolcs Gyurko
[    9.850353] __power_supply_register: Expected proper parent device for 'test_ac'
[    9.851839] power_supply test_ac: uevent
[    9.852730] power_supply test_ac: POWER_SUPPLY_NAME=test_ac
[    9.853870] __power_supply_register: Expected proper parent device for 'test_battery'
[    9.855202] power_supply test_battery: uevent
[    9.857739] power_supply test_battery: POWER_SUPPLY_NAME=test_battery
[    9.859049] __power_supply_register: Expected proper parent device for 'test_usb'
[    9.860466] power_supply test_usb: uevent
[    9.861237] power_supply test_usb: POWER_SUPPLY_NAME=test_usb
[    9.868275] power_supply test_ac: power_supply_changed
[    9.869234] power_supply test_ac: power_supply_changed_work
[    9.871455] power_supply test_ac: power_supply_update_gen_leds 1
[    9.872904] power_supply test_ac: uevent
[    9.873919] power_supply test_ac: POWER_SUPPLY_NAME=test_ac
[    9.874753] power_supply test_ac: prop ONLINE=1
[    9.875822] power_supply test_battery: power_supply_changed
[    9.881107] power_supply test_usb: power_supply_changed
[    9.882226] power_supply test_battery: power_supply_changed_work
[    9.883549] power_supply test_battery: power_supply_update_bat_leds 2
[    9.884965] power_supply test_battery: uevent
[    9.885814] power_supply test_battery: POWER_SUPPLY_NAME=test_battery
[    9.886965] power_supply test_battery: prop STATUS=Discharging
[    9.892662] power_supply test_battery: prop CHARGE_TYPE=Fast
[    9.893650] power_supply test_battery: prop HEALTH=Good
[    9.894852] power_supply test_battery: prop PRESENT=1
[    9.895787] power_supply test_battery: prop TECHNOLOGY=Li-ion
[    9.896887] power_supply test_battery: prop CHARGE_FULL_DESIGN=100
[    9.897998] power_supply test_battery: prop CHARGE_FULL=100
[    9.899022] power_supply test_battery: prop CHARGE_NOW=50
[    9.903842] power_supply test_battery: prop CAPACITY=50
[    9.905236] power_supply test_battery: prop CAPACITY_LEVEL=Normal
[    9.906631] power_supply test_battery: prop TIME_TO_EMPTY_AVG=3600
[    9.907754] power_supply test_battery: prop TIME_TO_FULL_NOW=3600
[    9.909078] power_supply test_battery: prop MODEL_NAME=Test battery
[    9.910037] power_supply test_battery: prop MANUFACTURER=Linux
[    9.915281] power_supply test_battery: prop SERIAL_NUMBER=4.12.0-02191-gde8a3b1
[    9.917199] power_supply test_battery: prop TEMP=26
[    9.918196] power_supply test_battery: prop VOLTAGE_NOW=3300
[    9.919246] power_supply test_usb: power_supply_changed_work
[    9.920105] power_supply test_usb: power_supply_update_gen_leds 1
[    9.921043] power_supply test_usb: uevent
[    9.921657] power_supply test_usb: POWER_SUPPLY_NAME=test_usb
[    9.922532] power_supply test_usb: prop ONLINE=1
[   10.960594] VUB300 Driver rom wait states = 1C irqpoll timeout = 0400
[   10.960768] usbcore: registered new interface driver vub300
[   10.962923] usbcore: registered new interface driver ushc
[   10.963941] ledtrig-cpu: registered to indicate activity on CPUs
[   10.969732] greybus: registered new driver bootrom
[   10.970680] greybus: registered new driver lights
[   10.971443] greybus: registered new driver power_supply
[   10.972548] greybus: registered new driver raw
[   10.973593] greybus: registered new driver vibrator
[   10.974449] greybus: registered new driver gbphy
[   10.975272] gb_gbphy: registered new driver gpio
[   10.977190] acerhdf: error getting hardware information
[   10.983633] Board is not the VME system controller
[   10.985032] VME geographical address is set to 0
[   10.986145] CR/CSR Offset: 0
[   10.987104] intel_rapl: driver does not support CPU family 6 model 44
[   10.989355] ... APIC ID:      00000000 (0)
[   10.990264] ... APIC VERSION: 01050014
[   10.991302] 0000000000000000000000000000000000000000000000000000000000000000
[   10.992264] 0000000000000000000000000000000000000000000000000000000000000000
[   10.992264] 0000000000000000000000000000000000000000000000000000000000008000
[   10.996202] number of MP IRQ sources: 15.
[   10.996847] number of IO-APIC #0 registers: 24.
[   10.997760] testing the IO APIC.......................
[   10.998719] IO APIC #0......
[   10.999886] .... register #00: 00000000
[   11.000717] .......    : physical APIC id: 00
[   11.001658] .......    : Delivery Type: 0
[   11.002349] .......    : LTS          : 0
[   11.003094] .... register #01: 00170011
[   11.003752] .......     : max redirection entries: 17
[   11.004942] .......     : PRQ implemented: 0
[   11.005690] .......     : IO APIC version: 11
[   11.006586] .... register #02: 00000000
[   11.007320] .......     : arbitration: 00
[   11.008099] .... IRQ redirection table:
[   11.009723] IOAPIC 0:
[   11.010214]  pin00, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.011679]  pin01, enabled , edge , high, V(31), IRR(0), S(0), logical , D(01), M(1)
[   11.013537]  pin02, enabled , edge , high, V(30), IRR(0), S(0), logical , D(01), M(1)
[   11.015057]  pin03, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.017291]  pin04, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.018643]  pin05, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.020170]  pin06, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.021584]  pin07, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.023258]  pin08, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.024968]  pin09, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.026654]  pin0a, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.027930]  pin0b, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.029425]  pin0c, enabled , edge , high, V(3C), IRR(0), S(0), logical , D(01), M(1)
[   11.031168]  pin0d, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.033392]  pin0e, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.034704]  pin0f, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.036478]  pin10, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.037964]  pin11, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.039434]  pin12, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.041230]  pin13, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.042695]  pin14, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.044466]  pin15, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.046134]  pin16, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.047797]  pin17, disabled, edge , high, V(00), IRR(0), S(0), physical, D(00), M(0)
[   11.050193] IRQ to pin mappings:
[   11.050729] IRQ0 -> 0:2
[   11.051269] IRQ1 -> 0:1
[   11.052123] IRQ3 -> 0:3
[   11.052673] IRQ4 -> 0:4
[   11.053406] IRQ5 -> 0:5
[   11.053924] IRQ6 -> 0:6
[   11.054351] IRQ7 -> 0:7
[   11.054713] IRQ8 -> 0:8
[   11.055202] IRQ9 -> 0:9
[   11.055669] IRQ10 -> 0:10
[   11.057080] IRQ11 -> 0:11
[   11.057537] IRQ12 -> 0:12
[   11.058078] IRQ13 -> 0:13
[   11.058539] IRQ14 -> 0:14
[   11.059189] IRQ15 -> 0:15
[   11.059728] .................................... done.
[   11.060545] sched_clock: Marking stable (11060498578, 0)->(12121587876, -1061089298)
[   11.065363] Loading compiled-in X.509 certificates
[   11.078454] modprobe (120) used greatest stack depth: 14576 bytes left
[   11.090128] Key type trusted registered
[   11.093416] rtc-test rtc-test.0: setting system clock to 2017-07-14 03:52:30 UTC (1500004350)
[   11.097667] Freeing unused kernel memory: 664K
[   11.100690] Write protecting the kernel read-only data: 10240k
[   11.103441] Freeing unused kernel memory: 1512K
[   11.111198] Freeing unused kernel memory: 1264K
[   11.120012] nfsroot (132) used greatest stack depth: 14336 bytes left
ifconfig: socket: Address family not supported by protocol
mkdir: can't create directory '/var/lock': No such file or directory
mkdir: can't create directory '/var/lock/lkp-bootstrap.lock': No such file or directory
sleep: invalid number '333.3'
[   11.145191] cat (140) used greatest stack depth: 14280 bytes left
/ # PATH=/sbin:/usr/sbin:/bin:/usr/bin:/lkp/lkp/src/bin
LKP: HOSTNAME vm-kbuild-yocto-ia32-26, MAC , kernel 4.12.0-02191-gde8a3b1 1, serial console /dev/ttyS0
[   12.168284] Kernel tests: Boot OK!
[   12.168284] LKP: waiting for network...
[   13.236256] sleep (170) used greatest stack depth: 14224 bytes left
[   28.301165] process 214 (wait) attempted a POSIX timer syscall while CONFIG_POSIX_TIMERS is not set
[   28.354732] random: fast init done
[   29.232067] ls /sys/class/net
[   29.232067] lo
[   29.232067] /lkp/lkp/src/bin/run-lkp
[   29.232067] RESULT_ROOT=/result/trinity/300s/vm-kbuild-yocto-ia32/yocto-tiny-i386-2016-04-22.cgz/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/0
[   29.232067] job=/lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.yaml
[   29.232067] run-job /lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.yaml
[   29.232067] skip http request: cgi-bin/lkp-jobfile-append-var?job_file=/lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.yaml&job_state=running -O /dev/null
[   40.159886] modprobe (260) used greatest stack depth: 14144 bytes left
[   40.254933] trinity-main uses obsolete (PF_INET,SOCK_PACKET)
[   40.980675] modprobe (316) used greatest stack depth: 13824 bytes left
[   47.761699] VFS: Warning: trinity-c1 using old stat() call. Recompile your binary.
[   47.792001] VFS: Warning: trinity-c2 using old stat() call. Recompile your binary.
[   47.808915] VFS: Warning: trinity-c1 using old stat() call. Recompile your binary.
[   47.916588] VFS: Warning: trinity-c3 using old stat() call. Recompile your binary.
[   48.304025] VFS: Warning: trinity-c3 using old stat() call. Recompile your binary.
[   66.023757] rcu-torture: rtc: ffffffff82a4e460 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 barrier: 0/0:0 cbflood: 1
[   66.028077] rcu-torture: Reader Pipe:  2 0 0 0 0 0 0 0 0 0 0
[   66.029796] rcu-torture: Reader Batch:  1 1 0 0 0 0 0 0 0 0 0
[   66.030832] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  127.555267] rcu-torture: rtc: ffffffff82a4e460 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 barrier: 0/0:0 cbflood: 1
[  127.558454] rcu-torture: Reader Pipe:  2 0 0 0 0 0 0 0 0 0 0
[  127.566179] rcu-torture: Reader Batch:  1 1 0 0 0 0 0 0 0 0 0
[  127.569225] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  127.570400] ??? Writer stall state RTWS_STUTTER(8) g3034 c3034 f0x2 ->state 0x1 cpu 0
[  127.580039] rcu_preempt: wait state: 1 ->state: 0x402
[  127.590668] rcu_sched: wait state: 1 ->state: 0x402
[  127.592985] rcu_bh: wait state: 1 ->state: 0x402
[  189.010785] rcu-torture: rtc: ffffffff82a4e460 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 barrier: 0/0:0 cbflood: 1
[  189.013325] rcu-torture: Reader Pipe:  2 0 0 0 0 0 0 0 0 0 0
[  189.020221] rcu-torture: Reader Batch:  1 1 0 0 0 0 0 0 0 0 0
[  189.021332] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  189.026185] ??? Writer stall state RTWS_STUTTER(8) g3158 c3158 f0x2 ->state 0x1 cpu 0
[  189.032235] rcu_preempt: wait state: 1 ->state: 0x402
[  189.036959] rcu_sched: wait state: 1 ->state: 0x402
[  189.042543] rcu_bh: wait state: 1 ->state: 0x402
[  250.478371] rcu-torture: rtc: ffffffff82a4e460 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 barrier: 0/0:0 cbflood: 1
[  250.483237] rcu-torture: Reader Pipe:  2 0 0 0 0 0 0 0 0 0 0
[  250.484712] rcu-torture: Reader Batch:  1 1 0 0 0 0 0 0 0 0 0
[  250.493311] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  250.497012] ??? Writer stall state RTWS_STUTTER(8) g3280 c3280 f0x2 ->state 0x1 cpu 0
[  250.504122] rcu_preempt: wait state: 1 ->state: 0x402
[  250.509439] rcu_sched: wait state: 1 ->state: 0x402
[  250.513098] rcu_bh: wait state: 1 ->state: 0x402
[  311.937823] rcu-torture: rtc: ffffffff82a4e460 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 barrier: 0/0:0 cbflood: 1
[  311.940399] rcu-torture: Reader Pipe:  2 0 0 0 0 0 0 0 0 0 0
[  311.941418] rcu-torture: Reader Batch:  1 1 0 0 0 0 0 0 0 0 0
[  311.945850] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  311.946726] ??? Writer stall state RTWS_STUTTER(8) g3402 c3402 f0x2 ->state 0x1 cpu 0
[  311.947732] rcu_preempt: wait state: 1 ->state: 0x402
[  311.948388] rcu_sched: wait state: 1 ->state: 0x402
[  311.949024] rcu_bh: wait state: 1 ->state: 0x402
[  332.440306] sysrq: SysRq : Emergency Sync
[  332.443870] Emergency Sync complete
[  332.446560] sysrq: SysRq : Resetting

Elapsed time: 340

initrds=(
	/osimage/yocto/yocto-tiny-i386-2016-04-22.cgz
	/lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.cgz
	/lkp/lkp/lkp-i386.cgz
	/osimage/deps/debian-x86_64-2016-08-31.cgz/run-ipconfig.i386_2016-09-03.cgz
	/osimage/pkg/static/trinity-i386.cgz
	/pkg/linux/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/modules.cgz
)

cat "${initrds[@]}" > /fs/sde1/initrd-vm-kbuild-yocto-ia32-26

kvm=(
	qemu-system-x86_64
	-enable-kvm
	-cpu Westmere
	-kernel /pkg/linux/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/vmlinuz-4.12.0-02191-gde8a3b1
	-initrd /fs/sde1/initrd-vm-kbuild-yocto-ia32-26
	-m 512
	-smp 1
	-device e1000,netdev=net0
	-netdev user,id=net0
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-watchdog-action debug
	-rtc base=localtime
	-drive file=/fs/sde1/disk0-vm-kbuild-yocto-ia32-26,media=disk,if=virtio
	-pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-ia32-26
	-serial file:/dev/shm/kboot/vm-kbuild-yocto-ia32-26/serial
	-serial file:/dev/shm/kboot/vm-kbuild-yocto-ia32-26/kmsg
	-daemonize
	-display none
	-monitor null
)

append=(
	ip=::::vm-kbuild-yocto-ia32-26::dhcp
	root=/dev/ram0
	user=lkp
	job=/lkp/scheduled/vm-kbuild-yocto-ia32-26/trinity-300s-yocto-tiny-i386-2016-04-22.cgz-de8a3b1249d6d6eb910e271dc0d18bafd032172d-20170714-25167-1exypw-0.yaml
	ARCH=x86_64
	kconfig=x86_64-randconfig-r0-07132314
	branch=linux-devel/devel-catchup-201707140302
	commit=de8a3b1249d6d6eb910e271dc0d18bafd032172d
	BOOT_IMAGE=/pkg/linux/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/vmlinuz-4.12.0-02191-gde8a3b1
	max_uptime=1500
	RESULT_ROOT=/result/trinity/300s/vm-kbuild-yocto-ia32/yocto-tiny-i386-2016-04-22.cgz/x86_64-randconfig-r0-07132314/gcc-6/de8a3b1249d6d6eb910e271dc0d18bafd032172d/0
	LKP_SERVER=inn
	debug
	apic=debug
	sysrq_always_enabled
	rcupdate.rcu_cpu_stall_timeout=100
	net.ifnames=0
	printk.devkmsg=on
	panic=-1
	softlockup_panic=1
	nmi_watchdog=panic
	oops=panic
	load_ramdisk=2
	prompt_ramdisk=0
	drbd.minor_count=8
	systemd.log_level=err
	ignore_loglevel
	earlyprintk=ttyS0,115200
	console=ttyS0,115200
	console=tty0
	vga=normal
	rw
	drbd.minor_count=8
)

"${kvm[@]}" -append "${append[*]}"
