Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pyterm: use clean output by default #12094

Closed
wants to merge 7 commits into from

Conversation

cladmi
Copy link
Contributor

@cladmi cladmi commented Aug 27, 2019

Contribution description

Do not prepend the output with the timestamp and the loglevel (always
INFO) by default.
This gives a different behavior with the other RIOT_TERMINAL. Also, CI
uses picocom by default so does not have timestamp which can make a
test fail locally when it works in CI. Or work in native and fail on a
board as native does not have this decoration.

Also it will help with test when you need to get the output of the node
and not from your terminal program.

The previous behavior can be achieved by using the environment variable

PYTERMFLAGS='--format "%(asctime)s - %(levelname)s # %(message)s"

So for example

PYTERMFLAGS='-f "%(asctime)s - %(levelname)s # %(message)s"' \
    RIOT_TERMINAL=pyterm BOARD=samr21-xpro make -C tests/shell/ flash term

Implementation details

I first introduce PYTERMFLAGS to allow having pyterm specific options.
I then use it for boards that have pyterm specific options.

I then disabled using the timestamp in the output by default. It can be restored by configuring PYTERMFLAGS from the environment.

I then added a test that indeed the output is now clean.

Fix the issue that the shell was requiring to use RIOT_TERMINAL ?= socat that was incompatible with some boards. pyterm does not handle sending ctrl+c, so it cannot be replaced.

Testing procedure

Run BOARD=your_board make -C tests/test_tools/ flash test with different RIOT_TERMINAL, currently supported (not on all boards) pyterm, socat, picocom. If possible one with term_rtt. But as it is internally using pyterm it will benefit from the changes automatically.

RIOT_TERMINAL=pyterm samr21-xpro
RIOT_TERMINAL=pyterm  BOARD=samr21-xpro RIOT_CI_BUILD=1 make --no-print-directory -C tests/test_tools/ flash test
Building application "tests_test_tools" for "samr21-xpro" with MCU "samd21".

   text    data     bss     dec     hex filename
   9848     504    2612   12964    32a4 /home/harter/work/git/RIOT/tests/test_tools/bin/samr21-xpro/tests_test_tools.elf
/home/harter/work/git/RIOT/dist/tools/edbg/edbg  -t atmel_cm0p -b -v -p -f /home/harter/work/git/RIOT/tests/test_tools/bin/samr21-xpro/tests_test_tools.bin
Debugger: ATMEL EDBG CMSIS-DAP ATML2127031800004678 01.1A.00FB (S)
Clock frequency: 16.0 MHz
Target: SAM R21G18 (Rev C)
Programming............................................ done.
Verification............................................ done.
/home/harter/work/git/RIOT/dist/tools/pyterm/pyterm -p "/dev/ttyACM0" -b "115200"
Twisted not available, please install it if you want to use pyterm's JSON capabilities
Connect to serial port /dev/ttyACM0
Welcome to pyterm!
Type '/exit' to exit.
main(): This is RIOT! (Version: buildtest)
Running 'tests_tools' application
shellping
shellpong
true this should not be echoed
shellping
shellpong
toupper lowercase
LOWERCASE
RIOT_TERMINAL=picocom samr21-xpro
RIOT_TERMINAL=picocom  BOARD=samr21-xpro RIOT_CI_BUILD=1 make --no-print-directory -C tests/test_tools/ flash test
Building application "tests_test_tools" for "samr21-xpro" with MCU "samd21".

   text    data     bss     dec     hex filename
   9848     504    2612   12964    32a4 /home/harter/work/git/RIOT/tests/test_tools/bin/samr21-xpro/tests_test_tools.elf
/home/harter/work/git/RIOT/dist/tools/edbg/edbg  -t atmel_cm0p -b -v -p -f /home/harter/work/git/RIOT/tests/test_tools/bin/samr21-xpro/tests_test_tools.bin
Debugger: ATMEL EDBG CMSIS-DAP ATML2127031800004678 01.1A.00FB (S)
Clock frequency: 16.0 MHz
Target: SAM R21G18 (Rev C)
Programming............................................ done.
Verification............................................ done.
picocom --nolock --imap lfcrlf --baud "115200" "/dev/ttyACM0"
picocom v2.2

port is        : /dev/ttyACM0
flowcontrol    : none
baudrate is    : 115200
parity is      : none
databits are   : 8
stopbits are   : 1
escape is      : C-a
local echo is  : no
noinit is      : no
noreset is     : no
nolock is      : yes
send_cmd is    : sz -vv
receive_cmd is : rz -vv -E
imap is        : lfcrlf,
omap is        : 
emap is        : crcrlf,delbs,

Type [C-a] [C-h] to see available commands

Terminal ready
main(): This is RIOT! (Version: buildtest)
Running 'tests_tools' application
shellping
shellpong
true this should not be echoed
shellping
shellpong
toupper lowercase
LOWERCASE

RIOT_TERMINAL=socat samr21-xpro
RIOT_TERMINAL=socat  BOARD=samr21-xpro RIOT_CI_BUILD=1 make --no-print-directory -C tests/test_tools/ flash test
Building application "tests_test_tools" for "samr21-xpro" with MCU "samd21".

   text    data     bss     dec     hex filename
   9848     504    2612   12964    32a4 /home/harter/work/git/RIOT/tests/test_tools/bin/samr21-xpro/tests_test_tools.elf
/home/harter/work/git/RIOT/dist/tools/edbg/edbg  -t atmel_cm0p -b -v -p -f /home/harter/work/git/RIOT/tests/test_tools/bin/samr21-xpro/tests_test_tools.bin
Debugger: ATMEL EDBG CMSIS-DAP ATML2127031800004678 01.1A.00FB (S)
Clock frequency: 16.0 MHz
Target: SAM R21G18 (Rev C)
Programming............................................ done.
Verification............................................ done.
socat - open:/dev/ttyACM0,b115200,echo=0,raw
main(): This is RIOT! (Version: buildtest)
Running 'tests_tools' application
shellping
shellpong
true this should not be echoed
shellping
shellpong
toupper lowercase
LOWERCASE

native
RIOT_CI_BUILD=1 BOARD=native make --no-print-directory -C tests/test_tools/ flash test
Building application "tests_test_tools" for "native" with MCU "native".

   text    data     bss     dec     hex filename
  22892     644   47652   71188   11614 /home/harter/work/git/RIOT/tests/test_tools/bin/native/tests_test_tools.elf
true 
/home/harter/work/git/RIOT/tests/test_tools/bin/native/tests_test_tools.elf  
RIOT native interrupts/signals initialized.
LED_RED_OFF
LED_GREEN_ON
RIOT native board initialized.
RIOT native hardware initialization complete.

main(): This is RIOT! (Version: buildtest)
Running 'tests_tools' application
shellping
shellpong
true this should not be echoed
shellping
shellpong
toupper lowercase
LOWERCASE

On IoT-LAB it works too
IOTLAB_NODE=auto-ssh RIOT_CI_BUILD=1 BOARD=iotlab-m3 make --no-print-directory -C tests/test_tools/ flash test
Building application "tests_test_tools" for "iotlab-m3" with MCU "stm32f1".

   text    data     bss     dec     hex filename
   9504     504    2620   12628    3154 /home/harter/work/git/RIOT/tests/test_tools/bin/iotlab-m3/tests_test_tools.elf
iotlab-node --jmespath='keys(@)[0]' --format='int'  --list grenoble,m3,58 --update /home/harter/work/git/RIOT/tests/test_tools/bin/iotlab-m3/tests_test_tools.elf | grep 0
0
ssh -t [email protected] 'socat - tcp:m3-58.grenoble.iot-lab.info:20000'
�main(): This is RIOT! (Version: buildtest)
Running 'tests_tools' application
�main(): This is RIOT! (Version: buildtest)
Running 'tests_tools' application
shellping
shellpong
true this should not be echoed
shellping
shellpong
toupper lowercase
LOWERCASE

term works correctly with msba2

`tests/bloom_bytes` on `msba2`
BOARD=msba2 RIOT_CI_BUILD=1 make --no-print-directory -C tests/bloom_bytes/ flash >/dev/null; BOARD=msba2 RIOT_CI_BUILD=1 make --no-print-directory -C tests/bloom_bytes/  test
/home/harter/work/git/RIOT/dist/tools/pyterm/pyterm -p "/dev/ttyUSB0" -b "115200" -tg
Twisted not available, please install it if you want to use pyterm's JSON capabilities
Connect to serial port /dev/ttyUSB0
Welcome to pyterm!
Type '/exit' to exit.
main(): This is RIOT! (Version: buildtest)
Testing Bloom filter.

m: 4096 k: 8

adding 512 elements took 188ms
checking 10000 elements took 1801ms

267 elements probably in the filter.
9733 elements not in the filter.
0.026700 false positive rate.

All done!
The `term` command is still the same for `lobaro-lorabox` as in `master`
BOARD=lobaro-lorabox RIOT_CI_BUILD=1 make --no-print-directory -C tests/bloom_bytes/ info-debug-variable-TERMFLAGS
-p /dev/ttyUSB0 -b 115200 --set-rts 0

Which gives this execution

BOARD=lobaro-lorabox RIOT_CI_BUILD=1 make --no-print-directory -C tests/bloom_bytes/ term | head -n 3
/home/harter/work/git/RIOT/dist/tools/pyterm/pyterm -p "/dev/ttyUSB0" -b "115200" --set-rts 0
Twisted not available, please install it if you want to use pyterm's JSON capabilities
Connect to serial port /dev/ttyUSB0
Cannot connect to serial port /dev/ttyUSB0: could not open port /dev/ttyUSB0: [Errno 2] No such file or directory: '/dev/ttyUSB0'

Issues/PRs references

This fixes the issues with different behavior between the different test tools #9726 (comment)
This is a shortcut for #11099
This replaces [WIP] tests/test_tools: add a test for the testing tools environment #11094
Required for #10949

@cladmi
Copy link
Contributor Author

cladmi commented Aug 27, 2019

@MrKevinWeiss you may be interested by this

@cladmi
Copy link
Contributor Author

cladmi commented Aug 27, 2019

Hmm, the tests/shell does not work with pyterm as sending ctrl+c does exit the terminal. I will remove that change.

@cladmi
Copy link
Contributor Author

cladmi commented Aug 27, 2019

Funny thing, this PR could pass CI test without the pyterm changes.

@cladmi
Copy link
Contributor Author

cladmi commented Aug 27, 2019

I will split the changes that do not change the behavior.

Split the first commits in #12095

@jcarrano jcarrano added Area: tools Area: Supplementary tools State: waiting for other PR State: The PR requires another PR to be merged first Type: enhancement The issue suggests enhanceable parts / The PR enhances parts of the codebase / documentation labels Aug 27, 2019
@jcarrano jcarrano self-requested a review August 27, 2019 13:15
@@ -6,9 +6,6 @@ USEMODULE += shell
USEMODULE += shell_commands
USEMODULE += ps

# Use a terminal that does not introduce extra characters into the stream.
RIOT_TERMINAL ?= socat
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This will cause problems when testing long lines, see https:/RIOT-OS/RIOT/pull/10635/files#diff-16e3498e34b06780aaf14222a95484a5R91

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seems like a bad bug…

Currently the other issue with pyterm is that it exits when ctrl+c is sent.

@benpicco
Copy link
Contributor

I'm all in favor dropping the loglevel, but the timestamp is quite valuable to have.

@jcarrano
Copy link
Contributor

@benpicco the timestamp causes problems in test scripts with pexpect, when one needs to match a number and ends up matching the timestamp instead.

@benpicco
Copy link
Contributor

Wouldn't it be better then to change the output with an optional parameter just for the test scripts instead of changing the behavior for all users?

@cladmi
Copy link
Contributor Author

cladmi commented Aug 28, 2019

Wouldn't it be better then to change the output with an optional parameter just for the test scripts instead of changing the behavior for all users?

I did it the other way around and added support to configure it from command line.

By default, native, ethos, murdock, picocom, socat, and when using IOTLAB_NODE do not have any timestamp either. So why having a different default behavior with pyterm?

@aabadie
Copy link
Contributor

aabadie commented Aug 28, 2019

I did it the other way around and added support to configure it from command line.

So it should now be easy to remove the timestamp from the test using PYTERMFLAGS. I would do this instead of changing the behaviour just because this doesn't fit in your tests.

@cladmi
Copy link
Contributor Author

cladmi commented Aug 28, 2019

I will change the PRs to keep the current behavior and open issues that native and ethos have a different behavior that you can take care of.

Do not prepend the output with the timestamp and the loglevel (always
INFO) by default.
This gives a different behavior with the other RIOT_TERMINAL. Also, CI
uses `picocom` by default so does not have timestamp which can make a
test fail locally when it works in CI. Or work in native and fail on a
board as native does not have this decoration.

Also it will help with test when you need to get the output of the node
and not from your terminal program.

The previous behavior can be achieved by using the environment variable

    PYTERMFLAGS='--format "%(asctime)s - %(levelname)s # %(message)s"

So for example

    PYTERMFLAGS='-f "%(asctime)s - %(levelname)s # %(message)s"' \
        RIOT_TERMINAL=pyterm BOARD=samr21-xpro make -C tests/shell/ flash term
Get the output of a one line command without other garbage messages.
All supported shells do now not add output when testing.
So the test can also run with `pyterm` or `jlink.sh term_rtt` for boards
that cannot use another terminal.
This reverts commit 3da8e83.

Sending ctrl+c is not supported by pyterm.
@cladmi cladmi force-pushed the pr/pyterm/no_stupid_behavior branch from 3f6ddd3 to d9793c5 Compare August 28, 2019 15:13
It is similar to 'term' but with removing possible additional behaviors
from pyterm.

It currently only removes the logging decorators.
Use a clean terminal without added decoration on the output for testing.
@cladmi
Copy link
Contributor Author

cladmi commented Aug 28, 2019

It's easier to re-open a new one.

@cladmi
Copy link
Contributor Author

cladmi commented Aug 28, 2019

Replaced by #12094 EDIT: #12107

@cladmi
Copy link
Contributor Author

cladmi commented Aug 28, 2019

And the issue #12108

@miri64
Copy link
Member

miri64 commented Aug 28, 2019

Replaced by #12094

Huh? This is #12094 ;-).

@cladmi
Copy link
Contributor Author

cladmi commented Aug 28, 2019

Wrong link copy #12107

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area: tools Area: Supplementary tools State: waiting for other PR State: The PR requires another PR to be merged first Type: enhancement The issue suggests enhanceable parts / The PR enhances parts of the codebase / documentation
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants