Flush buffered standard steams

[ivankravets]

Hi,

Firstly, a big THANK YOU for the amazing project! Glad to see that @platformio users found it useful.

See initial platformio/platformio-core#3965 posted by @adbancroft.

There is a problem with data buffering on the SimAVR/Windows side. Possible solutions:

• https://stackoverflow.com/questions/12450066/flushing-buffers-in-c
• https://stackoverflow.com/questions/7876660/how-to-turn-off-buffering-of-stdout-in-c

Please note that it works great on Unix.

How to reproduce?

I've just created a simple Python script and tried to redirect standard streams to the PIPE. Subsequent reading of 1 byte hangs Python script. See code

simavr.py

import sys
import subprocess


if __name__ == "__main__":
    with subprocess.Popen(
        sys.argv[1:],
        stdout=subprocess.PIPE,
        stderr=subprocess.PIPE,
        bufsize=0,
    ) as proc:
        print("reading...")
        proc.stdout.read(1)
        print("reading is done.")

Call SimAVR using Python bridge/script:

python simavr.py bin/simavr -m atmega328p -f 16000000L firmware.elf

[gatk555]

You could suggest to your user to try stdbuf. It is apparently included for Windows in msys2. It should work if the program was built with MINGW, but not if MS build tools were used.

Please note that it works great on Unix.
Only because of a bug (PR #490). But stdbuf works after that is applied.

[ivankravets]

Thanks for the quick response. Could you share somewhere simavr built with msys2? We will publish it to the registry. Thanks!

[gatk555]

My understanding is that Msys2 is just MINGW with pre-built GNU utilities. So you may already have it. As far as I can see, there is no simavr documentation on building for Windows, but I got the impression that MINGW is the easy, perhaps the only, way. I have not tried myself.

[ivankravets]

@adbancroft, could you try this instruction https://github.com/buserror/simavr/blob/master/README.mingw ? Does this work for you?

[gatk555]

I had forgotten those build instructions, as they are in a separate file. But I suggest looking at the fork by maxgerhardt or merging PR #460 as the MINGW instructions are much newer.

[ivankravets]

@gatk555 could you merge PR #460? The @maxgerhardt is from PlatformIO Community.

@maxgerhardt , could you help us with the new binaries for SimAVR? We can remove the warning from https://docs.platformio.org/en/latest/advanced/unit-testing/simulators/simavr.html

Thanks in advance!

[maxgerhardt]

I can rebase my branch (which just fixes building) against the latest version of this repo and then build + test Windows x86 + x64 binaries, sure.

[gatk555]

The only place I could merge that would be in my own fork, but the target file (README.md) is completely different there. It could be used to update README.mingw. I think that would be a better target for the change and that may be the reason it has not yet been merged here. But MP usually comments with a reason for turning down a PR.

[maxgerhardt]

I rebuilt the PlatformIO tool-simavr package for Win x64 with the latest branch plus my build fixes plus gatk555's logging fixes and execution on the commandline looks good. A simple Arduino firmware that prints 10 times per seconds executes nicely with it and with correct timing (when invoked via the commandline). I also see that the firmware output now goes to stdout instead of stderr. (Redirecting stderr to nul only shows firmware output and no simavr messages, which are now on stderr)

simavr.exe -m atmega328p .pio\build\uno\firmware.elf 2> nul
Iteration: 0..
Iteration: 1..

However, when PlatformIO calls into the binary (and simavr opens the GDB server), then

1. Timing seems to be at least 10-40 times slower (delay(100); takes about 4 seconds, delay(1000); almost a minute instead of a second)
2. The firmware's serial output does not appear in the "Debug Console" in VSCode

And in general, simavr seems to postfix firmware output with ".." at the end, which mis-represents the true firmware output

See https://github.com/maxgerhardt/pio-simavr-testing for reproduction. Any ideas here? :/

[lcgamboa]

1. Timing seems to be at least 10-40 times slower (`delay(100);` takes about 4 seconds, `delay(1000);` 
     almost a minute instead of a second)

I solved this problem in PICSimLab using a modified avr_callback_run_gdb, I believe it can be applied as PR in simavr, what's your opinion @gatk555 ?

[edgar-bonet]

@maxgerhardt wrote:

simavr seems to postfix firmware output with ".." at the end

This is meant to represent the "\r\n" line termination appended by Serial.println(). Simavr replaces non-printing characters by '.' in the firmware output:

p->stdio_out[p->stdio_len++] = v < ' ' ? '.' : v;

[gatk555]

A PR to fix the "real-time" behaviour with gdb sounds like a good idea to me. You may run into a conflict with merged PR #482. I did not worry about timing behaviour there, except to fix buzzing, as it seemed to be already broken.

It also looks a good idea to remove those trailing dots. I think there are two places where they can occur, for UART and "console" output.

[maxgerhardt]

I think simavr is more usefull if it outputs the firmware's intended output 1:1. Then you can even do things like having a firmware produce some binary output and pipe the simavr (= firmware output) into another program for processing or logging etc.

I'll try and patch that in plus try and copy/paste the modified avr_callback_run_gdb.

Ah and, I've started setting up Msys2 MinGW64 + MinGW32 github action builds in https://github.com/maxgerhardt/simavr/actions/runs/2303871484, it already produces binaries.

Edit: Linux x64 and x86 builds were also added in https://github.com/maxgerhardt/simavr/actions/runs/2310166991

[gatk555]

I think the conversion to dots is very useful when running interactively and the firmware is misbehaving. That is a common case, so "raw mode" should be a configurable option. If it also made stdout unbuffered it would fix the original issue here.

Windows binaries ought to be popular, but how will you advertise their availability? A PR to the README would be best, but slow. A Wiki entry perhaps.

[maxgerhardt]

Best case, the CI build things get merged back and thus every commit will have downloadable artefacts for every major OS and architecture, plus the simavr release page will have the downloadable artefacts as well (see e.g. here). Advertising my fork doesn't make sense, it has to go back into mainline.

That is a common case, so "raw mode" should be a configurable option.

I agree. Though I still think for a common text-things such as \r and \n it's weird to do this transformation. But best to keep backwards compatibility.

[gatk555]

The last round of merges was a month ago, with the one before 8 months previous. So I think it would make sense to advertise the fork until the auto-build configuration is merged.

[buserror]

If anyone want to make a PR for a RAW mode, more than welcome. Either as a function call, an IOCTL, or even an environment variable. The 'ascii filter' was made at at time my test program /was/ outputting binary strings over the UART, so it made perfect sense then.

[maxgerhardt]

I made a crude addition of a -r / --raw switch to simavr in commit maxgerhardt@5616a10, I now get the firmware output in its perfect raw form.

I tried to backport @lcgamboa fixes for execution speed in GDB server mode in maxgerhardt@e036e96, which restored nominal execution speed indeed (👍), but broke GDB's ability to pause the running code execution. Once I do continue in the GDB console, Ctrl+C does not respond anymore. This was working before the patch :(.

Old

(gdb) continue
Continuing.
^C
Program received signal SIGINT, Interrupt.
0x000000ea in micros ()

After patch

(gdb) continue
Continuing.
^C^CThe target is not responding to interrupt requests.
Stop debugging it? (y or n) y

Any ideas there? (Binaries for each patch state are in here).

[gatk555]

It seems you merged a change from a fork that has not merged PR #482 into one that has, and that has partially reverted the PR. Control-C handling was modified in the PR, so it is no surprise that it is now broken. In fact I am surprised gdb works at all.

If I understood correctly, you are trying to fix the timing of cpu_sleep() when running with gdb. I hacked-up one of simavr's test firmwares to make a program that writes to the UART every two seconds. With today's build of simavr upstream, I see no difference in timing with gdb. I am running like this:

../simavr/run_avr --gdb atmega88_timer16.axf &
avr-gdb atmega88_timer16.axf -ex 'target remote :1234'
(gdb) continue

Here is a link to the file: sleep_test.c

[maxgerhardt]

With today's build of simavr upstream, I see no difference in timing with gdb. I am running like this:

That's weird, I'm basically running it the same way you are, but with my firmware at https://github.com/maxgerhardt/pio-simavr-testing.

Can you test with for ATMega328P and the ELF file in firmware.zip? I do

simavr -m atmega328p -f 160000 firmware.elf

goes fast, and

simavr -m atmega328p -f 160000 -g firmware.elf

with avr-gdb firmware.elf -ex "target remote :1234" -ex "continue" goes really slow.

With exactly the current upstream repo I'm getting the ultra slow behavior. Print time is 10 times per second.

[maxgerhardt]

CC @ivankravets I got CI working for all previously supported operating systems in here, I plan to add pio package pack'ing too and either a revert of my fix for slowness in GDB mode or a different patch. Could you tell me whether the simavr binary is executable on your Mac machine?

[lcgamboa]

In my modification I only call the gdb_network_handler function when the simulation state is stopped and not in each iteration of the avr_callback_run_gdb function as in the original code, which is what causes the slowness problem. But I forgot to mention that I call the gdb_network_handler function every 100ms of simulation in another part of PICSimLab. I believe that using some timing mechanism it is possible to call the gdb_network_handler function to handle gdb signals directly in simavr.

[gatk555]

Yes, that one is more than 10 times slower when run with gdb. And my guess is also that making a system call for every AVR instruction is what slows it down. The Arduino library is busy-waiting so it suffers badly, but mine spent almost all of its time in cpu_sleep() and executes very few instructions. (I got 72Mb of simavr tracing output in a few seconds and there is no sleep instruction.)

[gatk555]

Calling gdb_network_handler() once every 100 instructions makes the speed reduction about 30%, which seems acceptable.
I tried to post a diff, but this site chewed it up as usual.

[ivankravets]

@maxgerhardt tested on macOS - works great!

P.S: You are the monster with this CI build config => https://github.com/maxgerhardt/simavr/blob/combined_fixes_and_ci/.github/workflows/build.yml

I even forked your repo to keep it as a gist 🙏

[ivankravets]

@maxgerhardt does it make sense to update SimAVR in the PlatformIO Regsitry by your build? We could remove this warning before PlatformIO Core 6.0 which is planned to be released this Monday.

[gatk555]

I tidied up my initial change and pushed to by fork as branch "gdb_burst". I would make a PR but the only validation is firmware.zip, which seems meagre. If anyone here has test material or wants to develop it further, that will be welcome.

[maxgerhardt]

@ivankravets I have the CI building all PlatformIO .tar.gz archives now at https://github.com/maxgerhardt/simavr/releases, but the binaries don't seem to be working well with the GDB debugger / VSCode. Stepping over code only advances PC by two bytes, step-into in my firmware throws an exception in string constructor code :/. Have to revert all C code back to mainline and test if behavior is the same + open issues.

[ivankravets]

Do you mean to not hurry with updating the SimAVR package in the registry?

[maxgerhardt]

Exactly. I'll update once I can verify that binaries are working well with PlatformIO+VSCode/GDB debugger.

[SRGDamia1]

Is this work still in progress?

[maxgerhardt]

I haven't actively worked on this since the last post, had to do other things. The issue may still persist in the current mainline.

[gatk555]

There are several useful changes that may come from this thread. Going into some detail they are:

make stdout unbuffered, preferably controlled by an option;

remove translation of non-printable firmware output to dots, again should probably be optional;

drop, rather than translate, CR/LF characters in firmware output;

improve execution speed when the gdb server is active;

CI configuration so that new binaries are built when the source code changes.

The first three could be combined in a single PR.
One addition to CI configuration may be useful: separate binaries with tracing enabled.

Mine is now PR#499, faster running with gdb.