[PATCH v6 08/12] efi_loader: Disable ANSI output for tests

[Heinrich Schuchardt]

On 10/1/24 20:02, Tom Rini wrote:
> On Tue, Oct 01, 2024 at 04:34:54AM +0200, Heinrich Schuchardt wrote:
>> On 10/1/24 02:24, Tom Rini wrote:
>>> On Tue, Oct 01, 2024 at 01:38:56AM +0200, Heinrich Schuchardt wrote:
>>>> On 26.09.24 23:59, Simon Glass wrote:
>>>>> We don't want ANSI characters written in tests since it is a pain to
>>>>> check the output with ut_assert_nextline() et al.
>>>>>
>>>>> Provide a way to tests to request that ANSI characters not be sent.
>>>>>
>>>>> Add a proper function comment while we are here, to encourage others.
>>>>>
>>>>> Signed-off-by: Simon Glass <sjg at chromium.org>
>>>>
>>>> Please, consider prior review before resubmitting patches.
>>>>
>>>> As responded to all prior submissions:
>>>>
>>>> We want to test the code running on actual machines.
>>>> We don't want to have sandbox code everywhere.
>>>>
>>>> I cannot see any test that is not passing due to the current behavior.
>>>
>>> The pytests for the EFI selftests are unreliable for me, on Raspberry Pi
>>> 3, more often in 32bit mode than 64bit mode, but I feel like I see it
>>> there too. And when they fail, the console log is full of ANSI escape
>>> sequences. Is this specific test a test you run regularly on real
>>> hardware?
>>>
>>
>> It is not only the EFI test but also pytest adding color to the console
>> output.
>
> Alright, so at least for the problems I have _today_, I've figured it
> out, and the problem is that the watchdog test fails too quickly:
>
> [snip]
> test/py/tests/test_efi_selftest.py ..F
> test/py/u_boot_console_base.p
> =================================== FAILURES ===================================
> ______________________ test_efi_selftest_watchdog_reboot _______________________
> test/py/tests/test_efi_selftest.py:61: in test_efi_selftest_watchdog_reboot
>      u_boot_console.restart_uboot()
> test/py/u_boot_console_base.py:478: in restart_uboot
>      self.ensure_spawned(expect_reset)
> test/py/u_boot_console_base.py:442: in ensure_spawned
>      self.wait_for_boot_prompt(loop_num = loop_num)
> test/py/u_boot_console_base.py:195: in wait_for_boot_prompt
>      raise Exception('Bad pattern found on console: ' +
> E   Exception: Bad pattern found on console: spl_signon
> ----------------------------- Captured stdout call -----------------------------
> => setenv efi_selftest list
> => => bootefi selftest
> 78No EFI system partition
> No EFI system partition
> Failed to persist EFI variables
> No EFI system partition
> Failed to persist EFI variables
> No EFI system partition
> Failed to persist EFI variables
>
> Available tests:
> 'block image transfer' - on request
> 'block device'
> 'configuration tables'
> 'controllers'
> 'crc32'
> 'device path'
> 'device path utilities protocol'
> 'conformance profile table'
> 'event groups'
> 'event services'
> 'exception' - on request
> 'ExitBootServices'
> 'device tree'
> 'graphical output'
> 'HII database protocols'
> 'load file protocol'
> 'loaded image'
> 'load image from file'
> 'mem'
> 'memory'
> 'open protocol'
> 'manage protocols'
> 'register protocol notify'
> 'reset system' - on request
> 'reset system runtime' - on request
> 'real time clock'
> 'simple network protocol'
> 'start image return'
> 'start image exit'
> 'text input' - on request
> 'extended text input' - on request
> 'text output'
> 'task priority levels'
> 'unicode collation'
> 'variables'
> 'variables at runtime'
> 'virtual address map'
> 'watchdog timer'
> 'watchdog reboot' - on request
> => => setenv efi_selftest watchdog reboot
> => => bootefi selftest
> 
> Testing EFI API implementation
> 
> Selected test: 'watchdog reboot'
> 
> Setting up 'watchdog reboot'
> Setting up 'watchdog reboot' succeeded
> 
> Executing 'watchdog reboot'
> 
> EFI: Watchdog timeout
> resetting ...
> +u-boot-test-reset am64x_evm_a53 na
> Selected role am64-sk from configuration file
> Selected role am64-sk from configuration file
> connecting to NetworkSerialPort(target=Target(name='am64-sk', env=Environment(config_file='/home/trini/u-boot/lg_env.yaml')), name='USBSerialPort', state=<BindingState.bound: 1>, avail=True, host='ti-lab-host', port=57479, speed=115200, protocol='rfc2217') calling microcom -s 115200 -t ti-lab-host:57479
> connected to 192.168.116.10 (port 57479)
> Escape character: Ctrl-\
> Type the escape character to get to the prompt.
>
> U-Boot SPL 2024.10-rc5-00022-g17da9795c115 (Oct 01 2024 - 14:29:10 +0000)
> SYSFW ABI: 3.1 (firmware rev 0x0009 '9.2.7--v09.02.07 (Kool Koala)')
> EEPROM not available at 0x50, trying to read at 0x51
> SPL initial stack usage: 13368 bytes
> Trying to boot from MMC2
> Loading Environment from MMC... MMC Device 0 not found
> *** Warning - No MMC card found, using default environment
>
> Starting ATF on ARM64 core...
>
> NOTICE:  BL31: v2.10.0(release):v2.10.0-729-gc8be7c08c
> NOTICE:  BL31: Built : 13:50:07, Apr 24 2024
> I/TC:
> I/TC: OP-TEE version: 4.2.0-22-g16fbd46d2 (gcc version 13.2.0 (GCC)) #2 Wed Apr 24 19:50:23 UTC 2024 aarch64
> I/TC: WARNING: This OP-TEE configuration might be insecure!
> I/TC: WARNING: Please check https://optee.readthedocs.io/en/latest/architecture/porting_guidelines.html
> I/TC: Primary CPU initializing
> I/TC: GIC redistributor base address not provided
> I/TC: Assuming default GIC group status and modifier
> I/TC: SYSFW ABI: 3.1 (firmware rev 0x0009 '9.2.7--v09.02.07 (Kool Koala)')
> I/TC: HUK Initialized
> I/TC: Activated SA2UL device
> I/TC: Fixing SA2UL firewall owner for GP device
> I/TC: Enabled firewalls for SA2UL TRNG device
> I/TC: SA2UL TRNG initialized
> I/TC: SA2UL Drivers initialized
> I/TC: Primary CPU switching to normal world boot
>
> U-Boot SPL 2024.10-rc5-00022-g17da9795c115 (Oct 01 2024 - 14:31:31 +0000)
> SYSFW ABI: 3.1 (firmware rev 0x0009 '9.2.7--v09.02.07 (Kool Koala)')
> Trying to boot from MMC2
> ?
> U-Boot SPL 2024.10-rc5-00022-g17da9795c115 (Oct 01 2024 - 14:29:10 +0000)
> Resetting on cold boot to workaround ErrataID:i2331
> Please resend tiboot3.bin in case of UART/DFU boot
> resetting ...
>
> U-Boot SPL 2024.10-rc5-00022-g17da9795c115 (Oct 01 2024 - 14:29:10 +0000)
> =========================== short test summary info ============================
> SKIPPED [47] test/py/conftest.py:512: board "am64x_evm_a53" not supported
> SKIPPED [5] test/py/conftest.py:531: .config feature "cmd_avb" not enabled
> SKIPPED [1] test/py/conftest.py:531: .config feature "optee_ta_avb" not enabled
> SKIPPED [1] test/py/conftest.py:531: .config feature "cmd_bootstage" not enabled
> SKIPPED [2] test/py/conftest.py:531: .config feature "bootstage_stash" not enabled
> SKIPPED [1] test/py/tests/test_dfu.py:114: got empty parameter set ['env__usb_dev_port'], function test_dfu at /home/trini/u-boot/u-boot/test/py/tests/test_dfu.py:113
> SKIPPED [1] test/py/tests/test_efi_fit.py:401: No env__efi_fit_tftp_file binary specified in environment
> FAILED test/py/tests/test_efi_selftest.py::test_efi_selftest_watchdog_reboot
> !!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 1 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!
> ================== 1 failed, 17 passed, 58 skipped in 58.92s ===================
>
> I thought it was the escape sequences confusing the check rather than
> the platform takes longer than expected to provide whatever the expected
> string is. Another TI K3 platform gets slightly farther along before
> failing the same way. I'm going back to looping over Pis to see if they
> fail in a way that they used to in my previous lab setup.
>

The relevant error message is:

     E   Exception: Bad pattern found on console: spl_signon

The error occurs because the substring

     U-Boot SPL 2024.10

occurs multiple times during the reboot process. This is not expected in
wait_for_boot_prompt().

The EFI test is resetting the board and then calling restart_uboot()
which by itself does another reset.

While the watchdog triggered reboot is running thee test environment may
need some time before triggering a reboot itself. This may lead to the
observed duplicate output of the U-Boot greeter which is recorded as an
error.

Maybe we should directly call wait_for_boot_prompt(loop_num = 2).


diff --git a/test/py/tests/test_efi_selftest.py
b/test/py/tests/test_efi_selftest.py
index 43f24245582..c3ee1888afb 100644
--- a/test/py/tests/test_efi_selftest.py
+++ b/test/py/tests/test_efi_selftest.py
@@ -58,7 +58,7 @@ def test_efi_selftest_watchdog_reboot(u_boot_console):
      u_boot_console.run_command(cmd='bootefi selftest',
wait_for_prompt=False)
      if u_boot_console.p.expect(['resetting', 'U-Boot']):
          raise Exception('Reset failed in \'watchdog reboot\' test')
-    u_boot_console.restart_uboot()
+    u_boot_console.wait_for_boot_prompt(loop_num = 2)

  @pytest.mark.buildconfigspec('cmd_bootefi_selftest')
  def test_efi_selftest_text_input(u_boot_console):

Thanks for bringing the issue to my attention.

Best regards

Heinrich