On Tue, Aug 11, 2020 at 1:48 AM Philippe Mathieu-Daudé <f4...@amsat.org> wrote: > > Hi Havard, > > On 8/11/20 2:46 AM, Havard Skinnemoen wrote: > > This adds two acceptance tests for the quanta-gsj machine. > > > > One test downloads a lightly patched openbmc flash image from github and > > verifies that it boots all the way to the login prompt. > > > > The other test downloads a kernel, initrd and dtb built from the same > > openbmc source and verifies that the kernel detects all CPUs and boots > > to the point where it can't find the root filesystem (because we have no > > flash image in this case). > > > > Reviewed-by: Philippe Mathieu-Daudé <f4...@amsat.org> > > Signed-off-by: Havard Skinnemoen <hskinnem...@google.com> > > --- > > tests/acceptance/boot_linux_console.py | 65 ++++++++++++++++++++++++++ > > 1 file changed, 65 insertions(+) > > > > diff --git a/tests/acceptance/boot_linux_console.py > > b/tests/acceptance/boot_linux_console.py > > index 73cc69c499..8592f33a41 100644 > > --- a/tests/acceptance/boot_linux_console.py > > +++ b/tests/acceptance/boot_linux_console.py > > @@ -569,6 +569,71 @@ class BootLinuxConsole(LinuxKernelTest): > > 'sda') > > # cubieboard's reboot is not functioning; omit reboot test. > > > > + def test_arm_quanta_gsj(self): > > + """ > > + :avocado: tags=arch:arm > > + :avocado: tags=machine:quanta-gsj > > + """ > > + # 25 MiB compressed, 32 MiB uncompressed. > > + image_url = ( > > + 'https://github.com/hskinnemoen/openbmc/releases/download/' > > + > > '20200711-gsj-qemu-0/obmc-phosphor-image-gsj.static.mtd.gz') > > + image_hash = '14895e634923345cb5c8776037ff7876df96f6b1' > > + image_path_gz = self.fetch_asset(image_url, asset_hash=image_hash) > > + image_name = 'obmc.mtd' > > + image_path = os.path.join(self.workdir, image_name) > > + archive.gzip_uncompress(image_path_gz, image_path) > > + > > + self.vm.set_console() > > + drive_args = 'file=' + image_path + ',if=mtd,bus=0,unit=0' > > + self.vm.add_args('-drive', drive_args) > > + self.vm.launch() > > + > > + self.wait_for_console_pattern('> BootBlock by Nuvoton') > > + self.wait_for_console_pattern('>Device: Poleg BMC NPCM730') > > + self.wait_for_console_pattern('>Skip DDR init.') > > + self.wait_for_console_pattern('U-Boot ') > > + self.wait_for_console_pattern('Booting Linux on physical CPU 0x0') > > Tests timeout using QEMU configured with '--enable-debug > --extra-cflags=-ggdb': > > console: Booting Linux on physical CPU 0x0 > console: CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 > > console: stmmaceth f0802000.eth: DMA HW capability register supported > console: stmmaceth f0802000.eth: Normal descriptors > console: stmmaceth f0802000.eth: Ring mode enabled > console: stmmaceth f0802000.eth: device MAC address 92:f6:8f:80:9f:bb > INTERRUPTED: Test interrupted by SIGTERM > Runner error occurred: Timeout reached > (91.05 s) > > My guess is unoptimized build makes guest hashing checks over > the bitbanged SPI flash emulation takes too long.
Right, flash access is super slow when optimization is turned off. > Trying with timeout=240s: > > console: [* ] (1 of 2) A start job is running for…dplug all Devices > (44s / no limit) > console: [** ] (2 of 2) A start job is running for…Save Random Seed > (44s / 10min 13s) > console: [*** ] (2 of 2) A start job is running for…Save Random Seed > (45s / 10min 13s) > console: [ *** ] (2 of 2) A start job is running for…Save Random Seed > (45s / 10min 13s) > console: [ *** ] (1 of 2) A start job is running for…dplug all Devices > (46s / no limit) > console: [ ***] (1 of 2) A start job is running for…dplug all Devices > (46s / no limit) > console: [ **] (1 of 2) A start job is running for…dplug all Devices > (47s / no limit) > console: [ *] (2 of 2) A start job is running for…Save Random Seed > (47s / 10min 13s) > console: [ **] (2 of 2) A start job is running for…Save Random Seed > (48s / 10min 13s) > console: [ ***] (2 of 2) A start job is running for…Save Random Seed > (48s / 10min 13s) > console: [ *** ] (1 of 2) A start job is running for…dplug all Devices > (49s / no limit) > console: [ *** ] (1 of 2) A start job is running for…dplug all Devices > (51s / no limit) > console: [*** ] (1 of 2) A start job is running for…dplug all Devices > (53s / no limit) > console: [** ] (2 of 2) A start job is running for…Save Random Seed > (53s / 10min 13s) > console: [* ] (2 of 2) A start job is running for…Save Random Seed > (54s / 10min 13s) > console: [** ] (2 of 2) A start job is running for…Save Random Seed > (55s / 10min 13s) > console: [*** ] (1 of 2) A start job is running for…dplug all Devices > (56s / no limit) > console: [ *** ] (1 of 2) A start job is running for…dplug all Devices > (57s / no limit) > console: [ *** ] (1 of 2) A start job is running for…dplug all Devices > (57s / no limit) > > Maybe you can disable some expensive services for the test purpose? > See examples of cmdline 'systemd.mask=' in test_arm_orangepi_bionic(). I'll try that, thanks! > Compiled with -O2: > > console: [ *** ] A start job is running for Load/Save Random Seed (1s / > 9min 45s) > console: [ *** ] A start job is running for Load/Save Random Seed (1s / > 9min 45s) > console: [*** ] A start job is running for Load/Save Random Seed (1s / > 9min 45s) > console: [** ] A start job is running for Load/Save Random Seed (2s / > 9min 45s) > console: [* ] A start job is running for Load/Save Random Seed (2s / > 9min 45s) > console: [** ] A start job is running for Load/Save Random Seed (2s / > 9min 45s) > ... > console: Phosphor OpenBMC (Phosphor OpenBMC Project Reference Distro) > 0.1.0 gsj ttyS0 > console: gsj login: stmmaceth f0802000.eth eth1: stmmac_open: Cannot > attach to PHY (error: -22) > PASS (102.36 s) > > It pass but took >90sec. > > > + self.wait_for_console_pattern('CPU1: thread -1, cpu 1, socket 0') > > BTW Cc'ing Cleber/Wainer because there was an Avocado feature request > to be able to kick the test timeout watchdog at runtime, so here this > console pattern would give the test more time to allow success. Not > sure this is implemented or released yet. > > > + self.wait_for_console_pattern('OpenBMC Project Reference Distro') > > + self.wait_for_console_pattern('gsj login:') > > + > > + def test_arm_quanta_gsj_initrd(self): > > + """ > > + :avocado: tags=arch:arm > > + :avocado: tags=machine:quanta-gsj > > + """ > > + initrd_url = ( > > + 'https://github.com/hskinnemoen/openbmc/releases/download/' > > + '20200711-gsj-qemu-0/obmc-phosphor-initramfs-gsj.cpio.xz') > > + initrd_hash = '98fefe5d7e56727b1eb17d5c00311b1b5c945300' > > + initrd_path = self.fetch_asset(initrd_url, asset_hash=initrd_hash) > > + kernel_url = ( > > + 'https://github.com/hskinnemoen/openbmc/releases/download/' > > + '20200711-gsj-qemu-0/uImage-gsj.bin') > > + kernel_hash = 'fa67b2f141d56d39b3c54305c0e8a899c99eb2c7' > > + kernel_path = self.fetch_asset(kernel_url, asset_hash=kernel_hash) > > + dtb_url = ( > > + 'https://github.com/hskinnemoen/openbmc/releases/download/' > > + '20200711-gsj-qemu-0/nuvoton-npcm730-gsj.dtb') > > + dtb_hash = '18315f7006d7b688d8312d5c727eecd819aa36a4' > > + dtb_path = self.fetch_asset(dtb_url, asset_hash=dtb_hash) > > + > > + self.vm.set_console() > > + kernel_command_line = (self.KERNEL_COMMON_COMMAND_LINE + > > + 'console=ttyS0,115200n8 ' > > + 'earlycon=uart8250,mmio32,0xf0001000') > > + self.vm.add_args('-kernel', kernel_path, > > + '-initrd', initrd_path, > > + '-dtb', dtb_path, > > + '-append', kernel_command_line) > > + self.vm.launch() > > + > > + self.wait_for_console_pattern('Booting Linux on physical CPU 0x0') > > + self.wait_for_console_pattern('CPU1: thread -1, cpu 1, socket 0') > > Similarly: > > console: RPC: Registered named UNIX socket transport module. > console: RPC: Registered udp transport module. > console: RPC: Registered tcp transport module. > console: RPC: Registered tcp NFSv4.1 backchannel transport module. > console: Trying to unpack rootfs image as initramfs... > INTERRUPTED: Test interrupted by SIGTERM > Runner error occurred: Timeout reached > (90.85 s) > > Trying with timeout=240s: > > console: npcm7xx-ehci: EHCI npcm7xx driver > console: npcm7xx-ehci f0806000.usb: EHCI Host Controller > console: npcm7xx-ehci f0806000.usb: new USB bus registered, assigned bus > number 1 > console: npcm7xx-ehci f0806000.usb: can't setup: -110 > console: npcm7xx-ehci f0806000.usb: USB bus 1 deregistered > console: npcm7xx-ehci f0806000.usb: init fail, -110 > console: npcm7xx-ehci: probe of f0806000.usb failed with error -110 > console: rcu: INFO: rcu_sched self-detected stall on CPU > console: rcu: 0-....: (2131 ticks this GP) idle=1fe/1/0x40000002 > softirq=2485/2487 fqs=105 > console: (t=2100 jiffies g=3217 q=8) > console: NMI backtrace for cpu 0 > console: CPU: 0 PID: 1 Comm: swapper/0 Not tainted > 5.4.32-7dc9442-dirty-8978043 #1 > console: Hardware name: NPCM7XX Chip family > console: Backtrace: > console: [<b0107c4c>] (dump_backtrace) from [<b010823c>] > (show_stack+0x20/0x24) > console: r7:00000000 r6:600f0193 r5:00000000 r4:b0b5b1b8 > console: [<b010821c>] (show_stack) from [<b077b230>] (dump_stack+0x94/0xa8) > console: [<b077b19c>] (dump_stack) from [<b0782d78>] > (nmi_cpu_backtrace+0xc8/0xcc) > console: r7:00000000 r6:00000000 r5:00000000 r4:00000000 > console: [<b0782cb0>] (nmi_cpu_backtrace) from [<b0782e0c>] > (nmi_trigger_cpumask_backtrace+0x90/0x130) > console: r5:b0b06d58 r4:b0109454 > console: [<b0782d7c>] (nmi_trigger_cpumask_backtrace) from [<b010a578>] > (arch_trigger_cpumask_backtrace+0x20/0x24) > console: r9:800f0193 r8:b0800948 r7:b0b03e2c r6:b0b03ed0 r5:b0b0e080 > r4:00000000 > console: [<b010a558>] (arch_trigger_cpumask_backtrace) from [<b0188584>] > (rcu_dump_cpu_stacks+0x98/0xdc) > console: [<b01884ec>] (rcu_dump_cpu_stacks) from [<b01869d0>] > (print_cpu_stall+0x104/0x19c) > console: r10:b0a78ab8 r9:b0b03e2c r8:b0b03f00 r7:b0b0e080 r6:b0b042b0 > r5:00000008 > console: r4:b0b02d00 r3:00025cd3 > console: [<b01868cc>] (print_cpu_stall) from [<b0186e0c>] > (check_cpu_stall+0x138/0x238) > console: r9:00000000 r8:cf08c000 r7:b0b0e080 r6:00025cd3 r5:b0b03ec0 > r4:b0b0e080 > console: [<b0186cd4>] (check_cpu_stall) from [<b0186f3c>] > (rcu_pending+0x30/0xac) > console: r9:00000000 r8:cf08c000 r7:b0b0e080 r6:1f13e000 r5:cfbc1700 > r4:b0a83700 > console: [<b0186f0c>] (rcu_pending) from [<b0187764>] > (rcu_sched_clock_irq+0x174/0x20c) > console: r7:cf0907c0 r6:00000000 r5:b0a83779 r4:b0b5f050 > console: [<b01875f0>] (rcu_sched_clock_irq) from [<b018ecf0>] > (update_process_times+0x70/0x98) > console: r7:cf0907c0 r6:1f13e000 r5:00000000 r4:cfbbb340 > console: [<b018ec80>] (update_process_times) from [<b019f10c>] > (tick_periodic+0xc4/0xcc) > console: r7:cf0907c0 r6:cfbc4700 r5:7fffffff r4:b0b02d40 > console: [<b019f048>] (tick_periodic) from [<b019f1bc>] > (tick_handle_periodic+0x38/0x9c) > console: r5:7fffffff r4:ffffffff > console: [<b019f184>] (tick_handle_periodic) from [<b010af04>] > (twd_handler+0x40/0x48) > console: r9:cf0bbde0 r8:cf08c000 r7:cf0907c0 r6:00000010 r5:b0b04504 > r4:00000001 > console: [<b010aec4>] (twd_handler) from [<b017666c>] > (handle_percpu_devid_irq+0x10c/0x278) > console: r5:b0b04504 r4:cf08aa00 > console: [<b0176560>] (handle_percpu_devid_irq) from [<b016fd34>] > (__handle_domain_irq+0xb8/0xcc) > console: r10:b0a78ab8 r9:cf0bbde0 r8:cf08c000 r7:00000001 r6:00000000 > r5:00000000 > console: r4:b0a82b88 r3:b0176560 > console: [<b016fc7c>] (__handle_domain_irq) from [<b0102234>] > (gic_handle_irq+0x6c/0xa0) > console: r9:cf0bbde0 r8:d0803100 r7:d0802100 r6:d080210c r5:b0b37db4 > r4:b0b04504 > console: [<b01021c8>] (gic_handle_irq) from [<b0101a8c>] > (__irq_svc+0x6c/0x90) > console: Exception stack(0xcf0bbde0 to 0xcf0bbe28) > console: bde0: cf1b8e10 b0b4576c 00000002 00000354 00000000 b0b4576c > b04b3be8 b0b3dd20 > console: be00: b0a00510 b0a53854 b0a78ab8 cf0bbe5c cf0bbe08 cf0bbe30 > b04b0c14 b04b3be8 > console: be20: a00f0013 ffffffff > console: r9:cf0ba000 r8:b0a00510 r7:cf0bbe14 r6:ffffffff r5:a00f0013 > r4:b04b3be8 > console: [<b04b0ba4>] (bus_for_each_dev) from [<b04b2748>] > (driver_attach+0x2c/0x30) > console: r6:00000000 r5:cb640200 r4:b0b4576c > console: [<b04b271c>] (driver_attach) from [<b04b213c>] > (bus_add_driver+0x128/0x214) > console: [<b04b2014>] (bus_add_driver) from [<b04b4940>] > (driver_register+0xdc/0x118) > console: r7:00000000 r6:ffffe000 r5:00000000 r4:b0b4576c > console: [<b04b4864>] (driver_register) from [<b04b5c04>] > (__platform_driver_register+0x50/0x58) > console: r5:b0a2e408 r4:b0b3dd20 > console: [<b04b5bb4>] (__platform_driver_register) from [<b0a2e45c>] > (ehci_npcm7xx_init+0x54/0x60) > console: r5:b0a2e408 r4:00000000 > console: [<b0a2e408>] (ehci_npcm7xx_init) from [<b0102d80>] > (do_one_initcall+0xd0/0x260) > console: r5:b0a2e408 r4:b0b5eb00 > console: [<b0102cb0>] (do_one_initcall) from [<b0a01280>] > (kernel_init_freeable+0x15c/0x1f4) > console: r7:b09bbb4c r6:b0a53834 r5:b0b72700 r4:00000007 > console: [<b0a01124>] (kernel_init_freeable) from [<b0794f8c>] > (kernel_init+0x18/0x120) > console: r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 > r5:b0794f74 > console: r4:00000000 > console: [<b0794f74>] (kernel_init) from [<b01010e8>] > (ret_from_fork+0x14/0x2c) > console: Exception stack(0xcf0bbfb0 to 0xcf0bbff8) > console: bfa0: 00000000 00000000 > 00000000 00000000 > console: bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 > 00000000 00000000 > console: bfe0: 00000000 00000000 00000000 00000000 00000013 00000000 > console: r5:b0794f74 r4:00000000 > ... > console: rcu: INFO: rcu_sched self-detected stall on CPU > console: rcu: 1-....: (18 ticks this GP) idle=92e/1/0x40000002 > softirq=2723/2723 fqs=111 > console: (t=2106 jiffies g=3257 q=1) > console: NMI backtrace for cpu 1 > console: CPU: 1 PID: 17 Comm: kworker/1:0 Not tainted > 5.4.32-7dc9442-dirty-8978043 #1 > console: Hardware name: NPCM7XX Chip family > console: Workqueue: events regulator_init_complete_work_function > console: Backtrace: > console: [<b0107c4c>] (dump_backtrace) from [<b010823c>] > (show_stack+0x20/0x24) > console: r7:00000000 r6:600f0193 r5:00000000 r4:b0b5b1b8 > console: [<b010821c>] (show_stack) from [<b077b230>] (dump_stack+0x94/0xa8) > console: [<b077b19c>] (dump_stack) from [<b0782d78>] > (nmi_cpu_backtrace+0xc8/0xcc) > console: r7:00000000 r6:00000001 r5:00000000 r4:00000001 > console: [<b0782cb0>] (nmi_cpu_backtrace) from [<b0782e0c>] > (nmi_trigger_cpumask_backtrace+0x90/0x130) > console: r5:b0b06d58 r4:b0109454 > console: [<b0782d7c>] (nmi_trigger_cpumask_backtrace) from [<b010a578>] > (arch_trigger_cpumask_backtrace+0x20/0x24) > console: r9:800f0193 r8:b0800948 r7:b0b03e2c r6:b0b03ed0 r5:b0b0e080 > r4:00000001 > console: [<b010a558>] (arch_trigger_cpumask_backtrace) from [<b0188584>] > (rcu_dump_cpu_stacks+0x98/0xdc) > console: [<b01884ec>] (rcu_dump_cpu_stacks) from [<b01869d0>] > (print_cpu_stall+0x104/0x19c) > console: r10:00000000 r9:b0b03e2c r8:b0b03f00 r7:b0b0e080 r6:b0b042b0 > r5:00000001 > console: r4:b0b02d00 r3:0002a7f6 > console: [<b01868cc>] (print_cpu_stall) from [<b0186e0c>] > (check_cpu_stall+0x138/0x238) > console: r9:00000001 r8:cf08c000 r7:b0b0e080 r6:0002a7ef r5:b0b03ec0 > r4:b0b0e080 > console: [<b0186cd4>] (check_cpu_stall) from [<b0186f3c>] > (rcu_pending+0x30/0xac) > console: r9:00000001 r8:cf08c000 r7:b0b0e080 r6:1f150000 r5:cfbd3700 > r4:b0a83700 > console: [<b0186f0c>] (rcu_pending) from [<b0187764>] > (rcu_sched_clock_irq+0x174/0x20c) > console: r7:cf0907c0 r6:00000000 r5:b0a83779 r4:b0b5f050 > console: [<b01875f0>] (rcu_sched_clock_irq) from [<b018ecf0>] > (update_process_times+0x70/0x98) > console: r7:cf0907c0 r6:1f150000 r5:00000000 r4:cfbcd340 > console: [<b018ec80>] (update_process_times) from [<b019f10c>] > (tick_periodic+0xc4/0xcc) > console: r7:cf0907c0 r6:cfbd6700 r5:7fffffff r4:ffffffff > console: [<b019f048>] (tick_periodic) from [<b019f1bc>] > (tick_handle_periodic+0x38/0x9c) > console: r5:7fffffff r4:ffffffff > console: [<b019f184>] (tick_handle_periodic) from [<b010af04>] > (twd_handler+0x40/0x48) > console: r9:cf101eb8 r8:cf08c000 r7:cf0907c0 r6:00000010 r5:b0b04504 > r4:00000001 > console: [<b010aec4>] (twd_handler) from [<b017666c>] > (handle_percpu_devid_irq+0x10c/0x278) > console: r5:b0b04504 r4:cf08aa00 > console: [<b0176560>] (handle_percpu_devid_irq) from [<b016fd34>] > (__handle_domain_irq+0xb8/0xcc) > console: r10:00000000 r9:cf101eb8 r8:cf08c000 r7:00000001 r6:00000000 > r5:00000000 > console: r4:b0a82b88 r3:b0176560 > console: [<b016fc7c>] (__handle_domain_irq) from [<b0102234>] > (gic_handle_irq+0x6c/0xa0) > console: r9:cf101eb8 r8:d0803100 r7:d0802100 r6:d080210c r5:b0b37db4 > r4:b0b04504 > console: [<b01021c8>] (gic_handle_irq) from [<b0101a8c>] > (__irq_svc+0x6c/0x90) > console: Exception stack(0xcf101eb8 to 0xcf101f00) > console: 1ea0: > b0b38e5c cf007264 > console: 1ec0: b0b54cc4 b046a4ac b0b38e5c cf006600 cfbd2c00 cfbd5f00 > 00000000 b0b5ec90 > console: 1ee0: 00000000 cf101f44 00007374 cf101f08 b0136778 b046a4ac > 600f0113 ffffffff > console: r9:cf100000 r8:00000000 r7:cf101eec r6:ffffffff r5:600f0113 > r4:b046a4ac > console: [<b0136444>] (process_one_work) from [<b0136c54>] > (worker_thread+0x2d0/0x4e4) > console: r10:cfbd2c00 r9:b0b02d00 r8:cf100000 r7:cfbd2c18 r6:cf006614 > r5:cfbd2c00 > console: r4:cf006600 > console: [<b0136984>] (worker_thread) from [<b013c8d0>] > (kthread+0x150/0x158) > console: r10:cf0d851c r9:b0136984 r8:cf006600 r7:cf100000 r6:cf0bbd7c > r5:cf0d8580 > console: r4:cf0d8500 > console: [<b013c780>] (kthread) from [<b01010e8>] (ret_from_fork+0x14/0x2c) > console: Exception stack(0xcf101fb0 to 0xcf101ff8) > console: 1fa0: 00000000 00000000 > 00000000 00000000 > console: 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 > 00000000 00000000 > console: 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 > console: r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 > r5:b013c780 > console: r4:cf0d8580 r3:00000001 > console: Run /init as init process > console: rcu: INFO: rcu_sched self-detected stall on CPU > console: rcu: 1-....: (2120 ticks this GP) idle=ab2/1/0x40000002 > softirq=3079/3079 fqs=78 > console: (t=2107 jiffies g=3741 q=0) > console: NMI backtrace for cpu 1 > console: CPU: 1 PID: 138 Comm: mount Not tainted > 5.4.32-7dc9442-dirty-8978043 #1 > console: Hardware name: NPCM7XX Chip family > console: Backtrace: > console: [<b0107c4c>] (dump_backtrace) from [<b010823c>] > (show_stack+0x20/0x24) > console: r7:00000000 r6:600d0193 r5:00000000 r4:b0b5b1b8 > console: [<b010821c>] (show_stack) from [<b077b230>] (dump_stack+0x94/0xa8) > console: [<b077b19c>] (dump_stack) from [<b0782d78>] > (nmi_cpu_backtrace+0xc8/0xcc) > console: r7:00000000 r6:00000001 r5:00000000 r4:00000001 > console: [<b0782cb0>] (nmi_cpu_backtrace) from [<b0782e0c>] > (nmi_trigger_cpumask_backtrace+0x90/0x130) > console: r5:b0b06d58 r4:b0109454 > console: [<b0782d7c>] (nmi_trigger_cpumask_backtrace) from [<b010a578>] > (arch_trigger_cpumask_backtrace+0x20/0x24) > console: r9:800d0193 r8:b0800948 r7:b0b03e2c r6:b0b03ed0 r5:b0b0e080 > r4:00000001 > console: [<b010a558>] (arch_trigger_cpumask_backtrace) from [<b0188584>] > (rcu_dump_cpu_stacks+0x98/0xdc) > console: [<b01884ec>] (rcu_dump_cpu_stacks) from [<b01869d0>] > (print_cpu_stall+0x104/0x19c) > console: r10:00000015 r9:b0b03e2c r8:b0b03f00 r7:b0b0e080 r6:b0b042b0 > r5:00000000 > console: r4:b0b02d00 r3:0003301a > console: [<b01868cc>] (print_cpu_stall) from [<b0186e0c>] > (check_cpu_stall+0x138/0x238) > console: r9:00000001 r8:cf08c000 r7:b0b0e080 r6:00033011 r5:b0b03ec0 > r4:b0b0e080 > console: [<b0186cd4>] (check_cpu_stall) from [<b0186f3c>] > (rcu_pending+0x30/0xac) > console: r9:00000001 r8:cf08c000 r7:b0b0e080 r6:1f150000 r5:cfbd3700 > r4:b0a83700 > console: [<b0186f0c>] (rcu_pending) from [<b0187764>] > (rcu_sched_clock_irq+0x174/0x20c) > console: r7:cf0907c0 r6:00000000 r5:b0a83779 r4:b0b5f050 > console: [<b01875f0>] (rcu_sched_clock_irq) from [<b018ecf0>] > (update_process_times+0x70/0x98) > console: r7:cf0907c0 r6:1f150000 r5:00000000 r4:cfbcd340 > console: [<b018ec80>] (update_process_times) from [<b019f10c>] > (tick_periodic+0xc4/0xcc) > console: r7:cf0907c0 r6:cfbd6700 r5:7fffffff r4:ffffffff > console: [<b019f048>] (tick_periodic) from [<b019f1bc>] > (tick_handle_periodic+0x38/0x9c) > console: r5:7fffffff r4:ffffffff > console: [<b019f184>] (tick_handle_periodic) from [<b010af04>] > (twd_handler+0x40/0x48) > console: r9:cb7c7ed0 r8:cf08c000 r7:cf0907c0 r6:00000010 r5:b0b04504 > r4:00000001 > console: [<b010aec4>] (twd_handler) from [<b017666c>] > (handle_percpu_devid_irq+0x10c/0x278) > console: r5:b0b04504 r4:cf08aa00 > console: [<b0176560>] (handle_percpu_devid_irq) from [<b016fd34>] > (__handle_domain_irq+0xb8/0xcc) > console: r10:00000015 r9:cb7c7ed0 r8:cf08c000 r7:00000001 r6:00000000 > r5:00000000 > console: r4:b0a82b88 r3:b0176560 > console: [<b016fc7c>] (__handle_domain_irq) from [<b0102234>] > (gic_handle_irq+0x6c/0xa0) > console: r9:cb7c7ed0 r8:d0803100 r7:d0802100 r6:d080210c r5:b0b37db4 > r4:b0b04504 > console: [<b01021c8>] (gic_handle_irq) from [<b0101a8c>] > (__irq_svc+0x6c/0x90) > console: Exception stack(0xcb7c7ed0 to 0xcb7c7f18) > console: 7ec0: 00000000 aeffffff > 00000000 00000055 > console: 7ee0: 0000021c cb7c6000 cb7c0de4 000b21a0 00008004 cb7c6000 > 00000015 cb7c7f3c > console: 7f00: 00000051 cb7c7f20 b0278a5c b0278a60 000d0013 ffffffff > console: r9:cb7c6000 r8:00008004 r7:cb7c7f04 r6:ffffffff r5:000d0013 > r4:b0278a60 > console: [<b02789dc>] (exact_copy_from_user) from [<b027dc60>] > (copy_mount_options+0x58/0xa0) > console: r7:aea22fa9 r6:cb7c0000 r5:000b11a0 r4:00001000 > console: [<b027dc08>] (copy_mount_options) from [<b027e538>] > (ksys_mount+0x74/0xc4) > console: r7:aea22fa9 r6:cb77db00 r5:00008004 r4:cb77d240 > console: [<b027e4c4>] (ksys_mount) from [<b027e5ac>] (sys_mount+0x24/0x2c) > console: r8:b0101204 r7:00000015 r6:000974dc r5:00008004 r4:000b11a0 > console: [<b027e588>] (sys_mount) from [<b0101000>] > (ret_fast_syscall+0x0/0x54) > console: Exception stack(0xcb7c7fa8 to 0xcb7c7ff0) > console: 7fa0: 000b11a0 00008004 aea22fa3 aea22fa9 > aea22fb0 00008004 > console: 7fc0: 000b11a0 00008004 000974dc 00000015 000b11a0 00000000 > 00000000 000af65c > console: 7fe0: 000af4e0 aea22bb8 0004f3e0 49fe8330 > INTERRUPTED: Test interrupted by SIGTERM > Runner error occurred: Timeout reached > (240.45 s) > > Is that expected? I'm not sure why it only happens when running direct kernel boot with unoptimized qemu, but it seems a little happier if I enable a few more peripherals that I have queued up (sd, ehci, ohci and rng), though not enough. It still stalls for an awfully long time on "console: Run /init as init process" though. I'm not sure what it's doing there. With -O2 it only takes a couple of seconds to move on. Adding set -x to the top of /init give me this: https://gist.github.com/hskinnemoen/d48982b791dd8389e41468c9a3fbffbe The blkid invocations seem to take a lot of time (e.g. there was an NMI backtrace while running blkid /dev/mtdblock6). Perhaps it takes especially long when there's no valid filesystem in the flash? > Compiled with -O2 it works much better: > > console: Give root password for system maintenance > PASS (11.71 s) > > > + self.wait_for_console_pattern( > > + 'Give root password for system maintenance') > > + > > def test_arm_orangepi(self): > > """ > > :avocado: tags=arch:arm > > >