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

[Thomas Huth <thuth@redhat.com>]

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