lava-dispatcher, installed at version: 2023.10
start: 0 validate
Start time: 2024-09-30 09:49:59.828914+00:00 (UTC)
Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.4.y/v5.4.40/x86_64/x86_64_defconfig/gcc-8/bzImage?raw=true exists
Validating that https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/kci-2019.02-9-g25091c539382/x86/baseline/rootfs.cpio.gz?raw=true exists
qemu-system-x86, installed at version: 1:7.2+dfsg-7+deb12u2, host architecture: amd64
validate duration: 2.43
case: validate
case_id: 4051910
definition: lava
result: pass
start: 1 deployimages (timeout 00:03:00) [common]
start: 1.1 lava-overlay (timeout 00:03:00) [common]
[common] Preparing overlay tarball in /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_
makedir: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin
makedir: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/tests
makedir: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/results
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-add-keys
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-add-sources
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-background-process-start
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-background-process-stop
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-common-functions
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-echo-ipv4
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-install-packages
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-installed-packages
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-os-build
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-probe-channel
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-probe-ip
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-target-ip
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-target-mac
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-target-storage
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-case
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-event
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-feedback
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-raise
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-reference
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-runner
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-set
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-test-shell
Updating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-install-packages (oe)
Updating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/bin/lava-installed-packages (oe)
Creating /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/environment
LAVA metadata
- LAVA_JOB_ID=36608
- LAVA_DISPATCHER_IP=172.19.0.2
start: 1.1.1 lava-vland-overlay (timeout 00:03:00) [common]
skipped lava-vland-overlay
end: 1.1.1 lava-vland-overlay (duration 00:00:00) [common]
start: 1.1.2 lava-multinode-overlay (timeout 00:03:00) [common]
skipped lava-multinode-overlay
end: 1.1.2 lava-multinode-overlay (duration 00:00:00) [common]
start: 1.1.3 test-definition (timeout 00:03:00) [common]
Loading test definitions
start: 1.1.3.1 inline-repo-action (timeout 00:03:00) [common]
Using /lava-36608 at stage 0
uuid=36608_1.1.3.1 testdef=None
end: 1.1.3.1 inline-repo-action (duration 00:00:00) [common]
start: 1.1.3.2 test-overlay (timeout 00:03:00) [common]
end: 1.1.3.2 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 4051914
definition: lava
duration: 0.00
extra: ...
level: 1.1.3.2
namespace: common
result: pass
start: 1.1.3.3 test-install-overlay (timeout 00:03:00) [common]
end: 1.1.3.3 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 4051915
definition: lava
duration: 0.00
extra: ...
level: 1.1.3.3
namespace: common
result: pass
start: 1.1.3.4 test-runscript-overlay (timeout 00:03:00) [common]
runner path: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/0/tests/0_dmesg test_uuid 36608_1.1.3.1
end: 1.1.3.4 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 4051916
definition: lava
duration: 0.00
extra: ...
level: 1.1.3.4
namespace: common
result: pass
start: 1.1.3.5 inline-repo-action (timeout 00:03:00) [common]
Using /lava-36608 at stage 1
uuid=36608_1.1.3.5 testdef=None
end: 1.1.3.5 inline-repo-action (duration 00:00:00) [common]
start: 1.1.3.6 test-overlay (timeout 00:03:00) [common]
end: 1.1.3.6 test-overlay (duration 00:00:00) [common]
case: test-overlay
case_id: 4051914
definition: lava
duration: 0.00
extra: ...
level: 1.1.3.6
namespace: common
result: pass
start: 1.1.3.7 test-install-overlay (timeout 00:03:00) [common]
end: 1.1.3.7 test-install-overlay (duration 00:00:00) [common]
case: test-install-overlay
case_id: 4051915
definition: lava
duration: 0.00
extra: ...
level: 1.1.3.7
namespace: common
result: pass
start: 1.1.3.8 test-runscript-overlay (timeout 00:03:00) [common]
runner path: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/1/tests/1_bootrr test_uuid 36608_1.1.3.5
end: 1.1.3.8 test-runscript-overlay (duration 00:00:00) [common]
case: test-runscript-overlay
case_id: 4051916
definition: lava
duration: 0.00
extra: ...
level: 1.1.3.8
namespace: common
result: pass
Creating lava-test-runner.conf files
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/0 for stage 0
- 0_dmesg
Using lava-test-runner path: /var/lib/lava/dispatcher/tmp/36608/lava-overlay-9z5cdji_/lava-36608/1 for stage 1
- 1_bootrr
end: 1.1.3 test-definition (duration 00:00:00) [common]
start: 1.1.4 compress-overlay (timeout 00:03:00) [common]
end: 1.1.4 compress-overlay (duration 00:00:00) [common]
start: 1.1.5 persistent-nfs-overlay (timeout 00:03:00) [common]
end: 1.1.5 persistent-nfs-overlay (duration 00:00:00) [common]
end: 1.1 lava-overlay (duration 00:00:00) [common]
start: 1.2 apply-overlay-guest (timeout 00:03:00) [common]
Overlay: /var/lib/lava/dispatcher/tmp/36608/compress-overlay-b0p2bjmx/overlay-1.1.4.tar.gz
end: 1.2 apply-overlay-guest (duration 00:00:04) [common]
case: apply-overlay-guest
case_id: 4051921
definition: lava
duration: 4.09
extra: ...
level: 1.2
namespace: common
result: pass
start: 1.3 deploy-device-env (timeout 00:02:56) [common]
end: 1.3 deploy-device-env (duration 00:00:00) [common]
start: 1.4 download-retry (timeout 00:02:56) [common]
start: 1.4.1 http-download (timeout 00:02:56) [common]
downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/stable/linux-5.4.y/v5.4.40/x86_64/x86_64_defconfig/gcc-8/bzImage?raw=true
saving as /var/lib/lava/dispatcher/tmp/36608/deployimages-v606ary4/kernel/bzImage
total size: 8909696 (8 MB)
No compression specified
progress 0 % (0 MB)
progress 5 % (0 MB)
progress 10 % (0 MB)
progress 15 % (1 MB)
progress 20 % (1 MB)
progress 25 % (2 MB)
progress 30 % (2 MB)
progress 35 % (3 MB)
progress 40 % (3 MB)
progress 45 % (3 MB)
progress 50 % (4 MB)
progress 55 % (4 MB)
progress 60 % (5 MB)
progress 65 % (5 MB)
progress 70 % (5 MB)
progress 75 % (6 MB)
progress 80 % (6 MB)
progress 85 % (7 MB)
progress 90 % (7 MB)
progress 95 % (8 MB)
progress 100 % (8 MB)
8 MB downloaded in 1.98 s (4.30 MB/s)
end: 1.4.1 http-download (duration 00:00:02) [common]
case: http-download
case_id: 4051923
definition: lava
duration: 1.98
extra: ...
level: 1.4.1
namespace: common
result: pass
end: 1.4 download-retry (duration 00:00:02) [common]
start: 1.5 download-retry (timeout 00:02:54) [common]
start: 1.5.1 http-download (timeout 00:02:54) [common]
Not decompressing ramdisk as can be used compressed.
downloading https://github.com/montjoie/lava-healthchecks-binary/blob/master/images/rootfs/buildroot/kci-2019.02-9-g25091c539382/x86/baseline/rootfs.cpio.gz?raw=true
saving as /var/lib/lava/dispatcher/tmp/36608/deployimages-v606ary4/ramdisk/rootfs.cpio.gz
total size: 4607869 (4 MB)
No compression specified
progress 0 % (0 MB)
progress 5 % (0 MB)
progress 10 % (0 MB)
progress 15 % (0 MB)
progress 20 % (0 MB)
progress 25 % (1 MB)
progress 30 % (1 MB)
progress 35 % (1 MB)
progress 40 % (1 MB)
progress 45 % (2 MB)
progress 50 % (2 MB)
progress 55 % (2 MB)
progress 60 % (2 MB)
progress 65 % (2 MB)
progress 70 % (3 MB)
progress 75 % (3 MB)
progress 80 % (3 MB)
progress 85 % (3 MB)
progress 90 % (3 MB)
progress 95 % (4 MB)
progress 100 % (4 MB)
4 MB downloaded in 0.23 s (19.50 MB/s)
end: 1.5.1 http-download (duration 00:00:00) [common]
case: http-download
case_id: 4051923
definition: lava
duration: 0.23
extra: ...
level: 1.5.1
namespace: common
result: pass
end: 1.5 download-retry (duration 00:00:00) [common]
end: 1 deployimages (duration 00:00:06) [common]
start: 2 boot-image-retry (timeout 00:05:00) [common]
start: 2.1 boot-qemu-image (timeout 00:05:00) [common]
start: 2.1.1 execute-qemu (timeout 00:05:00) [common]
Extending command line for qcow2 test overlay
Boot command: /usr/bin/qemu-system-x86_64 -cpu host -enable-kvm -nographic -net nic,model=virtio,macaddr=52:54:00:12:34:58 -net user -m 512 -monitor none -kernel /var/lib/lava/dispatcher/tmp/36608/deployimages-v606ary4/kernel/bzImage -append "console=ttyS0,115200 root=/dev/ram0 debug verbose console_msg_format=syslog" -initrd /var/lib/lava/dispatcher/tmp/36608/deployimages-v606ary4/ramdisk/rootfs.cpio.gz -drive format=qcow2,file=/var/lib/lava/dispatcher/tmp/36608/apply-overlay-guest-qifkj6gp/lava-guest.qcow2,media=disk,if=ide,id=lavatest
started a shell command
end: 2.1.1 execute-qemu (duration 00:00:01) [common]
case: execute-qemu
case_id: 4051924
definition: lava
duration: 0.90
extra: ...
level: 2.1.1
namespace: common
result: pass
end: 2.1 boot-qemu-image (duration 00:00:01) [common]
start: 2.2 auto-login-action (timeout 00:04:59) [common]
Setting prompt string to ['Linux version [0-9]']
auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:05:00)
c[?7l[2J[0mSeaBIOS (version 1.16.2-debian-1.16.2-1)
iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+1EFCEF00+1EF0EF00 CA00
Press Ctrl-B to configure iPXE (PCI 00:03.0)...
Booting from ROM...
start: 2.2.1 login-action (timeout 00:04:58) [common]
The string '/ #' does not look like a typical prompt and could match status messages instead. Please check the job log files and use a prompt string which matches the actual prompt string more closely.
Setting prompt string to []
Setting prompt string to ['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing']
Using line separator: #'\n'#
No login prompt set.
Parsing kernel messages
['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', '/ #', 'Login timed out', 'Login incorrect']
[login-action] Waiting for messages, (timeout 00:04:58)
early console in setup codc[?7l[2J[0me<5>[ 0.000000] Linux version 5.4.40 (KernelCI@02fc7aed0572) (gcc version 8.3.0 (Debian 8.3.0-6)) #1 SMP Sun May 10 16:40:28 UTC 2020
<6>[ 0.000000] Command line: console=ttyS0,115200 root=/dev/ram0 debug verbose console_msg_format=syslog
<6>[ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
<6>[ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
<6>[ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
<6>[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
<6>[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
<6>[ 0.000000] BIOS-provided physical RAM map:
<6>[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
<6>[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
<6>[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
<6>[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001ffdffff] usable
<6>[ 0.000000] BIOS-e820: [mem 0x000000001ffe0000-0x000000001fffffff] reserved
<6>[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
<6>[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
<6>[ 0.000000] NX (Execute Disable) protection: active
<6>[ 0.000000] SMBIOS 2.8 present.
<6>[ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
<6>[ 0.000000] tsc: Fast TSC calibration using PIT
<6>[ 0.000000] tsc: Detected 1795.755 MHz processor
<7>[ 0.002706] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
<7>[ 0.002709] e820: remove [mem 0x000a0000-0x000fffff] usable
<6>[ 0.002713] last_pfn = 0x1ffe0 max_arch_pfn = 0x400000000
<7>[ 0.002777] MTRR default type: write-back
<7>[ 0.002778] MTRR fixed ranges enabled:
<7>[ 0.002780] 00000-9FFFF write-back
<7>[ 0.002781] A0000-BFFFF uncachable
<7>[ 0.002782] C0000-FFFFF write-protect
<7>[ 0.002783] MTRR variable ranges enabled:
<7>[ 0.002785] 0 base 000080000000 mask 3FFF80000000 uncachable
<7>[ 0.002786] 1 disabled
<7>[ 0.002787] 2 disabled
<7>[ 0.002787] 3 disabled
<7>[ 0.002788] 4 disabled
<7>[ 0.002789] 5 disabled
<7>[ 0.002789] 6 disabled
<7>[ 0.002790] 7 disabled
<6>[ 0.002806] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
<6>[ 0.013870] found SMP MP-table at [mem 0x000f5ba0-0x000f5baf]
<6>[ 0.013962] check: Scanning 1 areas for low memory corruption
<6>[ 0.014012] Using GB pages for direct mapping
<7>[ 0.014019] BRK [0x17601000, 0x17601fff] PGTABLE
<7>[ 0.014022] BRK [0x17602000, 0x17602fff] PGTABLE
<7>[ 0.014023] BRK [0x17603000, 0x17603fff] PGTABLE
<7>[ 0.014060] BRK [0x17604000, 0x17604fff] PGTABLE
<7>[ 0.014124] BRK [0x17605000, 0x17605fff] PGTABLE
<6>[ 0.014148] RAMDISK: [mem 0x1fb7b000-0x1ffdffff]
<6>[ 0.014175] ACPI: Early table checksum verification disabled
<6>[ 0.014202] ACPI: RSDP 0x00000000000F59D0 000014 (v00 BOCHS )
<6>[ 0.014210] ACPI: RSDT 0x000000001FFE1AC6 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
<6>[ 0.014219] ACPI: FACP 0x000000001FFE197A 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
<6>[ 0.014226] ACPI: DSDT 0x000000001FFE0040 00193A (v01 BOCHS BXPC 00000001 BXPC 00000001)
<6>[ 0.014231] ACPI: FACS 0x000000001FFE0000 000040
<6>[ 0.014235] ACPI: APIC 0x000000001FFE19EE 000078 (v01 BOCHS BXPC 00000001 BXPC 00000001)
<6>[ 0.014240] ACPI: HPET 0x000000001FFE1A66 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
<6>[ 0.014245] ACPI: WAET 0x000000001FFE1A9E 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
<7>[ 0.014260] ACPI: Local APIC address 0xfee00000
<6>[ 0.014814] No NUMA configuration found
<6>[ 0.014816] Faking a node at [mem 0x0000000000000000-0x000000001ffdffff]
<6>[ 0.014820] NODE_DATA(0) allocated [mem 0x1fb77000-0x1fb7afff]
<6>[ 0.015504] Zone ranges:
<6>[ 0.015505] DMA [mem 0x0000000000001000-0x0000000000ffffff]
<6>[ 0.015507] DMA32 [mem 0x0000000001000000-0x000000001ffdffff]
<6>[ 0.015508] Normal empty
<6>[ 0.015509] Movable zone start for each node
<6>[ 0.015511] Early memory node ranges
<6>[ 0.015512] node 0: [mem 0x0000000000001000-0x000000000009efff]
<6>[ 0.015514] node 0: [mem 0x0000000000100000-0x000000001ffdffff]
<6>[ 0.016806] Zeroed struct page in unavailable ranges: 130 pages
<6>[ 0.016807] Initmem setup node 0 [mem 0x0000000000001000-0x000000001ffdffff]
<7>[ 0.016809] On node 0 totalpages: 130942
<7>[ 0.016814] DMA zone: 64 pages used for memmap
<7>[ 0.016815] DMA zone: 21 pages reserved
<7>[ 0.016817] DMA zone: 3998 pages, LIFO batch:0
<7>[ 0.016879] DMA32 zone: 1984 pages used for memmap
<7>[ 0.016884] DMA32 zone: 126944 pages, LIFO batch:31
<6>[ 0.020468] ACPI: PM-Timer IO Port: 0x608
<7>[ 0.020472] ACPI: Local APIC address 0xfee00000
<6>[ 0.020487] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
<6>[ 0.020555] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
<6>[ 0.020560] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
<6>[ 0.020562] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
<6>[ 0.020563] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
<6>[ 0.020570] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
<6>[ 0.020572] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
<7>[ 0.020574] ACPI: IRQ0 used by override.
<7>[ 0.020575] ACPI: IRQ5 used by override.
<7>[ 0.020576] ACPI: IRQ9 used by override.
<7>[ 0.020577] ACPI: IRQ10 used by override.
<7>[ 0.020578] ACPI: IRQ11 used by override.
<6>[ 0.020581] Using ACPI (MADT) for SMP configuration information
<6>[ 0.020583] ACPI: HPET id: 0x8086a201 base: 0xfed00000
<6>[ 0.020588] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
<6>[ 0.020601] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]
<6>[ 0.020603] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
<6>[ 0.020604] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
<6>[ 0.020605] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
<6>[ 0.020608] [mem 0x20000000-0xfeffbfff] available for PCI devices
<6>[ 0.020624] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
<6>[ 0.169861] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:1 nr_node_ids:1
<6>[ 0.170332] percpu: Embedded 50 pages/cpu s167064 r8192 d29544 u2097152
<7>[ 0.170338] pcpu-alloc: s167064 r8192 d29544 u2097152 alloc=1*2097152
<7>[ 0.170339] pcpu-alloc: [0] 0
<6>[ 0.170376] Built 1 zonelists, mobility grouping on. Total pages: 128873
<6>[ 0.170377] Policy zone: DMA32
<5>[ 0.170380] Kernel command line: console=ttyS0,115200 root=/dev/ram0 debug verbose console_msg_format=syslog
<6>[ 0.170587] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
<6>[ 0.170637] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
<6>[ 0.170685] mem auto-init: stack:off, heap alloc:off, heap free:off
<7>[ 0.170688] Calgary: detecting Calgary via BIOS EBDA area
<7>[ 0.170691] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
<6>[ 0.172387] Memory: 481236K/523768K available (14340K kernel code, 1328K rwdata, 3240K rodata, 1308K init, 1176K bss, 42532K reserved, 0K cma-reserved)
<6>[ 0.173121] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
<6>[ 0.173140] Kernel/User page tables isolation: enabled
<6>[ 0.173922] rcu: Hierarchical RCU implementation.
<6>[ 0.173923] rcu: RCU event tracing is enabled.
<6>[ 0.173925] rcu: RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=1.
<6>[ 0.173928] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
<6>[ 0.173929] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
<6>[ 0.174144] NR_IRQS: 4352, nr_irqs: 256, preallocated irqs: 16
<5>[ 0.174517] random: get_random_bytes called from start_kernel+0x30e/0x4dd with crng_init=0
<6>[ 0.187724] Console: colour VGA+ 80x25
<6>[ 0.382824] printk: console [ttyS0] enabled
<6>[ 0.384032] ACPI: Core revision 20190816
<6>[ 0.385393] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
<6>[ 0.388037] APIC: Switch to symmetric I/O mode setup
<6>[ 0.391517] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
<6>[ 0.398023] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x19e27f8a4fc, max_idle_ns: 440795296688 ns
<6>[ 0.400958] Calibrating delay loop (skipped), value calculated using timer frequency.. 3591.51 BogoMIPS (lpj=1795755)
<6>[ 0.401955] pid_max: default: 32768 minimum: 301
<6>[ 0.402981] LSM: Security Framework initializing
<6>[ 0.403973] SELinux: Initializing.
<6>[ 0.404996] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes, linear)
<6>[ 0.405957] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes, linear)
<6>[ 0.408323] x86/cpu: User Mode Instruction Prevention (UMIP) activated
<6>[ 0.409068] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
<6>[ 0.409955] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
<6>[ 0.410962] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
<6>[ 0.411955] Spectre V2 : Mitigation: Full generic retpoline
<6>[ 0.412954] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
<6>[ 0.413954] Spectre V2 : Enabling Restricted Speculation for firmware calls
<6>[ 0.414956] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
<6>[ 0.415955] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
<6>[ 0.416959] MDS: Mitigation: Clear CPU buffers
<6>[ 0.428561] Freeing SMP alternatives memory: 40K
<7>[ 0.430094] TSC deadline timer enabled
<6>[ 0.430952] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2650L v3 @ 1.80GHz (family: 0x6, model: 0x3f, stepping: 0x2)
<6>[ 0.431070] Performance Events: Haswell events, Intel PMU driver.
<6>[ 0.431961] ... version: 2
<6>[ 0.432957] ... bit width: 48
<6>[ 0.433956] ... generic registers: 4
<6>[ 0.434957] ... value mask: 0000ffffffffffff
<6>[ 0.435956] ... max period: 000000007fffffff
<6>[ 0.436956] ... fixed-purpose events: 3
<6>[ 0.437957] ... event mask: 000000070000000f
<6>[ 0.439024] rcu: Hierarchical SRCU implementation.
<6>[ 0.440044] smp: Bringing up secondary CPUs ...
<6>[ 0.440960] smp: Brought up 1 node, 1 CPU
<6>[ 0.441957] smpboot: Max logical packages: 1
<6>[ 0.442957] smpboot: Total of 1 processors activated (3591.51 BogoMIPS)
<6>[ 0.444139] devtmpfs: initialized
<6>[ 0.445297] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
<6>[ 0.445962] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
<6>[ 0.447083] PM: RTC time: 09:50:09, date: 2024-09-30
<6>[ 0.448079] NET: Registered protocol family 16
<6>[ 0.449094] audit: initializing netlink subsys (disabled)
<6>[ 0.450103] cpuidle: using governor menu
<6>[ 0.451025] ACPI: bus type PCI registered
<6>[ 0.452107] PCI: Using configuration type 1 for base access
<5>[ 0.453012] audit: type=2000 audit(1727689809.057:1): state=initialized audit_enabled=0 res=1
<6>[ 0.453961] core: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off
<6>[ 0.457585] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
<6>[ 0.458058] cryptomgr_test (19) used greatest stack depth: 15520 bytes left
<6>[ 0.459017] kworker/u2:0 (21) used greatest stack depth: 14640 bytes left
<6>[ 0.460063] kworker/u2:0 (25) used greatest stack depth: 14208 bytes left
<6>[ 0.462036] ACPI: Added _OSI(Module Device)
<6>[ 0.462966] ACPI: Added _OSI(Processor Device)
<6>[ 0.463957] ACPI: Added _OSI(3.0 _SCP Extensions)
<6>[ 0.464957] ACPI: Added _OSI(Processor Aggregator Device)
<6>[ 0.465970] ACPI: Added _OSI(Linux-Dell-Video)
<6>[ 0.466994] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
<6>[ 0.467964] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
<6>[ 0.469723] ACPI: 1 ACPI AML tables successfully acquired and loaded
<6>[ 0.471136] ACPI: Interpreter enabled
<6>[ 0.471985] ACPI: (supports S0 S3 S4 S5)
<6>[ 0.472958] ACPI: Using IOAPIC for interrupt routing
<6>[ 0.473973] PCI: Using host bridge windows from ACPI; if necessary, use \"pci=nocrs\" and report a bug
<6>[ 0.475077] ACPI: Enabled 2 GPEs in block 00 to 0F
<6>[ 0.478430] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
<6>[ 0.478965] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
<4>[ 0.479969] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
<6>[ 0.480998] PCI host bridge to bus 0000:00
<6>[ 0.481966] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
<6>[ 0.482960] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
<6>[ 0.483958] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
<6>[ 0.484957] pci_bus 0000:00: root bus resource [mem 0x20000000-0xfebfffff window]
<6>[ 0.485958] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
<6>[ 0.486957] pci_bus 0000:00: root bus resource [bus 00-ff]
<6>[ 0.488029] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
<6>[ 0.489776] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
<6>[ 0.491063] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
<6>[ 0.495354] pci 0000:00:01.1: reg 0x20: [io 0xc020-0xc02f]
<6>[ 0.497405] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
<6>[ 0.497959] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
<6>[ 0.498957] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
<6>[ 0.499957] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
<6>[ 0.501233] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
<6>[ 0.502807] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
<6>[ 0.502974] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
<6>[ 0.504327] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000
<6>[ 0.506829] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref]
<6>[ 0.509005] pci 0000:00:02.0: reg 0x18: [mem 0xfebd0000-0xfebd0fff]
<6>[ 0.514690] pci 0000:00:02.0: reg 0x30: [mem 0xfebc0000-0xfebcffff pref]
<6>[ 0.515611] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000
<6>[ 0.516960] pci 0000:00:03.0: reg 0x10: [io 0xc000-0xc01f]
<6>[ 0.518961] pci 0000:00:03.0: reg 0x14: [mem 0xfebd1000-0xfebd1fff]
<6>[ 0.523960] pci 0000:00:03.0: reg 0x20: [mem 0xfe000000-0xfe003fff 64bit pref]
<6>[ 0.526505] pci 0000:00:03.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref]
<6>[ 0.528637] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
<6>[ 0.529129] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
<6>[ 0.530118] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
<6>[ 0.531116] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
<6>[ 0.532062] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
<6>[ 0.533359] iommu: Default domain type: Translated
<6>[ 0.534077] pci 0000:00:02.0: vgaarb: setting as boot VGA device
<6>[ 0.534952] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
<6>[ 0.534959] pci 0000:00:02.0: vgaarb: bridge control possible
<6>[ 0.535957] vgaarb: loaded
<5>[ 0.536907] SCSI subsystem initialized
<7>[ 0.537068] libata version 3.00 loaded.
<6>[ 0.537999] ACPI: bus type USB registered
<6>[ 0.538988] usbcore: registered new interface driver usbfs
<6>[ 0.539971] usbcore: registered new interface driver hub
<6>[ 0.540975] usbcore: registered new device driver usb
<6>[ 0.542036] pps_core: LinuxPPS API ver. 1 registered
<6>[ 0.542959] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]>
<6>[ 0.543962] PTP clock support registered
<6>[ 0.545038] EDAC MC: Ver: 3.0.0
<6>[ 0.546259] Advanced Linux Sound Architecture Driver Initialized.
<6>[ 0.546984] PCI: Using ACPI for IRQ routing
<7>[ 0.547958] PCI: pci_cache_line_size set to 64 bytes
<7>[ 0.549139] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
<7>[ 0.549966] e820: reserve RAM buffer [mem 0x1ffe0000-0x1fffffff]
<6>[ 0.551221] NetLabel: Initializing
<6>[ 0.551958] NetLabel: domain hash size = 128
<6>[ 0.552956] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
<6>[ 0.553988] NetLabel: unlabeled traffic allowed by default
<6>[ 0.555114] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
<6>[ 0.555959] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
<6>[ 0.562017] clocksource: Switched to clocksource tsc-early
<5>[ 0.670276] VFS: Disk quotas dquot_6.6.0
<6>[ 0.671466] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
<6>[ 0.673470] pnp: PnP ACPI init
<7>[ 0.674493] pnp 00:00: Plug and Play ACPI device, IDs PNP0303 (active)
<7>[ 0.676321] pnp 00:01: Plug and Play ACPI device, IDs PNP0f13 (active)
<7>[ 0.678147] pnp 00:02: [dma 2]
<7>[ 0.679085] pnp 00:02: Plug and Play ACPI device, IDs PNP0700 (active)
<7>[ 0.680934] pnp 00:03: Plug and Play ACPI device, IDs PNP0400 (active)
<7>[ 0.682801] pnp 00:04: Plug and Play ACPI device, IDs PNP0501 (active)
<7>[ 0.684647] pnp 00:05: Plug and Play ACPI device, IDs PNP0b00 (active)
<6>[ 0.686722] pnp: PnP ACPI: found 6 devices
<6>[ 0.689192] thermal_sys: Registered thermal governor 'step_wise'
<6>[ 0.689193] thermal_sys: Registered thermal governor 'user_space'
<6>[ 0.695566] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
<6>[ 0.699693] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
<6>[ 0.701409] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
<6>[ 0.703133] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
<6>[ 0.705028] pci_bus 0000:00: resource 7 [mem 0x20000000-0xfebfffff window]
<6>[ 0.706929] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
<6>[ 0.708962] NET: Registered protocol family 2
<6>[ 0.710437] tcp_listen_portaddr_hash hash table entries: 256 (order: 0, 4096 bytes, linear)
<6>[ 0.712736] TCP established hash table entries: 4096 (order: 3, 32768 bytes, linear)
<6>[ 0.714890] TCP bind hash table entries: 4096 (order: 4, 65536 bytes, linear)
<6>[ 0.716858] TCP: Hash tables configured (established 4096 bind 4096)
<6>[ 0.718667] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
<6>[ 0.720472] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
<6>[ 0.722449] NET: Registered protocol family 1
<6>[ 0.723865] RPC: Registered named UNIX socket transport module.
<6>[ 0.725530] RPC: Registered udp transport module.
<6>[ 0.726874] RPC: Registered tcp transport module.
<6>[ 0.728196] RPC: Registered tcp NFSv4.1 backchannel transport module.
<6>[ 0.730124] pci 0000:00:01.0: PIIX3: Enabling Passive Release
<6>[ 0.731770] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
<6>[ 0.733449] pci 0000:00:01.0: Activating ISA DMA hang workarounds
<6>[ 0.735282] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
<6>[ 0.737616] PCI: CLS 0 bytes, default 64
<6>[ 0.738821] Unpacking initramfs...
<6>[ 0.847437] Freeing initrd memory: 4500K
<6>[ 0.848906] check: Scanning for low memory corruption every 60 seconds
<5>[ 0.851127] Initialise system trusted keyrings
<6>[ 0.852466] workingset: timestamp_bits=56 max_order=17 bucket_order=0
<5>[ 0.856899] NFS: Registering the id_resolver key type
<5>[ 0.858337] Key type id_resolver registered
<5>[ 0.859545] Key type id_legacy registered
<5>[ 0.867756] Key type asymmetric registered
<5>[ 0.868968] Asymmetric key parser 'x509' registered
<6>[ 0.870383] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
<6>[ 0.872451] io scheduler mq-deadline registered
<6>[ 0.873728] io scheduler kyber registered
<6>[ 0.875127] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
<6>[ 0.877217] ACPI: Power Button [PWRF]
<6>[ 0.878574] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
<6>[ 0.906293] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
<6>[ 0.908787] Non-volatile memory driver v1.3
<6>[ 0.910033] Linux agpgart interface v0.103
<6>[ 0.913467] loop: module loaded
<7>[ 0.914507] ata_piix 0000:00:01.1: version 2.13
<6>[ 0.916811] scsi host0: ata_piix
<6>[ 0.917871] scsi host1: ata_piix
<6>[ 0.918880] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc020 irq 14
<6>[ 0.920748] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc028 irq 15
<6>[ 0.923543] e100: Intel(R) PRO/100 Network Driver, 3.5.24-k2-NAPI
<6>[ 0.925249] e100: Copyright(c) 1999-2006 Intel Corporation
<6>[ 0.926822] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
<6>[ 0.928770] e1000: Copyright (c) 1999-2006 Intel Corporation.
<6>[ 0.930385] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k
<6>[ 0.932021] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
<6>[ 0.933678] sky2: driver version 1.30
<6>[ 0.934853] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
<6>[ 0.936663] ehci-pci: EHCI PCI platform driver
<6>[ 0.937934] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
<6>[ 0.939662] ohci-pci: OHCI PCI platform driver
<6>[ 0.940945] uhci_hcd: USB Universal Host Controller Interface driver
<6>[ 0.942744] usbcore: registered new interface driver usblp
<6>[ 0.944298] usbcore: registered new interface driver usb-storage
<6>[ 0.945996] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
<6>[ 0.949391] serio: i8042 KBD port at 0x60,0x64 irq 1
<6>[ 0.950808] serio: i8042 AUX port at 0x60,0x64 irq 12
<6>[ 0.952763] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
<6>[ 0.955538] rtc_cmos 00:05: RTC can wake from S4
<6>[ 0.960042] rtc_cmos 00:05: registered as rtc0
<6>[ 0.961335] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
<6>[ 0.963509] device-mapper: ioctl: 4.41.0-ioctl (2019-09-16) initialised: [email protected]
<6>[ 0.965841] intel_pstate: CPU model not supported
<6>[ 0.967286] hidraw: raw HID events driver (C) Jiri Kosina
<6>[ 0.968943] usbcore: registered new interface driver usbhid
<6>[ 0.970509] usbhid: USB HID core driver
<6>[ 0.972002] Initializing XFRM netlink socket
<6>[ 0.973356] NET: Registered protocol family 10
<6>[ 0.974896] Segment Routing with IPv6
<6>[ 0.976140] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
<6>[ 0.978138] NET: Registered protocol family 17
<5>[ 0.979473] Key type dns_resolver registered
<6>[ 0.980847] IPI shorthand broadcast: enabled
<6>[ 0.982081] sched_clock: Marking stable (763557187, 218505765)->(1088079405, -106016453)
<6>[ 0.984385] registered taskstats version 1
<5>[ 0.985579] Loading compiled-in X.509 certificates
<6>[ 0.987737] PM: Magic number: 8:16:830
<6>[ 0.988927] printk: console [netcon0] enabled
<6>[ 0.990177] netconsole: network logging started
<5>[ 0.991586] cfg80211: Loading compiled-in X.509 certificates for regulatory database
<5>[ 0.995901] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
<4>[ 0.997766] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
<6>[ 1.000158] ALSA device list:
<6>[ 1.001045] cfg80211: failed to load regulatory.db
<6>[ 1.002407] No soundcards found.
<7>[ 1.103080] ata2.01: NODEV after polling detection
<7>[ 1.104785] ata1.01: NODEV after polling detection
<6>[ 1.106578] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
<6>[ 1.108579] ata1.00: ATA-7: QEMU HARDDISK, 2.5+, max UDMA/100
<6>[ 1.110190] ata1.00: 1048576 sectors, multi 16: LBA48
<5>[ 1.113196] scsi 0:0:0:0: Direct-Access ATA QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5
<5>[ 1.115599] sd 0:0:0:0: [sda] 1048576 512-byte logical blocks: (537 MB/512 MiB)
<5>[ 1.117652] sd 0:0:0:0: [sda] Write Protect is off
<7>[ 1.119024] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
<5>[ 1.120520] sd 0:0:0:0: Attached scsi generic sg0 type 0
<5>[ 1.122482] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
<5>[ 1.125750] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
<5>[ 1.129069] sd 0:0:0:0: [sda] Attached SCSI disk
<6>[ 1.142734] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
<6>[ 1.144586] cdrom: Uniform CD-ROM driver Revision: 3.20
<7>[ 1.146194] sr 1:0:0:0: Attached scsi CD-ROM sr0
<5>[ 1.147746] sr 1:0:0:0: Attached scsi generic sg1 type 5
<6>[ 1.150301] Freeing unused kernel image memory: 1308K
<6>[ 1.151766] Write protecting the kernel read-only data: 20480k
<6>[ 1.155307] Freeing unused kernel image memory: 2004K
<6>[ 1.157531] Freeing unused kernel image memory: 856K
<6>[ 1.158962] Run /init as init process
Starting syslogd: OK
Starting klogd: OK
Populating /dev using udev: <30>[ 1.183238] udevd[114]: starting version 3.2.7
<5>[ 1.187112] random: udevd: uninitialized urandom read (16 bytes read)
<5>[ 1.190069] random: udevd: uninitialized urandom read (16 bytes read)
<5>[ 1.191933] random: udevd: uninitialized urandom read (16 bytes read)
<27>[ 1.194536] udevd[114]: specified group 'kvm' unknown
<30>[ 1.199167] udevd[115]: starting eudev-3.2.7
<6>[ 1.319939] cdrom_id (130) used greatest stack depth: 13864 bytes left
done
Initializing random number generator... done.
Starting network: <6>[ 1.380553] ip (142) used greatest stack depth: 13648 bytes left
OK
Starting dropbear sshd: OK
/bin/sh: can't access tty; job control turned off
Matched prompt #10: / #
case: kernel-messages
case_id: 4051960
definition: lava
duration: 1.31
extra: ...
level: 2.2.1
namespace: common
result: pass
Setting prompt string to ['/ #']
end: 2.2.1 login-action (duration 00:00:01) [common]
case: login-action
case_id: 4051961
definition: lava
duration: 1.32
extra: ...
level: 2.2.1
namespace: common
result: pass
end: 2.2 auto-login-action (duration 00:00:02) [common]
start: 2.3 expect-shell-connection (timeout 00:04:57) [common]
Setting prompt string to ['/ #']
Forcing a shell prompt, looking for ['/ #']
/ #
expect-shell-connection: Wait for prompt ['/ #'] (timeout 00:05:00)
Waiting using forced prompt support (timeout 00:02:30)
end: 2.3 expect-shell-connection (duration 00:00:00) [common]
start: 2.4 export-device-env (timeout 00:04:57) [common]
end: 2.4 export-device-env (duration 00:00:00) [common]
end: 2 boot-image-retry (duration 00:00:03) [common]
start: 3 lava-test-retry (timeout 00:01:00) [common]
start: 3.1 lava-test-shell (timeout 00:01:00) [common]
Using namespace: common
#
/ # #
lava-test-shell: Wait for prompt ['/ #'] (timeout 00:01:00)
#<6>[ 1.515269] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
mkdir /lava-36608
/ # mkdir /lava-36608
mkdir /lava-36608
mount /dev/disk/by-uuid/42a7fa20-b197-4e57-bfcf-b9f6d37b9b15 -t ext2 /lava-36608
/ # mount /dev/disk/by-uuid/42a7fa20-b197-4e57-bfcf-b9f6d37b9b15 -t ext2 /lava-36608
mount /dev/disk/by-uuid/42a<5>[ 1.717055] random: fast init done
7fa20-b197-4e57-bfcf-b9f6d37b9b15 -t ext2 /lava-3
6608
<6>[ 1.761472] EXT4-fs (sda): mounting ext2 file system using the ext4 subsystem
<6>[ 1.776937] EXT4-fs (sda): mounted filesystem without journal. Opts: (null)
ls -la /lava-36608/bin/lava-test-runner
/ # ls -la /lava-36608/bin/lava-test-runner
ls -la /l<6>[ 1.833063] tsc: Refined TSC clocksource calibration: 1795.813 MHz
<6>[ 1.834819] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x19e2b65752e, max_idle_ns: 440795275676 ns
ava-36608/bin/lava-test-r<6>[ 1.841026] clocksource: Switched to clocksource tsc
unner
-rwxr-xr-x 1 root root 1039 Sep 30 09:50 [1;32m/lava-36608/bin/lava-test-runner[m
Using /lava-36608
export SHELL=/bin/sh
/ # export SHELL=/bin/sh
export SHELL=/bin/sh
. /lava-36608/environment
/ # . /lava-36608/environment
. /lava-36608/environment
/lava-36608/bin/lava-test-runner /lava-36608/0
/ # /lava-36608/bin/lava-test-runner /lava-36608/0
Test shell timeout: 10s (minimum of the action and connection timeout)
/lava-36608/bin/lava-test-runner /lava-36608/0
+ export 'TESTRUN_ID=0_dmesg'
+ cd /lava-36608/0/tests/0_dmesg
+ cat uuid
+ UUID=36608_1.1.3.1
+ set +x
Received signal: <STARTRUN> 0_dmesg 36608_1.1.3.1
Starting test lava.0_dmesg (36608_1.1.3.1)
Skipping test definition patterns.
<LAVA_SIGNAL_STARTRUN 0_dmesg 36608_1.1.3.1>
+ dmesg '--level=warn' --notime -x -k
+ dmesg '--level=err' --notime -x -k
+ dmesg '--level=crit' --notime -x -k
+ test -s dmesg.crit
+ res=pass
+ wc -l
+ cat dmesg.crit
+ count=0
+ lava-test-case crit --result pass --measurement 0 --units lines
Received signal: <TESTCASE> TEST_CASE_ID=crit RESULT=pass UNITS=lines MEASUREMENT=0
case: crit
case_id: 4051962
definition: 0_dmesg
endtc: 653
measurement: 0.0
result: pass
starttc: 653
units: lines
<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=crit RESULT=pass UNITS=lines MEASUREMENT=0>
+ dmesg '--level=alert' --notime -x -k
+ test -s dmesg.alert
+ res=pass
+ wc -l
+ cat dmesg.alert
+ count=0
+ lava-test-case alert --result pass --measurement 0 --units lines
Received signal: <TESTCASE> TEST_CASE_ID=alert RESULT=pass UNITS=lines MEASUREMENT=0
case: alert
case_id: 4051963
definition: 0_dmesg
endtc: 663
measurement: 0.0
result: pass
starttc: 663
units: lines
<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=alert RESULT=pass UNITS=lines MEASUREMENT=0>
+ dmesg '--level=emerg' --notime -x -k
+ test -s dmesg.emerg
+ res=pass
+ wc -l
+ cat dmesg.emerg
+ count=0
+ lava-test-case emerg --result pass --measurement 0 --units lines
Received signal: <TESTCASE> TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0
case: emerg
case_id: 4051964
definition: 0_dmesg
endtc: 673
measurement: 0.0
result: pass
starttc: 673
units: lines
<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=emerg RESULT=pass UNITS=lines MEASUREMENT=0>
+ cat dmesg.emerg dmesg.alert dmesg.crit dmesg.err dmesg.warn
kern :warn : acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
kern :warn : platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
+ set +x
Received signal: <ENDRUN> 0_dmesg 36608_1.1.3.1
Ending use of test pattern.
Ending test lava.0_dmesg (36608_1.1.3.1), duration 0.06
case: 0_dmesg
case_id: 4051965
definition: lava
duration: 0.06
namespace: common
path: inline/dmesg.yaml
metadata: {'description': 'baseline test plan', 'environment': ['lava-test-shell'], 'format': 'Lava-Test Test Definition 1.0', 'name': 'baseline', 'os': ['debian'], 'scope': ['functional']}
run: {'steps': ['for level in warn err; do\n dmesg --level=$level --notime -x -k > dmesg.$level\ndone\n', 'for level in crit alert emerg; do\n dmesg --level=$level --notime -x -k > dmesg.$level\n test -s dmesg.$level && res=fail || res=pass\n count=$(cat dmesg.$level | wc -l)\n lava-test-case $level \\\n --result $res \\\n --measurement $count \\\n --units lines\ndone\n', 'cat dmesg.emerg dmesg.alert dmesg.crit dmesg.err dmesg.warn']}
result: pass
revision: unspecified
uuid: 36608_1.1.3.1
<LAVA_SIGNAL_ENDRUN 0_dmesg 36608_1.1.3.1>
<LAVA_TEST_RUNNER EXIT>
ok: lava_test_shell seems to have completed
alert: pass
crit: pass
emerg: pass
end: 3.1 lava-test-shell (duration 00:00:01) [common]
end: 3 lava-test-retry (duration 00:00:01) [common]
start: 4 lava-test-retry (timeout 00:01:00) [common]
start: 4.1 lava-test-shell (timeout 00:01:00) [common]
Using namespace: common
#
/ # #
lava-test-shell: Wait for prompt ['/ #'] (timeout 00:01:00)
mkdir /lava-36608
mkdir /lava-36608
#
mount /dev/disk/by-uuid/42a7fa20-b197-4e57-bfcf-b9f6d37b9b15 -t ext2 /lava-36608
/ # mkdir /lava-36608mount /dev/disk/by-uuid/42a7fa20-b197-4e57-bfcf-b9f6d37b9b15 -t ext2 /lava-36608
mkdir: can't create directory '/lava-36608': File exists
/ # mount /dev/disk/by-uuid/42a7fa20-b197-4e57-bfcf-b9f6d37b9b15 -t ext2 /lava-3
6608
ls -la /lava-36608/bin/lava-test-runner
ls -la /lava-36608/bin/lava-test-runner
mount: mounting /dev/disk/by-uuid/42a7fa20-b197-4e57-bfcf-b9f6d37b9b15 on /lava-36608 failed: Device or resource busy
Using /lava-36608
export SHELL=/bin/sh
/ # ls -la /lava-36608/bin/lava-test-runnerexport SHELL=/bin/sh
-rwxr-xr-x 1 root root 1039 Sep 30 09:50 [1;32m/lava-36608/bin/lava-test-runner[m
. /lava-36608/environment
/ # export SHELL=/bin/sh. /lava-36608/environment
/lava-36608/bin/lava-test-runner /lava-36608/1
/ # . /lava-36608/environment/lava-36608/bin/lava-test-runner /lava-36608/1
Test shell timeout: 10s (minimum of the action and connection timeout)
/ # /lava-36608/bin/lava-test-runner /lava-36608/1
+ export 'TESTRUN_ID=1_bootrr'
+ cd /lava-36608/1/tests/1_bootrr
+ cat uuid
+ UUID=36608_1.1.3.5
+ set +x
<8>[ 3.002934] <LAVA_SIGNAL_STARTRUN 1_bootrr 36608_1.1.3.5>
Received signal: <STARTRUN> 1_bootrr 36608_1.1.3.5
Starting test lava.1_bootrr (36608_1.1.3.5)
Skipping test definition patterns.
+ export 'PATH=/opt/bootrr/helpers:/lava-36608/1/../bin:/sbin:/usr/sbin:/bin:/usr/bin'
+ cd /opt/bootrr
+ sh helpers/bootrr-auto
/lava-36608/1/../bin/lava-test-case
Received signal: <TESTCASE> TEST_CASE_ID=deferred-probe-empty RESULT=pass
case: deferred-probe-empty
case_id: 4051966
definition: 1_bootrr
endtc: 734
result: pass
starttc: 734
<8>[ 4.016331] <LAVA_SIGNAL_TESTCASE TEST_CASE_ID=deferred-probe-empty RESULT=pass>
helpers/bootrr-auto: line 5: can't open /proc/device-tree/compatible: no such file
+ set +x
<8>[ 4.022081] <LAVA_SIGNAL_ENDRUN 1_bootrr 36608_1.1.3.5>
Received signal: <ENDRUN> 1_bootrr 36608_1.1.3.5
Ending use of test pattern.
Ending test lava.1_bootrr (36608_1.1.3.5), duration 1.02
case: 1_bootrr
case_id: 4051967
definition: lava
duration: 1.02
namespace: common
path: inline/bootrr.yaml
metadata: {'description': 'baseline test plan', 'environment': ['lava-test-shell'], 'format': 'Lava-Test Test Definition 1.0', 'name': 'baseline', 'os': ['debian'], 'scope': ['functional']}
run: {'steps': ['export PATH=/opt/bootrr/helpers:$PATH', 'cd /opt/bootrr && sh helpers/bootrr-auto']}
result: pass
revision: unspecified
uuid: 36608_1.1.3.5
<LAVA_TEST_RUNNER EXIT>
ok: lava_test_shell seems to have completed
deferred-probe-empty: pass
end: 4.1 lava-test-shell (duration 00:00:02) [common]
end: 4 lava-test-retry (duration 00:00:02) [common]
start: 5 finalize (timeout 00:09:48) [common]
start: 5.1 power-off (timeout 00:00:30) [common]
end: 5.1 power-off (duration 00:00:00) [common]
start: 5.2 read-feedback (timeout 00:09:48) [common]
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
/ # <4>[ 4.073320] urandom_read: 2 callbacks suppressed
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
<5>[ 4.073322] random: udevd: uninitialized urandom read (16 bytes read)
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
Listened to connection for namespace 'common' for up to 1s
<27>[ 4.078021] udevd[115]: specified group 'kvm' unknown
Listened to connection for namespace 'common' for up to 1s
Finalising connection for namespace 'common'
poweroff
poweroff
Already disconnected
poweroff
end: 5.2 read-feedback (duration 00:00:01) [common]
Already disconnected
end: 5 finalize (duration 00:00:01) [common]
Cleaning after the job
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/36608/deployimages-v606ary4/kernel
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/36608/deployimages-v606ary4/ramdisk
Root tmp directory removed at /var/lib/lava/dispatcher/tmp/36608
Job finished correctly
case: job
case_id: 4051968
definition: lava
result: pass
Please read the triage guidelines for help on debugging failures in the test job, test definitions or in individual test cases.
This section helps test writers to check for actions with a duration which is much shorter than the requested timeout. Reducing these timeouts will allow failures to be identified more quickly.
The graph only shows actions that are longer than 1 second. The full list is anyway available in the table.