[Buildroot] Issue with capture of emulator output in runtime test infra

[Buildroot] Issue with capture of emulator output in runtime test infra

[Thomas Petazzoni]

Hello,

I've been working on some additional test cases in support/testing/,
and stumbled across an issue in the infrastructure, which I thought I
should report before forgetting about it.

The run() method of the Emulator() class captures the output of the
command executed inside the emulated system:

    def run(self, cmd, timeout=-1):
        self.qemu.sendline(cmd)
        if timeout != -1:
            timeout *= self.timeout_multiplier
        self.qemu.expect("# ", timeout=timeout)
        # Remove double carriage return from qemu stdout so str.splitlines()
        # works as expected.
        output = self.qemu.before.replace("\r\r", "\r").splitlines()[1:]

        self.qemu.sendline("echo $?")
        self.qemu.expect("# ")
        exit_code = self.qemu.before.splitlines()[2]
        exit_code = int(exit_code)

As can be seen from the [1:], we remove the first line, because it
contains the command that was executed.

The problem is that when the command is long, for some reason due to
how the emulation works, it gets wrapped on two lines, like this:

# curl -s -o /dev/null -w "%{http_code}\n" -X POST -H "Content-Type: application
/json" -d '{"email": "test", "name": "test"}' http://127.0.0.1:5000
200

(The wrapping above does not come from my e-mail client, it is really
wrapped after "application" and before "/json" in the output).

Due to this, our Emulator.run() logic strips out the "# curl ..." line,
but the output array looks like this:

output[0] = /json" -d '{"email": "test", "name": "test"}' http://127.0.0.1:5000
output[1] = 200

While we would have expected output[] to contain just a single element,
"200", which is really the only output of the command. For now, I've
worked around this by looking at output[-1] in my test case, which is
good enough because I only care about one line of output.

However, I'm not really sure how to fix this in the Emulator.run() core
itself. Perhaps we should not be using the -serial stdio (which
requires interacting on stdin/stdout), but instead use a separate
telnet port (but then there's always the issue of which port to use) ?

Best regards,

Thomas
-- 
Thomas Petazzoni, co-owner and CEO, Bootlin
Embedded Linux and Kernel engineering and training
https://bootlin.com
_______________________________________________
buildroot mailing list
buildroot@lists.buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Edgar Bonet]

Hello!

Thomas Petazzoni wrote about support/testing/infra/emulator.py:
> the command [...] gets wrapped on two lines, like this:
>
> # curl -s -o /dev/null -w "%{http_code}\n" -X POST -H "Content-Type: application
> /json" -d '{"email": "test", "name": "test"}' http://127.0.0.1:5000

Is it just a coincidence that the line got wrapped at exactly
80 columns, or is it always at this width? 80 columns is the width of a
traditional IBM punched card, a VT100 terminal, and likely the default
for a pseudo-terminal. Does the behavior change if the width of the
pseudo-terminal ("dimensions" attribute of spawn()) is changed?

Regards,

Edgar.
_______________________________________________
buildroot mailing list
buildroot@lists.buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Edgar Bonet]

Hello!

Yesterday I wrote:
> Is it just a coincidence that the line got wrapped at exactly 80
> columns [...]

I think I found where the spurious line break comes from. Busybox's
lineedit library has a trick to work around the VT100's automargin
feature.[1] When a character is printed on the last column of the
terminal, lineedit adds a carriage return in order to force the cursor
to the next line:

		/* we go to the next line */
#if HACK_FOR_WRONG_WIDTH
		/* This works better if our idea of term width is wrong
		 * and it is actually wider (often happens on serial lines).
		 * Printing CR,LF *forces* cursor to next line.
		 * OTOH if terminal width is correct AND terminal does NOT
		 * have automargin (IOW: it is moving cursor to next line
		 * by itself (which is wrong for VT-10x terminals)),
		 * this will break things: there will be one extra empty line */
		puts("\r"); /* + implicit '\n' */

There doesn't seem to be a way to override this behavior, but we could
make busybox believe our terminal is ultra wide. Busybox gets its idea
of the terminal width from the kernel, via the TIOCGWINSZ ioctl[2]. The
kernel within the emulator may not be able to know the host's terminal
width, in which case setting the dimensions attribute in pexpect.spawn()
may not have any effect. We can, however, override the terminal width
using the "COLUMNS" environment variable[3], but beware that values
larger than 29999 are ignored.

Regards,

Edgar.

[1] https://git.busybox.net/busybox/tree/libbb/lineedit.c?h=1_33_1#n402
[2] https://git.busybox.net/busybox/tree/libbb/xfuncs.c?h=1_33_1#n263
[3] https://git.busybox.net/busybox/tree/libbb/xfuncs.c?h=1_33_1#n235
_______________________________________________
buildroot mailing list
buildroot@lists.buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Peter Korsgaard]

>>>>> "Thomas" == Thomas Petazzoni <thomas.petazzoni@bootlin.com> writes:

 > Hello,
 > I've been working on some additional test cases in support/testing/,
 > and stumbled across an issue in the infrastructure, which I thought I
 > should report before forgetting about it.

..

 > While we would have expected output[] to contain just a single element,
 > "200", which is really the only output of the command. For now, I've
 > worked around this by looking at output[-1] in my test case, which is
 > good enough because I only care about one line of output.

 > However, I'm not really sure how to fix this in the Emulator.run() core
 > itself. Perhaps we should not be using the -serial stdio (which
 > requires interacting on stdin/stdout), but instead use a separate
 > telnet port (but then there's always the issue of which port to use) ?

Just a hack, but how about we add a marker after each shell command (#
MARKER) and just strip everything util after the marker?

-- 
Bye, Peter Korsgaard
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Peter Korsgaard]

>>>>> "Edgar" == Edgar Bonet <bonet@grenoble.cnrs.fr> writes:

 > Hello!
 > Yesterday I wrote:
 >> Is it just a coincidence that the line got wrapped at exactly 80
 >> columns [...]

 > I think I found where the spurious line break comes from. Busybox's
 > lineedit library has a trick to work around the VT100's automargin
 > feature.[1] When a character is printed on the last column of the
 > terminal, lineedit adds a carriage return in order to force the cursor
 > to the next line:

 > 		/* we go to the next line */
 > #if HACK_FOR_WRONG_WIDTH
 > 		/* This works better if our idea of term width is wrong
 > 		 * and it is actually wider (often happens on serial lines).
 > 		 * Printing CR,LF *forces* cursor to next line.
 > 		 * OTOH if terminal width is correct AND terminal does NOT
 > 		 * have automargin (IOW: it is moving cursor to next line
 > 		 * by itself (which is wrong for VT-10x terminals)),
 > 		 * this will break things: there will be one extra empty line */
 > 		puts("\r"); /* + implicit '\n' */

 > There doesn't seem to be a way to override this behavior, but we could
 > make busybox believe our terminal is ultra wide. Busybox gets its idea
 > of the terminal width from the kernel, via the TIOCGWINSZ ioctl[2]. The
 > kernel within the emulator may not be able to know the host's terminal
 > width, in which case setting the dimensions attribute in pexpect.spawn()
 > may not have any effect. We can, however, override the terminal width
 > using the "COLUMNS" environment variable[3], but beware that values
 > larger than 29999 are ignored.

29999 chars should be enough for anybody (tm) ;)

Care to send a patch for this?

-- 
Bye, Peter Korsgaard
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Thomas Petazzoni]

On Mon, 04 Oct 2021 13:52:06 +0200
Peter Korsgaard <peter@korsgaard.com> wrote:

>  > While we would have expected output[] to contain just a single element,
>  > "200", which is really the only output of the command. For now, I've
>  > worked around this by looking at output[-1] in my test case, which is
>  > good enough because I only care about one line of output.  
> 
>  > However, I'm not really sure how to fix this in the Emulator.run() core
>  > itself. Perhaps we should not be using the -serial stdio (which
>  > requires interacting on stdin/stdout), but instead use a separate
>  > telnet port (but then there's always the issue of which port to use) ?  
> 
> Just a hack, but how about we add a marker after each shell command (#
> MARKER) and just strip everything util after the marker?

Hm, why not. Indeed a hack, though :-/

The problem with the telnet mechanism is that you need to specify a TCP
port that is available. Tricky, especially if you run multiple test
cases in parallel.

Best regards,

Thomas
-- 
Thomas Petazzoni, co-owner and CEO, Bootlin
Embedded Linux and Kernel engineering and training
https://bootlin.com
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Edgar Bonet]

Hello!

As I suggested that the wrapping could be prevented by setting the
"COLUMNS" environment variable to a large value (but no larger than
29999), Peter Korsgaard wrote:

> 29999 chars should be enough for anybody (tm) ;)
>
> Care to send a patch for this?

I would be happy to do so. However, as I am not familiar with this whole
testing infrastructure, the patch would need to be tested by someone
else.

Right now I am trying to check my hypothesis that setting COLUMNS=29999
is enough to make ash (Busybox's shell) behave properly. And I found a
little surprise: the command

    export COLUMNS=29999

does _not_ add the COLUMNS variable to the shell's environment. The
variable is added to the environment of the processes started by the
shell, but it is not in the environment of the shell itself. It doesn't
prevent the shell from wrapping the commands at 80 columns.

Right now the fix I have in mind is to run

    COLUMNS=29999 exec sh

after logging in, at the end of the login() method. I just checked that
reloading ash in this way does put the variable in the shell's
environment, and does fix this wrapping behavior. At least on the copy
of Busybox I compiled on my Ubuntu, I still have to test it on a
Buildroot environment.

Does this sound like an appropriate fix?

Regards,

Edgar.
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Yann E. MORIN]

Edgar, All,

On 2021-10-04 22:46 +0200, Edgar Bonet spake thusly:
> As I suggested that the wrapping could be prevented by setting the
> "COLUMNS" environment variable to a large value (but no larger than
> 29999), Peter Korsgaard wrote:
> 
> > 29999 chars should be enough for anybody (tm) ;)
> >
> > Care to send a patch for this?
> 
> I would be happy to do so. However, as I am not familiar with this whole
> testing infrastructure, the patch would need to be tested by someone
> else.
> 
> Right now I am trying to check my hypothesis that setting COLUMNS=29999
> is enough to make ash (Busybox's shell) behave properly. And I found a
> little surprise: the command
> 
>     export COLUMNS=29999
> 
> does _not_ add the COLUMNS variable to the shell's environment. The
> variable is added to the environment of the processes started by the
> shell, but it is not in the environment of the shell itself. It doesn't
> prevent the shell from wrapping the commands at 80 columns.
> 
> Right now the fix I have in mind is to run
> 
>     COLUMNS=29999 exec sh

What about actually telling the shell the size we want::

    # stty columns 29999

Regards,
Yann E. MORIN.

> after logging in, at the end of the login() method. I just checked that
> reloading ash in this way does put the variable in the shell's
> environment, and does fix this wrapping behavior. At least on the copy
> of Busybox I compiled on my Ubuntu, I still have to test it on a
> Buildroot environment.
> 
> Does this sound like an appropriate fix?
> 
> Regards,
> 
> Edgar.
> _______________________________________________
> buildroot mailing list
> buildroot@buildroot.org
> https://lists.buildroot.org/mailman/listinfo/buildroot

-- 
.-----------------.--------------------.------------------.--------------------.
|  Yann E. MORIN  | Real-Time Embedded | /"\ ASCII RIBBON | Erics' conspiracy: |
| +33 662 376 056 | Software  Designer | \ / CAMPAIGN     |  ___               |
| +33 561 099 427 `------------.-------:  X  AGAINST      |  \e/  There is no  |
| http://ymorin.is-a-geek.org/ | _/*\_ | / \ HTML MAIL    |   v   conspiracy.  |
'------------------------------^-------^------------------^--------------------'
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Edgar Bonet]

Hi!

In response to my suggestion of issuing

    COLUMNS=29999 exec sh

to avoid the command line wrapping, Yann E. MORIN wrote:
> What about actually telling the shell the size we want::
>
>     # stty columns 29999

Good idea: it seems indeed cleaner than starting a new shell. This is
actually telling the kernel's tty driver about the terminal width. The
shell then gets this info from the kernel, via the TIOCGWINSZ ioctl, and
it uses this width unless it is overridden by $COLUMNS.

I just tested on an actual board running Buildroot 2021.08, and it does
indeed prevent the shell from wrapping the lines.

I will send a pull request. May I add your name as Co-authored-by?

Regards,

Edgar.
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot

Re: [Buildroot] Issue with capture of emulator output in runtime test infra

[Yann E. MORIN]

Edgar, All,

On 2021-10-05 10:54 +0200, Edgar Bonet spake thusly:
> to avoid the command line wrapping, Yann E. MORIN wrote:
> > What about actually telling the shell the size we want::
> >     # stty columns 29999
> 
> Good idea: it seems indeed cleaner than starting a new shell. This is
> actually telling the kernel's tty driver about the terminal width. The
> shell then gets this info from the kernel, via the TIOCGWINSZ ioctl, and
> it uses this width unless it is overridden by $COLUMNS.
> 
> I just tested on an actual board running Buildroot 2021.08, and it does
> indeed prevent the shell from wrapping the lines.
> 
> I will send a pull request. May I add your name as Co-authored-by?

As you want, I'm fine either way.

Regards,
Yann E. MORIN.

-- 
.-----------------.--------------------.------------------.--------------------.
|  Yann E. MORIN  | Real-Time Embedded | /"\ ASCII RIBBON | Erics' conspiracy: |
| +33 662 376 056 | Software  Designer | \ / CAMPAIGN     |  ___               |
| +33 561 099 427 `------------.-------:  X  AGAINST      |  \e/  There is no  |
| http://ymorin.is-a-geek.org/ | _/*\_ | / \ HTML MAIL    |   v   conspiracy.  |
'------------------------------^-------^------------------^--------------------'
_______________________________________________
buildroot mailing list
buildroot@buildroot.org
https://lists.buildroot.org/mailman/listinfo/buildroot