[PATCH 1/1] test: stabilize test_efi_secboot
AKASHI Takahiro
takahiro.akashi at linaro.org
Thu May 21 11:55:56 CEST 2020
Heinrich,
On Thu, May 21, 2020 at 10:17:43AM +0200, Heinrich Schuchardt wrote:
> On 5/21/20 2:23 AM, AKASHI Takahiro wrote:
> > Heinrich,
> >
> > On Mon, May 11, 2020 at 03:56:56PM +0900, AKASHI Takahiro wrote:
> >> Heinrich,
> >>
> >> On Fri, May 08, 2020 at 08:10:28AM +0900, AKASHI Takahiro wrote:
> >>> On Thu, May 07, 2020 at 11:14:17PM +0200, Heinrich Schuchardt wrote:
> >>>> On 5/7/20 2:36 AM, AKASHI Takahiro wrote:
> >>>>> Heinrich,
> >>>>>
> >>>>> On Mon, May 04, 2020 at 12:33:26PM +0200, Heinrich Schuchardt wrote:
> >>>>>> When setting up the console via function efi_console_register() we call
> >>>>>> query_console_serial(). This functions sends an escape sequence to the
> >>>>>> terminal to query the display size. The response is another escape
> >>>>>> sequence.
> >>>>>>
> >>>>>> console.run_command_list() is looking for a regular expression '^==>'.
> >>>>>> If the escape sequence for the screen size precedes the prompt without a
> >>>>>> line break, no match is found.
> >>>>>>
> >>>>>> When efi_disk_register() is called before efi_console_register() this leads
> >>>>>> to a test failuere of the UEFI secure boot tests.
> >>>>>
> >>>>> Why does the order of those calls affect test results?
> >>>>
> >>>> Please, have a look at function query_console_serial() and at
> >>>> run_command_list().
> >>>>
> >>>> As described above:
> >>>> '\e7\e[r\e[999;999H\e[6n\e8==>' cannot be matched by regular expression
> >>>> '^==>'.
> >>>
> >>> (Probably) right, but what I don't get here is why efi_disk_register()
> >>> have an impact on efi_console_register(). The former function has
> >>> nothing to do with any console behaviors.
>
> efi_console_register writes ''\e7\e[r\e[999;999H\e[6n\e8' to the console.
>
> efi_disk_register writes to the console, e.g. "Found 2 disks\n". This
> output occurs before the output of the command line prompt.
How on earth the output can occur *before* the command line?
After applying your patch to efi_setup.c, the sequence of initialization
looks like:
efi_init_obj_list()
efi_disk_register()
efi_console_register()
But anyhow, efi_init_obj_list() will be called when the first "efi"
command is executed.
Therefore, the captured output of console must be logically
1. text of command line (efi command)
2. output from efi_init_obj_list()
2.1 output from efi_disk_register()
2.2 output from efi_console_register()
Again, why can the output (2.1) lead to (1)?
As a matter of fact, the real output log from pytest clearly
shows the order of output:
(I left html tags as they are.)
=== from test-log.html of pytest ===
<html>
...
U-Boot 2020.07-rc2-00021-gbd934e4844d5-dirty (May 21 2020 - 18:25:14 +0900)
Model: sandbox
DRAM: 128 MiB
WDT: Started with servicing (60s timeout)
MMC: mmc2: 2 (SD), mmc1: 1 (SD), mmc0: 0 (SD)
In: serial
Out: vidconsole
Err: vidconsole
Model: sandbox
SCSI:
Net: eth0: eth at 10002000, eth5: eth at 10003000, eth3: sbe5, eth1: eth at 10004000
Hit any key to stop autoboot: 2 %08%08%08 0
=> </pre>
...
U-Boot 2020.07-rc2-00021-gbd934e4844d5-dirty (May 21 2020 - 18:25:14 +0900)
Model: sandbox
DRAM: 128 MiB
WDT: Started with servicing (60s timeout)
MMC: mmc2: 2 (SD), mmc1: 1 (SD), mmc0: 0 (SD)
In: serial
Out: vidconsole
Err: vidconsole
Model: sandbox
SCSI:
Net: eth0: eth at 10002000, eth5: eth at 10003000, eth3: sbe5, eth1: eth at 10004000
Hit any key to stop autoboot: 2 %08%08%08 0
=> </pre>
...
<pre><span class="implicit">=> </span>fatload host 0:1 4000000 KEK.auth
2045 bytes read in 0 ms
=> </pre>
...
<pre><span class="implicit">=> </span>setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK
Scanning disk mmc2.blk...
** Unrecognized filesystem type **
Scanning disk mmc1.blk...
** Unrecognized filesystem type **
Scanning disk mmc0.blk...
** Unrecognized filesystem type **
Scanning disk host0...
Found 5 disks
%1b7%1b[r%1b[999;999H%1b[6n%1b8=> </pre>
...
</html>
=== end of log ===
> Now the Python test can match the regular expression '^==>' because the
> prompt is the first output on the line.
No. Python failed to match against "^==>."
-Takahiro Akashi
> >>
> >> You have merged your patch without replying to my comment.
>
> Your comment was written after my pull request.
>
> >
> >
> > Not yet
> >
> >
> >>> Moreover, I wonder
> >>> - why you want to move efi_console_register() after efi_disk_register().
> >>> - why python script can see such escape sequences.
> >>
> >> I don't like your fix.
> >> With your fixes, my secure boot pytest now fails to run
> >> on sandbox locally.
>
> Why is it failing?
>
> Best regards
>
> Heinrich
>
> >>
> >> Instead, I propose:
> >> 1. revert your commits
> >> commit 16ad946f41d3 ("efi_loader: change setup sequence")
> >> commit 5827c2545849 ("test: stabilize test_efi_secboot")
> >> 2. move efi_console_register() forward *before* efi_console_register()
> >>
> >>
> >> Then my secure boot test should work again without any modification.
> >> I believe that my solution is much better than your workaround.
> >
> >
> > Any comment?
> > Or do you want me to post a patch?
> >
> >
> >> -Takahiro Akashi
> >>
> >>>>
> >>>>>
> >>>>>> We can avoid the problem if the first UEFI command passed to
> >>>>>> u_boot_console.run_command_list() produces output. This patch achieves this
> >>>>>> by appending '; echo' to the first UEFI related command of the problematic
> >>>>>> tests.
> >>>>>
> >>>>> It looks to be a workaround.
> >>>>> We'd better have another approach to fix the problem.
> >>>>> Otherwise, similar issues will occur again.
> >>>>
> >>>> I would not like to change the logic in Python to detect the U-Boot
> >>>> prompt for something UEFI specific. And we need a method to determine
> >>>> the size of a serial console.
> >>>>
> >>>> The current approach allowed me to merge your patch series which
> >>>> otherwise might not have reached the v2020.07 release. Did the problem
> >>>> not show up in your Travis CI testing?
> >>>
> >>> No. If your saying is correct, this can happen only if efi_console_register()
> >>> is moved after efi_disk_register(). Right?
> >>>
> >>>> If you have a better solution, we can easily merge your patch.
> >>>
> >>> First, I want to understand what's happening.
> >>>
> >>> -Takahiro Akashi
> >>>
> >>>> Best regards
> >>>>
> >>>> Heinrich
> >>>>
> >>>>>
> >>>>> Thanks,
> >>>>> -Takahiro Akashi
> >>>>>
> >>>>>> Signed-off-by: Heinrich Schuchardt <xypron.glpk at gmx.de>
> >>>>>> ---
> >>>>>> test/py/tests/test_efi_secboot/test_authvar.py | 8 ++++----
> >>>>>> test/py/tests/test_efi_secboot/test_signed.py | 4 ++--
> >>>>>> test/py/tests/test_efi_secboot/test_unsigned.py | 6 +++---
> >>>>>> 3 files changed, 9 insertions(+), 9 deletions(-)
> >>>>>>
> >>>>>> diff --git a/test/py/tests/test_efi_secboot/test_authvar.py b/test/py/tests/test_efi_secboot/test_authvar.py
> >>>>>> index 55dcaa95f1..9912694a3e 100644
> >>>>>> --- a/test/py/tests/test_efi_secboot/test_authvar.py
> >>>>>> +++ b/test/py/tests/test_efi_secboot/test_authvar.py
> >>>>>> @@ -133,7 +133,7 @@ class TestEfiAuthVar(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 db.auth',
> >>>>>> @@ -174,7 +174,7 @@ class TestEfiAuthVar(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 db.auth',
> >>>>>> @@ -215,7 +215,7 @@ class TestEfiAuthVar(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 db.auth',
> >>>>>> @@ -249,7 +249,7 @@ class TestEfiAuthVar(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 db.auth',
> >>>>>> diff --git a/test/py/tests/test_efi_secboot/test_signed.py b/test/py/tests/test_efi_secboot/test_signed.py
> >>>>>> index 584282b338..fc722ab506 100644
> >>>>>> --- a/test/py/tests/test_efi_secboot/test_signed.py
> >>>>>> +++ b/test/py/tests/test_efi_secboot/test_signed.py
> >>>>>> @@ -29,7 +29,7 @@ class TestEfiSignedImage(object):
> >>>>>> # Test Case 1a, run signed image if no db/dbx
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> - 'efidebug boot add 1 HELLO1 host 0:1 /helloworld.efi.signed ""',
> >>>>>> + 'efidebug boot add 1 HELLO1 host 0:1 /helloworld.efi.signed ""; echo',
> >>>>>> 'efidebug boot next 1',
> >>>>>> 'bootefi bootmgr'])
> >>>>>> assert(re.search('Hello, world!', ''.join(output)))
> >>>>>> @@ -81,7 +81,7 @@ class TestEfiSignedImage(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 db.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize dbx',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize dbx; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> diff --git a/test/py/tests/test_efi_secboot/test_unsigned.py b/test/py/tests/test_efi_secboot/test_unsigned.py
> >>>>>> index 22d849afb8..a4af845c51 100644
> >>>>>> --- a/test/py/tests/test_efi_secboot/test_unsigned.py
> >>>>>> +++ b/test/py/tests/test_efi_secboot/test_unsigned.py
> >>>>>> @@ -30,7 +30,7 @@ class TestEfiUnsignedImage(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK; echo',
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize PK'])
> >>>>>> assert(not re.search('Failed to set EFI variable', ''.join(output)))
> >>>>>> @@ -58,7 +58,7 @@ class TestEfiUnsignedImage(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 db_hello.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize db',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize db; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> @@ -82,7 +82,7 @@ class TestEfiUnsignedImage(object):
> >>>>>> output = u_boot_console.run_command_list([
> >>>>>> 'host bind 0 %s' % disk_img,
> >>>>>> 'fatload host 0:1 4000000 db_hello.auth',
> >>>>>> - 'setenv -e -nv -bs -rt -at -i 4000000,$filesize dbx',
> >>>>>> + 'setenv -e -nv -bs -rt -at -i 4000000,$filesize dbx; echo',
> >>>>>> 'fatload host 0:1 4000000 KEK.auth',
> >>>>>> 'setenv -e -nv -bs -rt -at -i 4000000,$filesize KEK',
> >>>>>> 'fatload host 0:1 4000000 PK.auth',
> >>>>>> --
> >>>>>> 2.26.2
> >>>>>>
> >>>>
>
More information about the U-Boot
mailing list