Re: [PULL 18/42] tests: avocado: boot_linux_console: Add test case for bpim2u

[Thomas Huth]

On 30/06/2023 10.45, qianfan wrote:
> 在 2023/6/30 15:27, Thomas Huth 写道:
> > On 30/06/2023 08.15, qianfan wrote:
> > > 在 2023/6/29 19:35, Thomas Huth 写道:
> > > > On 06/06/2023 11.47, Peter Maydell wrote:
> > > > > From: qianfan Zhao <qianfanguijin@163.com>
> > > > >
> > > > > Add test case for booting from initrd and sd card.
> > > > >
> > > > > Signed-off-by: qianfan Zhao <qianfanguijin@163.com>
> > > > > Reviewed-by: Niek Linnenbank <nieklinnenbank@gmail.com>
> > > > > Tested-by: Niek Linnenbank <nieklinnenbank@gmail.com>
> > > > > Signed-off-by: Peter Maydell <peter.maydell@linaro.org>
> > > > > ---
> > > > >   tests/avocado/boot_linux_console.py | 176 ++++++++++++++++++++++++++++
> > > > >   1 file changed, 176 insertions(+)
> > > > ...
> > > > > +    def test_arm_bpim2u_gmac(self):
> > > > > +        """
> > > > > +        :avocado: tags=arch:arm
> > > > > +        :avocado: tags=accel:tcg
> > > > > +        :avocado: tags=machine:bpim2u
> > > > > +        :avocado: tags=device:sd
> > > > > +        """
> > > > > +        self.require_netdev('user')
> > > > > +
> > > > > +        deb_url = 
> > > > > ('https://apt.armbian.com/pool/main/l/linux-5.10.16-sunxi/'
> > > > > + 'linux-image-current-sunxi_21.02.2_armhf.deb')
> > > > > +        deb_hash = '9fa84beda245cabf0b4fa84cf6eaa7738ead1da0'
> > > > > +        deb_path = self.fetch_asset(deb_url, asset_hash=deb_hash)
> > > > > +        kernel_path = self.extract_from_deb(deb_path,
> > > > > + '/boot/vmlinuz-5.10.16-sunxi')
> > > > > +        dtb_path = ('/usr/lib/linux-image-current-sunxi/'
> > > > > +                    'sun8i-r40-bananapi-m2-ultra.dtb')
> > > > > +        dtb_path = self.extract_from_deb(deb_path, dtb_path)
> > > > > +        rootfs_url = 
> > > > > ('http://storage.kernelci.org/images/rootfs/buildroot/'
> > > > > + 'buildroot-baseline/20221116.0/armel/rootfs.ext2.xz')
> > > > > +        rootfs_hash = 'fae32f337c7b87547b10f42599acf109da8b6d9a'
> > > > > +        rootfs_path_xz = self.fetch_asset(rootfs_url, 
> > > > > asset_hash=rootfs_hash)
> > > > > +        rootfs_path = os.path.join(self.workdir, 'rootfs.cpio')
> > > > > +        archive.lzma_uncompress(rootfs_path_xz, rootfs_path)
> > > > > +        image_pow2ceil_expand(rootfs_path)
> > > > > +
> > > > > +        self.vm.set_console()
> > > > > +        kernel_command_line = (self.KERNEL_COMMON_COMMAND_LINE +
> > > > > +                               'console=ttyS0,115200 '
> > > > > +                               'root=/dev/mmcblk0 rootwait rw '
> > > > > +                               'panic=-1 noreboot')
> > > > > +        self.vm.add_args('-kernel', kernel_path,
> > > > > +                         '-dtb', dtb_path,
> > > > > +                         '-drive', 'file=' + rootfs_path + 
> > > > > ',if=sd,format=raw',
> > > > > +                         '-net', 'nic,model=gmac,netdev=host_gmac',
> > > > > +                         '-netdev', 'user,id=host_gmac',
> > > > > +                         '-append', kernel_command_line,
> > > > > +                         '-no-reboot')
> > > > > +        self.vm.launch()
> > > > > +        shell_ready = "/bin/sh: can't access tty; job control turned off"
> > > > > +        self.wait_for_console_pattern(shell_ready)
> > > > > +
> > > > > +        exec_command_and_wait_for_pattern(self, 'cat /proc/cpuinfo',
> > > > > +                                                'Allwinner sun8i Family')
> > > > > +        exec_command_and_wait_for_pattern(self, 'cat /proc/partitions',
> > > > > +                                                'mmcblk0')
> > > > > +        exec_command_and_wait_for_pattern(self, 'ifconfig eth0 up',
> > > > > +                                                 'eth0: Link is Up')
> > > > > +        exec_command_and_wait_for_pattern(self, 'udhcpc eth0',
> > > > > +            'udhcpc: lease of 10.0.2.15 obtained')
> > > > > +        exec_command_and_wait_for_pattern(self, 'ping -c 3 10.0.2.2',
> > > > > +            '3 packets transmitted, 3 packets received, 0% packet loss')
> > > > > +        exec_command_and_wait_for_pattern(self, 'reboot',
> > > > > +                                                'reboot: Restarting 
> > > > > system')
> > > > > +        # Wait for VM to shut down gracefully
> > > > > +        self.vm.wait()
> > > >
> > > > FYI, the test_arm_bpim2u_gmac test just failed during one of my CI runs:
> > > >
> > > > https://gitlab.com/thuth/qemu/-/jobs/4565108610#L300
> > > >
> > > > Looking at the debug.log in the artifacts, it looks like the kernel was 
> > > > hanging during boot:
> > > >
> > > > 10:53:56 DEBUG| of_cfs_init
> > > > 10:53:56 DEBUG| of_cfs_init: OK
> > > > 10:53:56 DEBUG| ALSA device list:
> > > > 10:53:56 DEBUG| No soundcards found.
> > > > 10:53:56 DEBUG| Waiting for root device /dev/mmcblk0...
> > > > 10:54:26 DEBUG| dcdc4: disabling
> > > > 10:54:26 DEBUG| dc5ldo: disabling
> > > > 10:54:26 DEBUG| vcc5v0: disabling
> > > > 10:55:15 ERROR|
> > > > ...
> > > > 10:55:15 ERROR| RuntimeError: Test interrupted by SIGTERM
> > > >
> > > > I can reproduce the problem locally on my laptop when running the test 
> > > > repeatedly, e.g. with:
> > > >
> > > >  make check-venv
> > > >  for ((x=0;x<10;x++)); do \
> > > >   ./tests/venv/bin/avocado run \
> > > >     tests/avocado/boot_linux_console.py:test_arm_bpim2u_gmac ; \
> > > >  done
> > > >
> > > > 1 out of 10 runs were failing.
> > > >
> > > > Any ideas what could be wrong in those failing cases?
> > > Hi:
> > >
> > > I can reproduce this issue based on master 
> > > code(v8.0.0-rc1-2442-g4d541f63e9) with your's
> > > test scripts, and I have tested 50 times only failed once.
> > >
> > > Copy liunx boot logs and make a diff:
> > >
> > > $ diff ~/a/qemu_bpi_good.txt ~/a/qemu_bpi_bad.txt
> > ...
> > > 288a289,291
> > >  > mmc1: host does not support reading read-only switch, assuming 
> > > write-enable
> > >  > mmc1: new high speed SD card at address 4567
> > >  > mmcblk1: mmc1:4567 QEMU! 64.0 MiB
> > > 296,298d298
> > > < mmc0: host does not support reading read-only switch, assuming 
> > > write-enable
> > > < mmc0: new high speed SD card at address 4567
> > > < mmcblk0: mmc0:4567 QEMU! 64.0 MiB
> > > 322,331c322,325
> > > < EXT4-fs (mmcblk0): mounting ext2 file system using the ext4 subsystem
> > > < EXT4-fs (mmcblk0): mounted filesystem without journal. Opts: (null)
> > > < VFS: Mounted root (ext2 filesystem) on device 179:0.
> > > < devtmpfs: mounted
> > > < Freeing unused kernel memory: 1024K
> > > < Run /sbin/init as init process
> > > < EXT4-fs (mmcblk0): re-mounted. Opts: (null)
> > > < Starting syslogd: OK
> > > < Starting klogd: OK
> > > < Running sysctl: OK
> > > \ No newline at end of file
> > > ---
> > >  > Waiting for root device /dev/mmcblk0...
> > >  > dcdc4: disabling
> > >  > dc5ldo: disabling
> > >  > vcc5v0: disabling
> > > \ No newline at end of file
> > >
> > > The first mmc device should be mmc0, but the linux kernel named it as 
> > > mmcblk1.
> > > So it always 'Waiting for root device /dev/mmcblk0...', that make the rootfs
> > > can not mounted.
> > >
> > > I'm not make sure where the problem came from.
> >
> > Oh, that's ugly, I think the problem is likely that the numbering
> > of device names that are directly in /dev/ is never guaranteed by
> > the Linux kernel.
> >
> > Could you please try whether this work more reliably for you
> > instead:
> >
> > diff a/tests/avocado/boot_linux_console.py 
> > b/tests/avocado/boot_linux_console.py
> > --- a/tests/avocado/boot_linux_console.py
> > +++ b/tests/avocado/boot_linux_console.py
> > @@ -869,7 +869,7 @@ def test_arm_bpim2u_gmac(self):
> >          self.vm.set_console()
> >          kernel_command_line = (self.KERNEL_COMMON_COMMAND_LINE +
> >                                 'console=ttyS0,115200 '
> > -                               'root=/dev/mmcblk0 rootwait rw '
> > +                               'root=b300 rootwait rw '
> >                                 'panic=-1 noreboot')
> >          self.vm.add_args('-kernel', kernel_path,
> >                           '-dtb', dtb_path,
> >
> > ?
> Yes, this patch is useful.
>
> The rootfs can mount successful even if the mmc block enumed as mmcblk1, 
> next is the
> kernel logs:
>
> mmc1: new high speed SD card at address 4567
> mmcblk1: mmc1:4567 QEMU! 64.0 MiB
> EXT4-fs (mmcblk1): mounting ext2 file system using the ext4 subsystem
> EXT4-fs (mmcblk1): mounted filesystem without journal. Opts: (null)
> VFS: Mounted root (ext2 filesystem) on device 179:0.

Great!

> But the test scripts still fail due to it always waiting mmc0blk:
>
>      exec_command_and_wait_for_pattern(self, 'cat /proc/partitions', 'mmcblk0')

Ok, so the "0" likely got to be dropped here?

> Could you please explain where is the "b300" come from?

I ran the kernel once without the "root=/dev/mmcblk0 rootwait"
part in its command line. Then it prints out something like this:

 VFS: Cannot open root device "(null)" or unknown-block(0,0): error -6
 Please append a correct "root=" boot option; here are the available partitions:
 0100            4096 ram0
 (driver?)
 0101            4096 ram1
 (driver?)
 0102            4096 ram2
 (driver?)
 0103            4096 ram3
 (driver?)
 b300           65536 mmcblk0
 driver: mmcblk
 Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(0,0)

Seems like the "b300" is stable here, no matter whether
its mmcblk0 or mmcblk1.

 Thomas