stdio_ethos: infinite shell loop

[fjmolinas]

Description

Since #17265 usage of stdio_ethos will result in a continuously exiting shell and therefore a barrage of prompts with the shell unusable.

This issue is solved if rebooting (hardware reboot) the device, but it renders automatic tests like examples/suit_update impossible.

Steps to reproduce the issue

Flash an applicationn using stdio_ethos, e.g.: examples/suit_update, examples/gnrc_border_router.

Expected results

Shell boots up fine.

Actual results

main(): This is RIOT! (Version: 2022.07-devel-135-gba15a6-pr-17950)
RIOT SUIT update example application
Running from slot 0
Image magic_number: 0x544f4952
Image Version: 0x6261064b
Image start address: 0x00002400
Header chksum: 0xe5ca2a4e

suit_coap: started.
Starting the shell
> > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > 

Versions

Operating System Environment
----------------------------
         Operating System: "Ubuntu" "20.04.1 LTS (Focal Fossa)"
                   Kernel: Linux 5.13.0-1017-oem x86_64 x86_64
             System shell: /usr/bin/dash (probably dash)
             make's shell: /usr/bin/dash (probably dash)

Installed compiler toolchains
-----------------------------
               native gcc: gcc (Ubuntu 11.2.0-7ubuntu2) 11.2.0
        arm-none-eabi-gcc: arm-none-eabi-gcc (GNU Arm Embedded Toolchain 10-2020-q4-major) 10.2.1 20201103 (release)
                  avr-gcc: avr-gcc (GCC) 5.4.0
         mips-mti-elf-gcc: missing
           msp430-elf-gcc: missing
       riscv-none-elf-gcc: missing
  riscv64-unknown-elf-gcc: missing
     riscv-none-embed-gcc: missing
     xtensa-esp32-elf-gcc: missing
   xtensa-esp8266-elf-gcc: missing
                    clang: Ubuntu clang version 13.0.0-2

Installed compiler libs
-----------------------
     arm-none-eabi-newlib: "3.3.0"
      mips-mti-elf-newlib: missing
        msp430-elf-newlib: missing
    riscv-none-elf-newlib: missing
riscv64-unknown-elf-newlib: missing
  riscv-none-embed-newlib: missing
  xtensa-esp32-elf-newlib: missing
xtensa-esp8266-elf-newlib: missing
                 avr-libc: "2.0.0" ("20150208")

Installed development tools
---------------------------
                   ccache: ccache version 4.2.1
                    cmake: cmake version 3.18.4
                 cppcheck: Cppcheck 2.3
                  doxygen: 1.9.1
                      git: git version 2.32.0
                     make: GNU Make 4.3
                  openocd: Open On-Chip Debugger 0.11.0+dev-00282-gae6de2f93-dirty (2021-11-19-15:06)
                   python: Python 3.9.7
                  python2: Python 2.7.18
                  python3: Python 3.9.7
                   flake8: 4.0.1 (mccabe: 0.6.1, pycodestyle: 2.8.0, pyflakes: 2.4.0) CPython 3.9.7 on
               coccinelle: spatch version 1.1.1-00068-g49826315 compiled with OCaml version 4.08.1

[miri64]

Brainstorming for solutions: I am somewhat wondering how #17265 could have caused this... the shell and its prompt is controlled by the shell module, so there is at least some layers of abstraction between the bug and the cause: stdio but also the stdio handler of ethos. So why is this happening?

[miri64]

Flash an application using stdio_ethos, e.g.: examples/suit_update, examples/gnrc_border_router.

This does not seem to be the case in general. The changes in #17265 worked fine on the IoT-LAB M3 (and at least @chrysn and @benpicco do not seem to encounter this issue either). Which boards were you using for that.

[fjmolinas]

Flash an application using stdio_ethos, e.g.: examples/suit_update, examples/gnrc_border_router.

This does not seem to be the case in general. The changes in #17265 worked fine on the IoT-LAB M3 (and at least @chrysn and @benpicco do not seem to encounter this issue either). Which boards were you using for that.

nrf52840-mdk, dwm1001 the ones I have with me right now...

I also saw it on iotlab-m3 a couple of times but quite rate, I don't think I saw it on samr21-xpro...

[miri64]

As I am unable to reliably reproduce this on boards I have at hand at the moment (or rather not at all), I think some remote debugging is required... From the output you provided, it looks to me that the shell is running into this condition:

RIOT/sys/shell/shell.c

Lines 490 to 491 in 37db22e

	case EOF:
	return;

This is caused by either EOT or EOF sent by stdin

RIOT/sys/shell/shell.c

Lines 430 to 434 in 37db22e

	case EOT:
	/* Ctrl-D terminates the current shell instance. */
	/* fall-thru */
	case EOF:
	return EOF;

So if this bug is indeed stdio_ethos related, those characters (\x04 and \xff) should show up after this function call:

RIOT/drivers/ethos/stdio.c

Line 70 in 37db22e

tmp = ethos_unstuff_readbyte(ptr, byte, &escaped, &frametype);

Could you maybe add a check like this:

if ((tmp > 0) && ((*ptr == 0xff) || (*ptr == 0x04))) {
    /* do something (e.g. toggle LED) */
}

Then at least we would see if the issue is from here.

[miri64]

Can reproduce with feather-nrf52840dk! Will try to debug.

[jia200x]

I have been running into this problem lately relative often. If this helps, I've seen it happening under this conditions:

• Rebooting the device while ethos is running
• It seems to be triggered when nodes are printing to stdout and transmitting frames through netdev_tap

In my use case I have an nrf52850dk gateway running ethos and a DSME interface. I forward all DSME traffic through ethos but at the same time I print some MAC metrics when scheduling/transmitting a frame. In order to avoid the issue, I need to set some timers between commands.

I might be wrong, but I think I've seen these kind of issues even before #17265, but since most of the times ethos run on a samr21-xpro (or equivalent), we probably didn't catch it before.

[miri64]

In my use case I have an nrf52850dk gateway running ethos and a DSME interface. I forward all DSME traffic through ethos but at the same time I print some MAC metrics when scheduling/transmitting a frame. In order to avoid the issue, I need to set some timers between commands.

For me, just hitting the on-board reset button also just stops it from happening.

Digging a bit through the code, it seems _read_r in sys/newlib_syscalls_default/syscalls.c only seems to be called once. After that, getchar just always returns EOF.

[miri64]

Was able to debug getchar down to

Thread 2 hit Breakpoint 2, __srget_r (ptr=ptr@entry=0x20000274 <impure_data>, fp=fp@entry=0x20005b74) at ../../../../../../../../newlib-4.2.0.20211231/newlib/libc/stdio/rget.c:40
40	../../../../../../../../newlib-4.2.0.20211231/newlib/libc/stdio/rget.c: No such file or directory.
Recursive internal problem.
make: *** [/home/mlenders/Repositories/RIOT-OS/RIOT/examples/gnrc_border_router/../../Makefile.include:884: debug] Terminated
Terminated

😕

[miri64]

Now I suddenly can't reproduce anymore 😲

[miri64]

Now I suddenly can't reproduce anymore astonished

back in business... appearently make flash term seems to cause it, while "make flash; sleep 1; make term" seems to work (sometimes).

[jia200x]

back in business... appearently make flash term seems to cause it, while "make flash; sleep 1; make term" seems to work (sometimes).

Same here! I usually trigger a make reset before make term in the experiment scripts to avoid that.

[miri64]

But this seems to be more of a newlib+stdio problem than a ethos_stdio issue. I suspect (but could not show yet) that the FILE objects for the re-entrants are somewhat broken, whenever newlib calls CHECK_INIT() nope ... that's not it