early console in setup code
early console in extract_kernel
input_data: 0x01b45069
input_len: 0x0055cef3
output: 0x01000000
output_len: 0x00c605c4
kernel_total_size: 0x014a6000

Decompressing Linux... Parsing ELF... done.
Booting the kernel.
[    0.000000] Linux version 4.18.0-rc1-00004-g50b7ae6 (kbuild@ivb43) (gcc version 7.3.0 (Debian 7.3.0-16)) #156 SMP Thu Jun 28 14:38:24 CST 2018
[    0.000000] KERNEL supported cpus:
[    0.000000]   NSC Geode by NSC
[    0.000000]   Cyrix CyrixInstead
[    0.000000]   Centaur CentaurHauls
[    0.000000]   UMC UMC UMC UMC
[    0.000000] CPU: vendor_id 'AuthenticAMD' unknown, using generic init.
[    0.000000] CPU: Your system may be unstable.
[    0.000000] x86/fpu: x87 FPU will use FXSAVE
[    0.000000] 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-0x000000001a3dffff] usable
[    0.000000] BIOS-e820: [mem 0x000000001a3e0000-0x000000001a3fffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] debug: ignoring loglevel setting.
[    0.000000] bootconsole [earlyser0] enabled
[    0.000000] Notice: NX (Execute Disable) protection cannot be enabled: non-PAE kernel!
[    0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] last_pfn = 0x1a3e0 max_arch_pfn = 0x100000
[    0.000000] x86/PAT: Configuration [0-7]: WB  WT  UC- UC  WB  WT  UC- UC  
[    0.000000] Scan for SMP in [mem 0x00000000-0x000003ff]
[    0.000000] Scan for SMP in [mem 0x0009fc00-0x0009ffff]
[    0.000000] Scan for SMP in [mem 0x000f0000-0x000fffff]
[    0.000000] found SMP MP-table at [mem 0x000f6aa0-0x000f6aaf] mapped at [(ptrval)]
[    0.000000]   mpc: f6ab0-f6b80
[    0.000000] Scanning 1 areas for low memory corruption
[    0.000000] initial memory mapped: [mem 0x00000000-0x027fffff]
[    0.000000] Base memory trampoline at [(ptrval)] 9b000 size 16384
[    0.000000] BRK [0x0239a000, 0x0239afff] PGTABLE
[    0.000000] RAMDISK: [mem 0x17814000-0x1a3dffff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F68D0 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x000000001A3E15CE 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x000000001A3E142A 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x000000001A3E0040 0013EA (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x000000001A3E0000 000040
[    0.000000] ACPI: APIC 0x000000001A3E151E 000078 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] ACPI: HPET 0x000000001A3E1596 000038 (v01 BOCHS  BXPCHPET 00000001 BXPC 00000001)
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] mapped APIC to         ffffc000 (        fee00000)
[    0.000000] 0MB HIGHMEM available.
[    0.000000] 419MB LOWMEM available.
[    0.000000]   mapped low ram: 0 - 1a3e0000
[    0.000000]   low ram: 0 - 1a3e0000
[    0.000000] tsc: Unable to calibrate against PIT
[    0.000000] tsc: No reference (HPET/PMTIMER) available
[    0.000000] BRK [0x0239b000, 0x0239bfff] PGTABLE
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   Normal   [mem 0x0000000001000000-0x000000001a3dffff]
[    0.000000]   HighMem  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-0x000000001a3dffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001a3dffff]
[    0.000000] On node 0 totalpages: 107390
[    0.000000]   DMA zone: 36 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 3998 pages, LIFO batch:0
[    0.000000]   Normal zone: 909 pages used for memmap
[    0.000000]   Normal zone: 103392 pages, LIFO batch:31
[    0.000000] Reserved but unavailable: 98 pages
[    0.000000] Using APIC driver default
[    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 32, 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 1 CPUs, 0 hotplug CPUs
[    0.000000] mapped IOAPIC to ffffb000 (fec00000)
[    0.000000] [mem 0x1a400000-0xfffbffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on bare hardware
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
[    0.000000] random: get_random_bytes called from start_kernel+0x95/0x4ae with crng_init=0
[    0.000000] setup_percpu: NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] percpu: Embedded 342 pages/cpu @(ptrval) s1371920 r0 d28912 u1400832
[    0.000000] pcpu-alloc: s1371920 r0 d28912 u1400832 alloc=342*4096
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 106445
[    0.000000] Kernel command line: ip=::::vm-lkp-os-openwrt-ia32-13::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-lkp-os-openwrt-ia32-13/trinity-300s-openwrt-i386-2016-03-16.cgz-50b7ae6af5671168cc6cf2de959b02584e4c3f87-20180628-40234-99phmy-3.yaml ARCH=i386 kconfig=i386-randconfig-i0-201825 branch=linux-devel/devel-spot-201806270834 commit=50b7ae6af5671168cc6cf2de959b02584e4c3f87 BOOT_IMAGE=/pkg/linux/i386-randconfig-i0-201825/gcc-7/50b7ae6af5671168cc6cf2de959b02584e4c3f87/vmlinuz-4.18.0-rc1-00004-g50b7ae6 max_uptime=1500 RESULT_ROOT=/result/trinity/300s/vm-lkp-os-openwrt-ia32/openwrt-i386-2016-03-16.cgz/i386-randconfig-i0-201825/gcc-7/50b7ae6af5671168cc6cf2de959b02584e4c3f87/3 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 console=tty0 earlyprintk=ttyS0,115200 conso
[    0.000000] sysrq: sysrq always enabled.
[    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] BRK [0x0239c000, 0x0239cfff] PGTABLE
[    0.000000] Initializing CPU#0
[    0.000000] Initializing HighMem for node 0 (00000000:00000000)
[    0.000000] Memory: 358748K/429560K available (7476K kernel code, 401K rwdata, 2760K rodata, 1888K init, 7364K bss, 70812K reserved, 0K cma-reserved, 0K highmem)
[    0.000000] virtual kernel memory layout:
[    0.000000]     fixmap  : 0xffd37000 - 0xfffff000   (2848 kB)
[    0.000000]   cpu_entry : 0xff400000 - 0xff4c1000   ( 772 kB)
[    0.000000]     pkmap   : 0xff000000 - 0xff400000   (4096 kB)
[    0.000000]     vmalloc : 0xdabe0000 - 0xfeffe000   ( 580 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xda3e0000   ( 419 MB)
[    0.000000]       .init : 0xc1a81000 - 0xc1c59000   (1888 kB)
[    0.000000]       .data : 0xc174d1e0 - 0xc1a65400   (3168 kB)
[    0.000000]       .text : 0xc1000000 - 0xc174d1e0   (7476 kB)
[    0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[    0.000000] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	RCU event tracing is enabled.
[    0.000000] 	RCU restricting CPUs from NR_CPUS=32 to nr_cpu_ids=1.
[    0.000000] 	RCU callback double-/use-after-free debug enabled.
[    0.000000] 	RCU CPU stall warnings timeout set to 100 (rcu_cpu_stall_timeout).
[    0.000000] 	Tasks RCU enabled.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.000000] NR_IRQS: 2304, nr_irqs: 48, preallocated irqs: 16
[    0.000000] CPU 0 irqstacks, hard=(ptrval) soft=(ptrval)
[    0.000000] random: get_random_u32 called from cache_random_seq_create+0x98/0x140 with crng_init=0
[    0.000000] console [ttyS0] enabled
[    0.000000] console [ttyS0] enabled
[    0.000000] bootconsole [earlyser0] disabled
[    0.000000] bootconsole [earlyser0] disabled
[    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: 4639 kB
[    0.000000]  per task-struct memory footprint: 2112 bytes
[    0.000000] ODEBUG: selftest passed
[    0.000000] ACPI: Core revision 20180531
[    0.000000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.000000] hpet clockevent registered
[    0.016000] APIC: Switch to symmetric I/O mode setup
[    0.016000] Enabling APIC mode:  Flat.  Using 1 I/O APICs
[    0.020000] enabled ExtINT on CPU#0
[    0.024000] ENABLING IO-APIC IRQs
[    0.028000] init IO_APIC IRQs
[    0.028000]  apic 0 pin 0 not connected
[    0.036000] IOAPIC[0]: Set routing entry (0-1 -> 0xef -> IRQ 1 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-2 -> 0x30 -> IRQ 0 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-3 -> 0xef -> IRQ 3 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-4 -> 0xef -> IRQ 4 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-5 -> 0xef -> IRQ 5 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-6 -> 0xef -> IRQ 6 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-7 -> 0xef -> IRQ 7 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-8 -> 0xef -> IRQ 8 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-9 -> 0xef -> IRQ 9 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-10 -> 0xef -> IRQ 10 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-11 -> 0xef -> IRQ 11 Mode:1 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-12 -> 0xef -> IRQ 12 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-13 -> 0xef -> IRQ 13 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-14 -> 0xef -> IRQ 14 Mode:0 Active:0 Dest:1)
[    0.040000] IOAPIC[0]: Set routing entry (0-15 -> 0xef -> 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.064000] tsc: Fast TSC calibration using PIT
[    0.072000] tsc: Detected 3199.993 MHz processor
[    0.077407] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x2e204376f46, max_idle_ns: 440795203828 ns
[    0.081887] Calibrating delay loop (skipped), value calculated using timer frequency.. 6399.98 BogoMIPS (lpj=12799972)
[    0.084393] pid_max: default: 32768 minimum: 301
[    0.098137] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.099205] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.205486] mce: CPU supports 10 MCE banks
[    0.207338] mce: unknown CPU type - not enabling MCE support
[    0.210849] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.212364] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.214840] Spectre V2 : Mitigation: Full generic retpoline
[    0.216464] Spectre V2 : Spectre v2 mitigation: Filling RSB on context switch
[    0.217686] Speculative Store Bypass: Vulnerable
[    0.700528] Freeing SMP alternatives memory: 24K
[    0.792555] Using local APIC timer interrupts.
[    0.792555] calibrating APIC timer ...
[    0.796000] ... lapic delta = 7415409
[    0.796000] ... PM-Timer delta = 424681
[    0.796000] APIC calibration not consistent with PM-Timer: 118ms instead of 100ms
[    0.796000] APIC delta adjusted to PM-Timer: 6250280 (7415409)
[    0.796000] TSC delta adjusted to PM-Timer: 319997772 (379649268)
[    0.796000] ..... delta 6250280
[    0.796000] ..... mult: 268447481
[    0.796000] ..... calibration result: 4000179
[    0.796000] ..... CPU clock speed is 3199.3910 MHz.
[    0.796000] ..... host bus clock speed is 1000.0179 MHz.
[    0.798887] smpboot: CPU0: AuthenticAMD QEMU Virtual CPU version 2.5+ (family: 0x6, model: 0x6, stepping: 0x3)
[    0.853655] Performance Events: no PMU driver, software events only.
[    0.873755] Hierarchical SRCU implementation.
[    0.912433] NMI watchdog: Perf event create on CPU 0 failed with -2
[    0.913527] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.938448] smp: Bringing up secondary CPUs ...
[    0.940736] smp: Brought up 1 node, 1 CPU
[    0.941711] smpboot: Max logical packages: 1
[    0.942813] smpboot: Total of 1 processors activated (6399.98 BogoMIPS)
[    1.013255] devtmpfs: initialized
[    1.122525] _warn_unseeded_randomness: 35 callbacks suppressed
[    1.123320] random: get_random_u32 called from bucket_table_alloc+0xce/0x160 with crng_init=0
[    1.141400] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[    1.154698] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[    1.159037] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    1.161618] futex hash table entries: 256 (order: 2, 16384 bytes)
[    1.181095] prandom: seed boundary self test passed
[    1.202274] prandom: 100 self tests passed
[    1.203584] pinctrl core: initialized pinctrl subsystem
[    1.253458] regulator-dummy: no parameters
[    1.320428] NET: Registered protocol family 16
[    1.358014] audit: initializing netlink subsys (disabled)
[    1.375150] audit: type=2000 audit(1530198215.368:1): state=initialized audit_enabled=0 res=1
[    1.410631] cpuidle: using governor menu
[    1.430067] ACPI: bus type PCI registered
[    1.452444] PCI: PCI BIOS revision 2.10 entry at 0xfd501, last bus=0
[    1.454014] PCI: Using configuration type 1 for base access
[    2.273001] _warn_unseeded_randomness: 63 callbacks suppressed
[    2.273198] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[    2.277291] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[    2.284830] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[    2.310834] HugeTLB registered 4.00 MiB page size, pre-allocated 0 pages
[    2.340960] cryptd: max_cpu_qlen set to 1000
[    2.357405] ACPI: Added _OSI(Module Device)
[    2.358345] ACPI: Added _OSI(Processor Device)
[    2.359042] ACPI: Added _OSI(3.0 _SCP Extensions)
[    2.360236] ACPI: Added _OSI(Processor Aggregator Device)
[    2.361782] ACPI: Added _OSI(Linux-Dell-Video)
[    2.597696] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    2.871485] ACPI: Interpreter enabled
[    2.878996] ACPI: (supports S0 S3 S5)
[    2.881079] ACPI: Using IOAPIC for interrupt routing
[    2.888515] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    2.923157] ACPI: Enabled 2 GPEs in block 00 to 0F
[    3.757538] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    3.761204] acpi PNP0A03:00: _OSC: OS supports [Segments]
[    3.764832] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    3.768258] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[    3.789060] PCI host bridge to bus 0000:00
[    3.790542] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    3.791589] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    3.792473] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    3.793540] pci_bus 0000:00: root bus resource [mem 0x1a400000-0xfebfffff window]
[    3.796339] pci_bus 0000:00: root bus resource [bus 00-ff]
[    3.802845] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
[    3.849475] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
[    3.873569] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
[    3.897004] pci 0000:00:01.1: reg 0x20: [io  0xc040-0xc04f]
[    3.904778] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
[    3.906051] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
[    3.908442] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
[    3.909559] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
[    3.933001] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
[    3.937680] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
[    3.938900] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
[    3.962278] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000
[    3.968639] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref]
[    3.982596] pci 0000:00:02.0: reg 0x18: [mem 0xfebf0000-0xfebf0fff]
[    4.012493] pci 0000:00:02.0: reg 0x30: [mem 0xfebe0000-0xfebeffff pref]
[    4.040697] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000
[    4.048517] pci 0000:00:03.0: reg 0x10: [mem 0xfebc0000-0xfebdffff]
[    4.056552] pci 0000:00:03.0: reg 0x14: [io  0xc000-0xc03f]
[    4.092589] pci 0000:00:03.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref]
[    4.134293] pci 0000:00:04.0: [8086:25ab] type 00 class 0x088000
[    4.142039] pci 0000:00:04.0: reg 0x10: [mem 0xfebf1000-0xfebf100f]
[    4.205149] pci_bus 0000:00: on NUMA node 0
[    4.289999] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    4.305126] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    4.320985] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    4.335225] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    4.342738] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    4.414532] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[    4.416000] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[    4.416557] pci 0000:00:02.0: vgaarb: bridge control possible
[    4.420352] vgaarb: loaded
[    4.427663] _warn_unseeded_randomness: 9 callbacks suppressed
[    4.428357] random: get_random_u32 called from cache_random_seq_create+0x98/0x140 with crng_init=0
[    4.433281] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[    4.447431] pps_core: LinuxPPS API ver. 1 registered
[    4.448391] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    4.451043] PTP clock support registered
[    4.453818] EDAC MC: Ver: 3.0.0
[    4.467001] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[    4.530741] PCI: Using ACPI for IRQ routing
[    4.533250] PCI: pci_cache_line_size set to 64 bytes
[    4.537763] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
[    4.540502] e820: reserve RAM buffer [mem 0x1a3e0000-0x1bffffff]
[    4.610651] Bluetooth: Core ver 2.22
[    4.614619] NET: Registered protocol family 31
[    4.615463] Bluetooth: HCI device and connection manager initialized
[    4.617411] Bluetooth: HCI socket layer initialized
[    4.618693] Bluetooth: L2CAP socket layer initialized
[    4.623206] Bluetooth: SCO socket layer initialized
[    4.668000] clocksource: Switched to clocksource tsc-early
[    4.686640] VFS: Disk quotas dquot_6.6.0
[    4.691873] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    4.705423] FS-Cache: Loaded
[    4.719864] pnp: PnP ACPI init
[    4.739824] pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active)
[    4.749057] pnp 00:01: Plug and Play ACPI device, IDs PNP0303 (active)
[    4.757275] pnp 00:02: Plug and Play ACPI device, IDs PNP0f13 (active)
[    4.761323] pnp 00:03: [dma 2]
[    4.765531] pnp 00:03: Plug and Play ACPI device, IDs PNP0700 (active)
[    4.775454] pnp 00:04: Plug and Play ACPI device, IDs PNP0400 (active)
[    4.785939] pnp 00:05: Plug and Play ACPI device, IDs PNP0501 (active)
[    4.795547] pnp 00:06: Plug and Play ACPI device, IDs PNP0501 (active)
[    4.839750] pnp: PnP ACPI: found 7 devices
[    4.963027] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    4.973409] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    4.974423] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
[    4.975277] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[    4.976770] pci_bus 0000:00: resource 7 [mem 0x1a400000-0xfebfffff window]
[    4.992131] NET: Registered protocol family 2
[    5.076218] tcp_listen_portaddr_hash hash table entries: 256 (order: 1, 12288 bytes)
[    5.079993] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[    5.083189] TCP bind hash table entries: 4096 (order: 5, 180224 bytes)
[    5.096081] TCP: Hash tables configured (established 4096 bind 4096)
[    5.111736] UDP hash table entries: 256 (order: 2, 24576 bytes)
[    5.115391] UDP-Lite hash table entries: 256 (order: 2, 24576 bytes)
[    5.135298] NET: Registered protocol family 1
[    5.182464] RPC: Registered named UNIX socket transport module.
[    5.183616] RPC: Registered udp transport module.
[    5.185070] RPC: Registered tcp transport module.
[    5.185816] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    5.210812] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    5.212873] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    5.214561] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    5.217649] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    5.219764] PCI: CLS 0 bytes, default 64
[    5.270491] Unpacking initramfs...
[  137.995769] Freeing initrd memory: 44848K
[  138.047280] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac)
[  138.050310] apm: overridden by ACPI.
[  138.057563] Scanning for low memory corruption every 60 seconds
[  138.075566] _warn_unseeded_randomness: 47 callbacks suppressed
[  138.075769] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[  138.203273] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[  138.211606] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[  139.043084] tsc: Refined TSC clocksource calibration: 3199.997 MHz
[  139.053906] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2e204719c91, max_idle_ns: 440795261699 ns
[  139.074530] clocksource: Switched to clocksource tsc
[  143.439526] _warn_unseeded_randomness: 5 callbacks suppressed
[  143.439742] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[  143.445044] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[  143.450214] random: get_random_u32 called from stress_one_work+0x13/0x90 with crng_init=0
[  145.687053] 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 stall_cpu_irqsoff=0 n_barrier_cbs=0 onoff_interval=0 onoff_holdoff=0
[  145.694047] rcu-torture: Creating rcu_torture_writer task
[  145.697525] _warn_unseeded_randomness: 1 callbacks suppressed
[  145.697699] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[  145.701614] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[  145.707907] rcu-torture: Creating rcu_torture_fakewriter task
[  145.710785] rcu-torture: rcu_torture_writer task started
[  145.711943] rcu-torture: GP expediting controlled from boot/sysfs for rcu.
[  145.714368] rcu_torture_writer: Testing conditional GPs.
[  145.715459] rcu_torture_writer: Testing expedited GPs.
[  145.717212] rcu_torture_writer: Testing asynchronous GPs.
[  145.718228] rcu_torture_writer: Testing normal GPs.
[  145.721789] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[  145.729981] rcu-torture: Creating rcu_torture_fakewriter task
[  145.735550] rcu-torture: rcu_torture_fakewriter task started
[  145.739935] rcu-torture: Creating rcu_torture_fakewriter task
[  145.745313] rcu-torture: rcu_torture_fakewriter task started
[  145.748058] rcu-torture: Creating rcu_torture_fakewriter task
[  145.757491] rcu-torture: rcu_torture_fakewriter task started
[  145.773438] rcu-torture: rcu_torture_fakewriter task started
[  145.775281] rcu-torture: Creating rcu_torture_reader task
[  145.817958] rcu-torture: Creating rcu_torture_stats task
[  145.838020] rcu-torture: rcu_torture_reader task started
[  145.879433] rcu-torture: Creating torture_shuffle task
[  145.886719] rcu-torture: rcu_torture_stats task started
[  145.919388] rcu-torture: torture_shuffle task started
[  145.932237] rcu-torture: Creating torture_stutter task
[  145.946937] rcu-torture: Creating rcu_torture_cbflood task
[  145.951207] rcu-torture: torture_stutter task started
[  145.988004] rcu-torture: rcu_torture_cbflood task started
[  146.073779] Key type blacklist registered
[  146.095142] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[  147.019923] _warn_unseeded_randomness: 29 callbacks suppressed
[  147.020869] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[  153.631080] random: get_random_u32 called from copy_process+0x18d/0x1c70 with crng_init=0
[  162.510369] random: get_random_u32 called from cache_grow_begin+0x52a/0xa60 with crng_init=0
[  163.510428] BUG: spinlock recursion on CPU#0, rcu_torture_cbf/54
[  163.511698]  lock: rcu_sched_state+0x0/0x9a0, .magic: dead4ead, .owner: rcu_torture_cbf/54, .owner_cpu: 0
[  163.512424] CPU: 0 PID: 54 Comm: rcu_torture_cbf Not tainted 4.18.0-rc1-00004-g50b7ae6 #156
[  163.512424] Call Trace:
[  163.512424]  <SOFTIRQ>
[  163.512424]  dump_stack+0x58/0x76
[  163.512424]  spin_dump+0x64/0xb0
[  163.512424]  do_raw_spin_lock+0x7d/0xb0
[  163.512424]  _raw_spin_lock+0x45/0x60
[  163.512424]  rcu_process_callbacks+0x991/0xba0
[  163.512424]  ? irqtime_account_irq+0x6e/0x80
[  163.512424]  __do_softirq+0xa3/0x1ba
[  163.512424]  ? __irqentry_text_end+0x5/0x5
[  163.512424]  call_on_stack+0x40/0x50
[  163.512424]  </SOFTIRQ>
[  163.512424]  ? irq_exit+0xb5/0xc0
[  163.512424]  ? smp_apic_timer_interrupt+0x51/0x80
[  163.512424]  ? apic_timer_interrupt+0x39/0x40
[  163.512424]  ? _raw_spin_unlock_irqrestore+0x24/0x40
[  163.512424]  ? __debug_object_init+0xba/0x490
[  163.512424]  ? debug_object_activate+0x1ae/0x210
[  163.512424]  ? __call_rcu+0x2b/0x250
[  163.512424]  ? rcu_torture_boost_cb+0x10/0x10
[  163.512424]  ? call_rcu_sched+0xf/0x20
[  163.512424]  ? rcu_torture_cbflood+0xe4/0x1b0
[  163.512424]  ? kthread+0xed/0x100
[  163.512424]  ? rcu_torture_err_cb+0x20/0x20
[  163.512424]  ? kthread_create_worker_on_cpu+0x20/0x20
[  163.512424]  ? ret_from_fork+0x2e/0x40

Elapsed time: 190

#!/bin/bash

# To reproduce,
# 1) save job-script and this script (both are attached in 0day report email)
# 2) run this script with your compiled kernel and optional env $INSTALL_MOD_PATH

kernel=$1

initrds=(
	/osimage/openwrt/openwrt-i386-2016-03-16.cgz
	/lkp/lkp/lkp-i386.cgz
	/osimage/pkg/debian-x86_64-2016-08-31.cgz/trinity-static-i386-x86_64-6ddabfd2_2017-11-10.cgz
)

HTTP_PREFIX=https://download.01.org/0day-ci/lkp-qemu
wget --timestamping "${initrds[@]/#/$HTTP_PREFIX}"

{
	cat "${initrds[@]//*\//}"
	[[ $INSTALL_MOD_PATH ]] && (
		cd "$INSTALL_MOD_PATH"
		find lib | cpio -o -H newc --quiet | gzip
	)
	echo  job-script | cpio -o -H newc --quiet | gzip
} > initrd.img

kvm=(
	qemu-system-x86_64
	-kernel $kernel
	-initrd initrd.img
	-m 420
	-smp 1
	-device e1000,netdev=net0
	-netdev user,id=net0
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-watchdog-action debug
	-rtc base=localtime
	-serial stdio
	-display none
	-monitor null
)

append=(
	ip=::::vm-lkp-os-openwrt-ia32-13::dhcp
	root=/dev/ram0
	user=lkp
	job=/job-script
	ARCH=i386
	kconfig=i386-randconfig-i0-201825
	branch=linux-devel/devel-spot-201806270834
	commit=50b7ae6af5671168cc6cf2de959b02584e4c3f87
	BOOT_IMAGE=/pkg/linux/i386-randconfig-i0-201825/gcc-7/50b7ae6af5671168cc6cf2de959b02584e4c3f87/vmlinuz-4.18.0-rc1-00004-g50b7ae6
	max_uptime=1500
	RESULT_ROOT=/result/trinity/300s/vm-lkp-os-openwrt-ia32/openwrt-i386-2016-03-16.cgz/i386-randconfig-i0-201825/gcc-7/50b7ae6af5671168cc6cf2de959b02584e4c3f87/3
	result_service=tmpfs
	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
	console=tty0
	earlyprintk=ttyS0,115200
	console=ttyS0,115200
	vga=normal
	rw
	drbd.minor_count=8
	rcuperf.shutdown=0
)

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