Add test start delay option

[maxgerhardt]

Solution

Please add to your project a POST Extra Script with the following contents:

platformio.ini

[env:seeed_wio_terminal]
platform = atmelsam
board = seeed_wio_terminal
framework = arduino
extra_scripts = post:extra_script.py

extra_script.py

import time

Import("env")

if "test" in env.GetBuildType():
    env.AddPostAction("upload", lambda *_, **__: time.sleep(2))

P.S: Do not forget to upgrade to the latest PlatformIO Core via pio upgrade --dev.

Related issues:

• https://community.platformio.org/t/teensy-4-1-unit-testing-issue/21033/5
• TEST Embedded Arduino Micro (ClearCommError) #3956

Configuration

Operating system: Windows 10 x64

PlatformIO Version (platformio --version): 5.0.4a2

Description of problem

Reference to topic where this popped up: https://community.platformio.org/t/unit-test-wio-terminal-could-not-open-port-while-testing/17180/

A user wants to do unit testing on a WIO terminal, which has a SAMD21G18A ATSAMD51P19A microcontroller onboard. This microcontroller implements a USB CDC serial connection. When a new firmware is uploaded, or the microcontroller is being reset, the USB connection is temporarily lost, then re-established.

The problem is then when testing, PlatformIO does a Build -> Upload -> Test, where there is no delay between uploading and testing when using this specific microcontroller.

A problem was problem was observed that when using Linux, after the upload is done, the microcontroller re-enumerates twices on the USB bus, and at the moment the "Test" part of the unit tests wants to access /dev/ttyACM0, the Linux kernel or subsystems have not yet fully re-enumerated the device and it's currently owned by root at this point. Then accessing it fails with [Errno 13] could not open port /dev/ttyACM0: [Errno 13] Permission denied: '/dev/ttyACM0'. A few milliseconds after it (exact timing log is here), Linux is done processing the device and now the user properly owns /dev/ttyACM0 and access to it would go through. That's at least how I read these logs.

However, since PlatformIO does not have a configurable delay after uploading, or equivalently before testing, pio test will always run into this problem. So it would be nice to have such an option to enable these use cases where the to-be-tested MCU is the USB serial port and does some re-enumeration stuff after uploading.

Steps to Reproduce

1. Create a project for the seeed_wio_terminal
2. Add standard unit testing code to it
3. Execute pio test

Actual Results

Permission denied error on the serial device.

Expected Results

Testing goes through.

If problems with PlatformIO Build System:

The content of platformio.ini:

[env:seeed_wio_terminal]
platform = atmelsam
board = seeed_wio_terminal
framework = arduino

Source file to reproduce issue:

#include <Arduino.h>
#include <unity.h>

void TestConvertTemperatureToString(void)
{
    TEST_ASSERT_EQUAL(32, 32);
}

void setup()
{
    // NOTE!!! Wait for >2 secs
    // if board doesn't support software reset via Serial.DTR/RTS
    delay(5000);

    UNITY_BEGIN();
    RUN_TEST(TestConvertTemperatureToString);
    UNITY_END();
}

void loop()
{
}

Additional info

[ivankravets]

Could you re-test with pio upgrade --dev?

[cccadel]

Did a re-test for issue #3886 after pio upgrade --dev (5.2.0a3), but the unit test results are still not showing. It is still saying If you don't see output for the first 10 secs, please reset board (press reset button).

[maxgerhardt]

I tested it on an Arduino Pro Micro (5V), that does the USB serial via the ATMega32U4 chip, and before updating I get

avrdude done.  Thank you.

Testing...
If you don't see any output for the first 10 secs, please reset board (press reset button)

Error: Traceback (most recent call last):
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\__main__.py", line 115, in main
    cli()  # pylint: disable=no-value-for-parameter
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 782, in main
    rv = self.invoke(ctx)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\__init__.py", line 44, in invoke
    return super(PlatformioCLI, self).invoke(ctx)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\test\command.py", line 172, in cli
    "succeeded": tp.process(),
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\test\embedded.py", line 52, in process
    return self.run()
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\test\embedded.py", line 83, in run
    line = ser.readline().strip()
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\serial\serialwin32.py", line 273, in read
    raise SerialException("ClearCommError failed ({!r})".format(ctypes.WinError()))
serial.serialutil.SerialException: ClearCommError failed (PermissionError(13, 'Das Gerät erkennt den Befehl nicht.', None, 22))

============================================================

An unexpected error occurred. Further steps:

* Verify that you have the latest version of PlatformIO using
  `pip install -U platformio` command

* Try to find answer in FAQ Troubleshooting section
  https://docs.platformio.org/page/faq.html

* Report this problem to the developers
  https://github.com/platformio/platformio-core/issues

============================================================

The terminal process "C:\Users\Max\AppData\Local\Programs\Python\Python38\Scripts\platformio.exe 'test', '--environment', 'sparkfun_promicro16'" terminated with exit code: 1.

and then after upgrading (PlatformIO Core, version 5.2.0a3), I get the exact same error, identical log per above.

avrdude done.  Thank you.

Testing...
If you don't see any output for the first 10 secs, please reset board (press reset button)

Error: Traceback (most recent call last):
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\__main__.py", line 115, in main
    cli()  # pylint: disable=no-value-for-parameter
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 782, in main
    rv = self.invoke(ctx)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\__init__.py", line 44, in invoke
    return super(PlatformioCLI, self).invoke(ctx)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 1259, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\click\decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\test\command.py", line 172, in cli
    "succeeded": tp.process(),
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\test\embedded.py", line 52, in process
    return self.run()
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\platformio\commands\test\embedded.py", line 83, in run
    line = ser.readline().strip()
  File "c:\users\max\appdata\local\programs\python\python38\lib\site-packages\serial\serialwin32.py", line 273, in read
    raise SerialException("ClearCommError failed ({!r})".format(ctypes.WinError()))
serial.serialutil.SerialException: ClearCommError failed (PermissionError(13, 'Das Gerät erkennt den Befehl nicht.', None, 22))

I'm testing this on Windows 10 x64. After uploading, the board is reset and the COM port is temporarily lost and then reconnected. Seems like PIO tries to access it too early?

serial.serialutil.SerialException: ClearCommError failed (PermissionError(13, 'Das Gerät erkennt den Befehl nicht.', None, 22))

The german part translates to "The device does not recognize this command".

[maxgerhardt]

Oh wow I just recognized another quirk of.. the Arduino core or the bootloader? The device will not send any output on the USB serial if the DTR line is not set. As in, a simple

#include <Arduino.h>

void setup() {
  Serial.begin(9600);
}

void loop() {
  Serial.println("Test");
  delay(500);
}

will make the device expose the USB Serial device but no output unless I use hterm to connect to and set DTR, or do monitor_dtr = 1 in the platformio.ini. They did the same in stm32duino/Arduino_Core_STM32#1193.

When I use the "Test" button with above code, it will upload, and then fail to connect. After that if I connect with hterm and DTR line set, I will see the output..

[maxgerhardt]

This is still occurring with the latest core version per https://community.platformio.org/t/teensy-4-1-unit-testing-issue/21033.

[ivankravets]

We plan to introduce a new feature in 5.2.0 where developers will be able to create their own result streamer/driver. We will provide examples of how to use it and include this use case where you have to need a special Serial connection.

[ArthurREGNARD]

This can help, to temporary patch ...
#3956 (comment)

[Richard-Gemmell]

The underlying issue with the (Teensy 4 problem)[https://community.platformio.org/t/teensy-4-1-unit-testing-issue/21033] is that the test port disappears for a short while. Another way to fix the problem would be for Platform IO to wait until the specified test_port reappears before trying to connect to get the test results.

[michaelkargl]

To expand on that, this is also happening with my ESP32-S2 Kaluga1

[Spongman]

this also happens with my STM32 blackpill_f401cc after DFU upload (pio 5.2.4). the ports flicker during the upload.

If I DON'T specify the monitor_port in platform.ini, then the monitor asks me for the name of the port, when i type com5, then it works fine:

Transitioning to dfuMANIFEST state
============== [SUCCESS] Took 8.56 seconds ==============
--- Available filters and text transformations: colorize, debug, default, direct, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters

--- Available ports:
--- Enter port index or full name: com5
--- Miniterm on com5  9600,8,N,1 ---
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---

However, if I DO specify monitor_port = com5 in platform.ini, then the monitor attempts to connect immediately after upload and fails:

Transitioning to dfuMANIFEST state
============== [SUCCESS] Took 8.45 seconds ==============
--- Available filters and text transformations: colorize, debug, default, direct, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
could not open port 'com5': could not open port 'com5': FileNotFoundError(2, 'The system cannot find the file specified.', None, 2)

if i do the separate upload-only command, then wait, and then do the separate monitor command, then it works fine, also. so it's not a problem with the ports or anything, it simply an issue where the monitor is attempting to connect before the port is ready, and it's failing.

there needs to be some timeout/retry logic in there.

fwiw: i was able to work around this by adding a custom script:

platformio.ini:

extra_scripts = post:extra_script.py

extra_script.py :

Import("env")

def after_upload(source, target, env):
    port = env.GetProjectOption("monitor_port")
    print("waiting for " + port + " ...")
    import serial
    while True:
        try:
            s = serial.Serial(port)
            break
        except:
            pass

env.AddPostAction("upload", after_upload)

[ivankravets]

See the solution in the original post #3742 (comment)