Skip to contentSkip to conversation

Issue with capture of emulator output in runtime test infra

Buildroot Thomas Petazzoni 4 participants 10 messages Sep 19, 2021 – Oct 5, 2021

lore
Share & tools
lore
#0 lore raw

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

Signature · 7 lines
Thomas Petazzoni, co-owner and CEO, Bootlin
Embedded Linux and Kernel engineering and training
https://bootlin.com
_______________________________________________
buildroot mailing list
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot
#1 lore raw

Hello!

Thomas Petazzoni wrote about support/testing/infra/emulator.py:

Quoted 4 lines

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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot

#2 lore raw

Hello!

Quoted 2 lines · Yesterday I

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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot

#3 lore raw
Quoted 24 lines
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line

"Edgar" == Edgar Bonet <[email protected]> writes:

Hello!

Quoted 2 lines · Yesterday I

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' */

Quoted 8 lines

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?

Signature · 5 lines
Bye, Peter Korsgaard
_______________________________________________
buildroot mailing list
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot
#4 lore raw

Hello!

As I suggested that the wrapping could be prevented by setting the "COLUMNS" environment variable to a large value (but no larger than

Quoted 3 lines · Peter Korsgaard

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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot

#5 lore raw

Edgar, All,

On 2021-10-04 22:46 +0200, Edgar Bonet spake thusly:

Quoted 18 lines

As I suggested that the wrapping could be prevented by setting the "COLUMNS" environment variable to a large value (but no larger than

Quoted 3 lines · Peter Korsgaard

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
Quoted 8 lines

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.

Quoted 15 lines

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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot

Signature · 10 lines
.-----------------.--------------------.------------------.--------------------.
|  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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot
#6 lore raw

Hi!

In response to my suggestion of issuing

    COLUMNS=29999 exec sh
Quoted 3 lines · Yann E. MORIN

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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot

#7 lore raw

Edgar, All,

On 2021-10-05 10:54 +0200, Edgar Bonet spake thusly:

Quoted 9 lines
Quoted 2 lines · Yann E. MORIN

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.

Quoted 4 lines

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.

Signature · 10 lines
.-----------------.--------------------.------------------.--------------------.
|  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
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot
#8 lore raw
In reply to Thomas Petazzoni
Quoted 6 lines
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line

"Thomas" == Thomas Petazzoni <[email protected]> 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.

..

Quoted 9 lines

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?

Signature · 5 lines
Bye, Peter Korsgaard
_______________________________________________
buildroot mailing list
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot
#9 lore raw
Quoted 5 lines · On Mon, 04 Oct 2021 13:52:06 +0200 Peter Korsgaard <[email protected]> wrote:
Quoted 4 lines

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.

Quoted 7 lines
Quoted 4 lines

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

Signature · 7 lines
Thomas Petazzoni, co-owner and CEO, Bootlin
Embedded Linux and Kernel engineering and training
https://bootlin.com
_______________________________________________
buildroot mailing list
[email protected]
https://lists.buildroot.org/mailman/listinfo/buildroot