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

embedded-test integration #2292

Merged
merged 12 commits into from
Mar 26, 2024
Merged

embedded-test integration #2292

merged 12 commits into from
Mar 26, 2024

Conversation

t-moe
Copy link
Contributor

@t-moe t-moe commented Mar 14, 2024

I've rebased/rewritten feature/testing. probe-rs run will now autodetect whether it is a test binary or a normal binary. You no longer need probe-rs test (adapt your cargo runner!)

New `probe-rs run --help` output
Flash and run an ELF program

Usage: probe-rs run [OPTIONS] <PATH> [TEST_FILTER]...

Arguments:
  <PATH>
          The path to the ELF file to flash and run.
          If the binary uses `embedded-test` each test will be executed in turn. See `TEST OPTIONS` for more configuration options exclusive to this mode.
          If the binary does not use `embedded-test` the binary will be flashed and run normally. See `RUN OPTIONS` for more configuration options exclusive to this mode.

Options:
      --always-print-stacktrace
          Always print the stacktrace on ctrl + c

      --no-location
          Suppress filename and line number information from the rtt log

      --log-format <LOG_FORMAT>
          The default format string to use for decoding defmt logs

      --rtt-scan-memory
          Scan the memory to find the RTT control block

  -h, --help
          Print help (see a summary with '-h')

RUN OPTIONS:
      --catch-reset
          Enable reset vector catch if its supported on the target

      --catch-hardfault
          Enable hardfault vector catch if its supported on the target

TEST OPTIONS:
      --list
          List all tests instead of executing them

      --format <pretty|terse|json>
          Configure formatting of the test report output

          Possible values:
          - pretty: One line per test. Output for humans. (default)
          - terse:  One character per test. Usefull for test suites with many tests
          - json:   Json output

      --exact
          If set, filters are matched exactly rather than by substring

  [TEST_FILTER]...
          The TEST_FILTER string is tested against the name of all tests, and only those tests whose names contain the filter are run. Multiple filter strings may be passed, which will run all tests matching any of the filters.

DOWNLOAD CONFIGURATION:
      --disable-progressbars
          

      --disable-double-buffering
          Use this flag to disable double-buffering when downloading flash data. If download fails during programming with timeout errors, try this option

      --restore-unwritten
          Enable this flag to restore all bytes erased in the sector erase but not overwritten by any page

      --flash-layout <filename>
          Requests the flash builder to output the layout into the given file in SVG format

      --verify
          After flashing, read back all the flashed data to verify it has been written correctly

      --binary-format <BINARY_FORMAT>
          If a format is provided, use it. If a target has a preferred format, we use that. Finally, if neither of the above cases are true, we default to ELF

      --base-address <BASE_ADDRESS>
          The address in memory where the binary will be put at. This is only considered when `bin` is selected as the format

      --skip <SKIP>
          The number of bytes to skip at the start of the binary file. This is only considered when `bin` is selected as the format
          
          [default: 0]

      --idf-bootloader <IDF_BOOTLOADER>
          The idf bootloader path

      --idf-partition-table <IDF_PARTITION_TABLE>
          The idf partition table path

      --chip-erase
          Whether to erase the entire chip before downloading

PROBE CONFIGURATION:
      --chip <CHIP>
          [env: PROBE_RS_CHIP=]

      --chip-description-path <chip description file path>
          [env: PROBE_RS_CHIP_DESCRIPTION_PATH=]

      --protocol <PROTOCOL>
          Protocol used to connect to chip. Possible options: [swd, jtag]
          
          [env: PROBE_RS_PROTOCOL=]

      --probe <PROBE>
          Use this flag to select a specific probe in the list.
          
          Use '--probe VID:PID' or '--probe VID:PID:Serial' if you have more than one probe with the same VID:PID.",
          
          [env: PROBE_RS_PROBE=]

      --speed <SPEED>
          The protocol speed in kHz
          
          [env: PROBE_RS_SPEED=]

      --connect-under-reset
          Use this flag to assert the nreset & ntrst pins during attaching the probe to the chip
          
          [env: PROBE_RS_CONNECT_UNDER_RESET=]

      --dry-run
          [env: PROBE_RS_DRY_RUN=]

      --allow-erase-all
          Use this flag to allow all memory, including security keys and 3rd party firmware, to be erased even when it has read-only protection
          
          [env: PROBE_RS_ALLOW_ERASE_ALL=]

LOG CONFIGURATION:
      --log-file <LOG_FILE>
          Location for log file
          
          If no location is specified, the behaviour depends on `--log-to-folder`.

      --log-to-folder
          Enable logging to the default folder. This option is ignored if `--log-file` is specified

Process finished with exit code 0

Remaining TODOs:

  • Improve Semihosting (maybe in a separate PR)
    • The architectures currently invoke decode_semihosting_syscall in every call to CoreInterface::status(), even if the target has not been continued between the calls. This is inefficient and leads to strange error messages (e.g. semihosting operation=0x00, because the register in question was overriden by the semihosting return value)
    • All semihosting operations which allow continuation of the core (e.g. SYS_GET_CMDLINE), should write a default return value back to the CPU register, so that even if the semihosting operation is not answered by the application, the core reads something valid back.
  • In Test RunMode: Print RTT + Stacktraces to stderr instead of stdout, so that test report can be collected by tools
    RustRover can handle the current output just fine though
  • Cleanup log messages ( + change log levels)

Test it

In order to test this branch, you need to use a diferent branch of embedded-test: https://github.com/probe-rs/embedded-test/compare/next?expand=1

I've also updated the example project: https://github.com/probe-rs/embedded-test-example/tree/next

You can test the whole thing for the esp32c6 with the following commands:

cargo install probe-rs --git https://github.com/probe-rs/probe-rs --branch feature/testing-rebased --features cli --bin probe-rs
git clone  git@github.com:probe-rs/embedded-test-example.git --branch next
cd embedded-test-example
cargo test --test async_test --features embassy

@t-moe t-moe changed the title Feature/testing rebased [WIP] Feature/testing rebased Mar 14, 2024
@t-moe t-moe marked this pull request as draft March 14, 2024 23:25
@t-moe t-moe mentioned this pull request Mar 14, 2024
5 tasks
@t-moe
Copy link
Contributor Author

t-moe commented Mar 15, 2024

When a test fails on riscv, I get the following output, if I print a stacktrace:

 INFO status: probe_rs::architecture::riscv: Semihosting found pc=0x4201e7a4 a0=0x20 a1=0x4086ed4c
 WARN probe_rs::debug::debug_info: UNWIND: Error while checking for exception context. The stack trace will not include the calling frames. : The unwinding of exception frames capability has not yet been implemented for this architecture.

Because of the large varieties of supported architectures, it is not always possible for
a contributor to implement functionality for all of them. This allows us to
implement new functionality on selected architectures first, and then add support for
the other architectures later.
 WARN probe_rs::debug::debug_info: UNWIND: Error while checking for exception context. The stack trace will not include the calling frames. : The unwinding of exception frames capability has not yet been implemented for this architecture.

Because of the large varieties of supported architectures, it is not always possible for
a contributor to implement functionality for all of them. This allows us to
implement new functionality on selected architectures first, and then add support for
the other architectures later.
 WARN probe_rs::debug::debug_info: UNWIND: Error while checking for exception context. The stack trace will not include the calling frames. : The unwinding of exception frames capability has not yet been implemented for this architecture.

Because of the large varieties of supported architectures, it is not always possible for
a contributor to implement functionality for all of them. This allows us to
implement new functionality on selected architectures first, and then add support for
the other architectures later.
 WARN probe_rs::debug::debug_info: UNWIND: Error while checking for exception context. The stack trace will not include the calling frames. : The unwinding of exception frames capability has not yet been implemented for this architecture.

Because of the large varieties of supported architectures, it is not always possible for
a contributor to implement functionality for all of them. This allows us to
implement new functionality on selected architectures first, and then add support for
the other architectures later.
 WARN probe_rs::debug::debug_info: UNWIND: Error while checking for exception context. The stack trace will not include the calling frames. : The unwinding of exception frames capability has not yet been implemented for this architecture.

Because of the large varieties of supported architectures, it is not always possible for
a contributor to implement functionality for all of them. This allows us to
implement new functionality on selected architectures first, and then add support for
the other architectures later.
Frame 0: syscall_readonly @ 0x4201e7a4
       /home/timo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.6/src/sys/arm_compat/syscall/riscv.rs:35:9
Frame 1: sys_exit_extended @ 0x4201e912
       /home/timo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.6/src/sys/arm_compat/mod.rs:198:2
Frame 2: exit @ 0x4201e844
       /home/timo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.6/src/sys/arm_compat/mod.rs:165:5
Frame 3: exit @ 0x4201e736
       /home/timo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.6/src/process.rs:14:5
Frame 4: <unknown function @ 0x4201e74e> @ 0x4201e74e
Error: "Test should have passed but it panicked"

We should de-noise this output :)

@t-moe

This comment was marked as outdated.

@t-moe

This comment was marked as outdated.

@SergioGasquez
Copy link
Contributor

SergioGasquez commented Mar 15, 2024

Thanks for all your work here @t-moe! I've updated my fork of esp-hal and did some local test of our HIL tests, here is a summary of the current status:

  • C6: All tests are working fine (as before)
  • H2: All tests are working fine (as before)
  • C3: Is now supported! All test are passing.
  • C2: Only some test can be flashed and pass (although the print an error reading from rtt), others just fail mid-flashing. Here is a log with both scenarios:
esp-hal/hil-test on  feature/hil-test [$] is 📦 v0.0.0 via 🦀 v1.76.0 took 2s 
❯ CARGO_BUILD_TARGET=riscv32imc-unknown-none-elf \
                  PROBE_RS_CHIP=esp32c2 \
                  cargo +nightly test --features=esp32c2 --test spi_full_duplex 
...
warning: `esp-hal` (lib) generated 4 warnings
    Finished `test` profile [optimized + debuginfo] target(s) in 0.03s
     Running tests/spi_full_duplex.rs (target/riscv32imc-unknown-none-elf/debug/deps/spi_full_duplex-c4f369c0047c7e05)
 WARN probe_rs::probe::ftdi: Read 0 bytes, expected 6
 WARN probe_rs::session: Failed to deconfigure device during shutdown: A RISC-V specific error occurred.

Caused by:
    Error occurred during execution of an abstract command: HaltResume                                                                                                                                                                                           Error: The flashing procedure failed for '/home/sergio/Documents/Espressif/forks/esp-hal/hil-test/target/riscv32imc-unknown-none-elf/debug/deps/spi_full_duplex-c4f369c0047c7e05'.

Caused by:
    0: Something during the interaction with the core went wrong
    1: An error with the usage of the probe occurred
    2: An error which is specific to the debug probe in use occurred.
    3: A timeout occurred during probe operation.
error: test failed, to rerun pass `--test spi_full_duplex`

Caused by:
  process didn't exit successfully: `probe-rs run /home/sergio/Documents/Espressif/forks/esp-hal/hil-test/target/riscv32imc-unknown-none-elf/debug/deps/spi_full_duplex-c4f369c0047c7e05` (exit status: 1)

esp-hal/hil-test on  feature/hil-test [$] is 📦 v0.0.0 via 🦀 v1.76.0 took 2s 
❯ CARGO_BUILD_TARGET=riscv32imc-unknown-none-elf \
                  PROBE_RS_CHIP=esp32c2 \
                  cargo +nightly test --features=esp32c2 --test uart 
....
warning: `esp-hal` (lib) generated 4 warnings
    Finished `test` profile [optimized + debuginfo] target(s) in 0.03s
     Running tests/uart.rs (target/riscv32imc-unknown-none-elf/debug/deps/uart-5ff41442273db4c9)
      Erasing ✔ [00:00:00] [#####################################################################################################################################################################################] 192.00 KiB/192.00 KiB @ 246.31 KiB/s (eta 0s )
  Programming ✔ [00:00:01] [########################################################################################################################################################################################] 35.88 KiB/35.88 KiB @ 24.46 KiB/s (eta 0s )    Finished in 2.318s

running 1 test
test tests::test_send_receive ... ERROR probe_rs::util::rtt: 
Error reading from RTT: The control block has been corrupted. write pointer is 578562214 while buffer size is 1024 for "up" channel 0 (defmt)
ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.87s

Edit: Did some testing flashing some ESP32-C2 apps (using esp-hal examples) and had some flashing issues there too, so maybe they are not related with this PR:

esp-hal/examples on  feat/hil-testing [$!?] is 📦 v0.0.0 via 🦀 v1.76.0 
❯ cargo +nightly esp32c2 --bin=hello_world 
...
   Compiling examples v0.0.0 (/home/sergio/Documents/Espressif/esp-rs/esp-hal/examples)
    Finished `release` profile [optimized + debuginfo] target(s) in 6.72s
     Running `probe-rs run --chip esp32c2 target/riscv32imc-unknown-none-elf/release/hello_world`
      Erasing ✔ [00:00:00] [#####################################################################################################] 192.00 KiB/192.00 KiB @ 222.23 KiB/s (eta 0s )
  Programming ✔ [00:00:01] [########################################################################################################] 25.82 KiB/25.82 KiB @ 24.52 KiB/s (eta 0s )    Finished in 1.988s
 WARN probe_rs::util::rtt: No RTT header info was present in the ELF file. Does your firmware run RTT?
^C⏎                                                                                                                                                                              

esp-hal/examples on  feat/hil-testing [$!?] is 📦 v0.0.0 via 🦀 v1.76.0 took 10s 
❯ cargo +nightly esp32c2 --bin=ledc
   Compiling examples v0.0.0 (/home/sergio/Documents/Espressif/esp-rs/esp-hal/examples)
    Finished `release` profile [optimized + debuginfo] target(s) in 0.16s
     Running `probe-rs run --chip esp32c2 target/riscv32imc-unknown-none-elf/release/ledc`
      Erasing ✔ [00:00:00] [#####################################################################################################] 192.00 KiB/192.00 KiB @ 224.59 KiB/s (eta 0s )
  Programming ✔ [00:00:01] [########################################################################################################] 28.20 KiB/28.20 KiB @ 22.15 KiB/s (eta 0s )    Finished in 2.199s
 WARN probe_rs::util::rtt: No RTT header info was present in the ELF file. Does your firmware run RTT?
^C⏎                                                                                                                                                                              

esp-hal/examples on  feat/hil-testing [$!?] is 📦 v0.0.0 via 🦀 v1.76.0 
❯ cargo +nightly esp32c2 --bin=i2c_display
   Compiling examples v0.0.0 (/home/sergio/Documents/Espressif/esp-rs/esp-hal/examples)
    Finished `release` profile [optimized + debuginfo] target(s) in 0.29s
     Running `probe-rs run --chip esp32c2 target/riscv32imc-unknown-none-elf/release/i2c_display`
      Erasing ✔ [00:00:00] [#####################################################################################################] 192.00 KiB/192.00 KiB @ 224.58 KiB/s (eta 0s )
  Programming ✔ [00:00:01] [########################################################################################################] 36.97 KiB/36.97 KiB @ 28.55 KiB/s (eta 0s )    Finished in 2.222s
 WARN probe_rs::util::rtt: No RTT header info was present in the ELF file. Does your firmware run RTT?
 WARN probe_rs::session: Could not clear all hardware breakpoints: A RISC-V specific error occurred.

Caused by:
    Error during transport
Error: Some cores are running while some are halted, this should not happen.

Caused by:
    Some cores are running while some are halted, this should not happen.

esp-hal/examples on  feat/hil-testing [$!?] is 📦 v0.0.0 via 🦀 v1.76.0 took 3s 
❯ cargo +nightly esp32c2 --bin=i2c_display
    Finished `release` profile [optimized + debuginfo] target(s) in 0.05s
     Running `probe-rs run --chip esp32c2 target/riscv32imc-unknown-none-elf/release/i2c_display`
ERROR probe_rs::probe::common: Fewer IRs detected than TAPs
Error: Connecting to the chip was unsuccessful.

Caused by:
    0: An error with the usage of the probe occurred
    1: Invalid IR scan chain
    2: Invalid IR scan chain

esp-hal/examples on  feat/hil-testing [$!?] is 📦 v0.0.0 via 🦀 v1.76.0 
❯ cargo +nightly esp32c2 --bin=hello_world 

    Finished `release` profile [optimized + debuginfo] target(s) in 0.12s
     Running `probe-rs run --chip esp32c2 target/riscv32imc-unknown-none-elf/release/hello_world`
ERROR probe_rs::probe::common: Truncated IDCODE: BitSlice<u8, bitvec::order::Lsb0> { addr: 0x651ad75d563f, head: 111, bits: 01 } [01]
Error: Connecting to the chip was unsuccessful.

Caused by:
    0: An error with the usage of the probe occurred
    1: Invalid IDCODE
    2: Invalid IDCODE

@t-moe t-moe mentioned this pull request Mar 15, 2024
@t-moe t-moe changed the title [WIP] Feature/testing rebased embedded-test integration Mar 20, 2024
@t-moe t-moe marked this pull request as ready for review March 20, 2024 21:22
@t-moe
Copy link
Contributor Author

t-moe commented Mar 20, 2024

I would like to get a first round of reviews for this PR.
There are only a few TODOs left, which are described in the top-level comment.

@t-moe t-moe requested review from bugadani and Yatekii March 20, 2024 21:24
@t-moe t-moe changed the title embedded-test integration embedded-test integration Mar 20, 2024
probe-rs/Cargo.toml Outdated Show resolved Hide resolved
Copy link
Contributor

@bugadani bugadani left a comment

Choose a reason for hiding this comment

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

Most of what I can see are stylistical nitpicking. This is really exciting!

Copy link
Contributor

@MabezDev MabezDev left a comment

Choose a reason for hiding this comment

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

Looking good from my perspective, just some nits around log levels now that things are working

probe-rs/src/bin/probe-rs/cmd/run/mod.rs Outdated Show resolved Hide resolved
probe-rs/src/semihosting.rs Outdated Show resolved Hide resolved
@SergioGasquez
Copy link
Contributor

Actually, the architecture matching (#2292 (comment)) was dumb, after reverting the changes (#2308):

  • On Xtensa devices, reg is:
id: RegisterId(2), roles: [Core("a2"), Argument("a2"), Return("a2")], data_type: UnsignedInteger(32), unwind_rule: Clear
  • On RISC-V devies, reg is:
id: RegisterId(4106), roles: [Core("x10"), Argument("a0"), Return("r0")], data_type: UnsignedInteger(32), unwind_rule: Clear

So both archs work fine with how it was.

@SergioGasquez
Copy link
Contributor

SergioGasquez commented Mar 22, 2024

Since we now support Xtensa devices, tried to run tests with this branch for Xtensa targets:

ESP32 Output Error
  Erasing ✔ [00:00:00] [########################################] 192.00 KiB/192.00 KiB @ 483.95 KiB/s (eta 0s )
  Programming ✔ [00:00:01] [###########################################] 46.58 KiB/46.58 KiB @ 37.84 KiB/s (eta 0s )    Finished in 1.693s
 INFO probe_rs::cmd::run::test_run_mode: libtest args Arguments { include_ignored: false, ignored: false, test: false, bench: false, list: false, nocapture: false, show_output: false, unstable_flags: None, exact: false, quiet: false, test_threads: Some(1), logfile: None, skip: [], color: None, format: None, filter: None }
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
ERROR probe_rs::cmd::run: Failed to attach to RTT, continuing...
Frame 0: <unknown function @ 0x400073d9> @ 0x400073d9
Frame 1: <unknown function @ 0x8000fc16> @ 0x8000fc16
 INFO session_drop: probe_rs::session: Core status: Halted(Request)
 INFO session_drop: probe_rs::architecture::xtensa::communication_interface: Left OCD mode
Error: The target did not respond with test list until timeout.
error: test failed, to rerun pass `--test gpio`

Caused by:
  process didn't exit successfully: `probe-rs run /home/sergio/Documents/Espressif/esp-rs/esp-hal/hil-test/target/xtensa-esp32-none-elf/debug/deps/gpio-5fbfd0d1ee03a753` (exit status: 1)
ESP32-S2 Output Error
      Erasing ✔ [00:00:00] [#####################################################################################################################################################################################] 192.00 KiB/192.00 KiB @ 209.22 KiB/s (eta 0s )
  Programming ✔ [00:00:01] [########################################################################################################################################################################################] 43.91 KiB/43.91 KiB @ 25.73 KiB/s (eta 0s )    Finished in 2.69s
 INFO probe_rs::cmd::run::test_run_mode: libtest args Arguments { include_ignored: false, ignored: false, test: false, bench: false, list: false, nocapture: false, show_output: false, unstable_flags: None, exact: false, quiet: false, test_threads: Some(1), logfile: None, skip: [], color: None, format: None, filter: None }
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: RTT initialized.
 INFO status: probe_rs::architecture::xtensa: Semihosting found pc=0x40082707 a2=0x15 a3=0x3ffdef64
 INFO probe_rs::cmd::run::test_run_mode: target asked for cmdline. send 'list'
 INFO status: probe_rs::architecture::xtensa: Semihosting found pc=0x400815b6 a2=0x100 a3=0x3ffdef64
 INFO probe_rs::cmd::run::test_run_mode: got list of tests from target: Tests { version: 1, tests: [Test { name: "tests::test_send_receive", should_panic: false, ignored: false, timeout: Some(3) }] }

running 1 test
test tests::test_send_receive ...  INFO probe_rs::cmd::run::test_run_mode: Running test tests::test_send_receive
 INFO probe_rs::util::rtt: Initializing RTT
 INFO probe_rs::util::rtt: RTT initialized.
ERROR probe_rs::util::rtt: 
Error reading from RTT: The control block has been corrupted. write pointer is 959144892 while buffer size is 1024 for "up" channel 0 (defmt)
 INFO status: probe_rs::architecture::xtensa: Semihosting found pc=0x40082707 a2=0x15 a3=0x3ffdef64
 INFO probe_rs::cmd::run::test_run_mode: target asked for cmdline. send 'run tests::test_send_receive'
 INFO status: probe_rs::architecture::xtensa: Semihosting found pc=0x400826bd a2=0x20 a3=0x3ffde360
Frame 0: syscall_readonly @ 0x400826bd inline
       /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/syscall/xtensa.rs:29:9
Frame 1: sys_exit_extended @ 0x00000000400826bd inline
       /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/mod.rs:197:9
Frame 2: exit @ 0x00000000400826b1 inline
       /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/mod.rs:166:5
Frame 3: exit @ 0x00000000400826b1
       /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/process.rs:14:5
Frame 4: <unknown function @ 0x800826e0> @ 0x800826e0
 INFO session_drop:status: probe_rs::architecture::xtensa: Semihosting found pc=0x400826bd a2=0x20 a3=0x3ffde360
 INFO session_drop: probe_rs::session: Core status: Halted(Breakpoint(Semihosting(ExitError(ExitErrorDetails { reason: 131110, exit_status: Some(134), subcode: None }))))
 INFO session_drop: probe_rs::architecture::xtensa::communication_interface: Left OCD mode
FAILED

failures:

---- tests::test_send_receive ----
Test should have passed but it panicked


failures:
    tests::test_send_receive

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.68s

Error: Some tests failed
error: test failed, to rerun pass `--test uart`

Caused by:
  process didn't exit successfully: `probe-rs run /home/sergio/Documents/Espressif/esp-rs/esp-hal/hil-test/target/xtensa-esp32s2-none-elf/debug/deps/uart-f5c7cc3a518f29e2` (exit status: 1)

@t-moe
Copy link
Contributor Author

t-moe commented Mar 25, 2024

I tried to improve the semihosting stuff today. Recall the two problems (top comment)

  • The architectures currently invoke decode_semihosting_syscall in every call to CoreInterface::status(), even if the target has not been continued between the calls. This is inefficient and leads to strange error messages (e.g. semihosting operation=0x00, because the register in question was overriden by the semihosting return value)
  • All semihosting operations which allow continuation of the core (e.g. SYS_GET_CMDLINE), should write a default return value back to the CPU register, so that even if the semihosting operation is not answered by the application, the core reads something valid back.

Especially the first point needs careful review. Please look at a4789d5 . I have only a risc-v here, and of course I validated the change there, but for the other platforms I need your eyes. Thank you!

@t-moe
Copy link
Contributor Author

t-moe commented Mar 25, 2024

I've also fixed the remaining ToDo and you can now obtain a test report on stdout, so that it can be processed by the CI pipeline.

e.g.
probe-rs run --chip esp32c6 --format=json <ELF> | cargo2junit > testreport.xml

@SergioGasquez
Copy link
Contributor

Please look at a4789d5

Just had a look and it looks good to me. I've also retested Xtensa and RISC-V targets:

  • C2, C3, C6, H2 and S3 are working fine. But some targets (C2 and C3) shows some rtt errors:
28.97 KiB/28.97 KiB @ 22.69 KiB/s (eta 0s )    Finished in 2.209s
ERROR probe_rs::util::rtt: 
Error reading from RTT: The control block has been corrupted. write pointer is 59496787 while buffer size is 1024 for "up" channel 0 (defmt)

running 1 test
test tests::test_send_receive ... ERROR probe_rs::util::rtt: 
Error reading from RTT: The control block has been corrupted. write pointer is 327110218 while buffer size is 1024 for "up" channel 0 (defmt)
ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.77s
  • ESP32-S2
    Finished in 2.207s

running 1 test
test tests::test_send_receive ... Frame 0: syscall_readonly @ 0x40082831 inline
      /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/syscall/xtensa.rs:29:9
Frame 1: sys_exit_extended @ 0x0000000040082831 inline
      /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/mod.rs:197:9
Frame 2: exit @ 0x0000000040082825 inline
      /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/sys/arm_compat/mod.rs:166:5
Frame 3: exit @ 0x0000000040082825
      /home/sergio/.cargo/registry/src/index.crates.io-6f17d22bba15001f/semihosting-0.1.7/src/process.rs:14:5
Frame 4: <unknown function @ 0x80082854> @ 0x80082854
FAILED

failures:

---- tests::test_send_receive ----
Test should Pass but it did Panic


failures:
   tests::test_send_receive

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.66s
  • ESP32:
    Finished in 1.71s
Frame 0: <unknown function @ 0x400073d9> @ 0x400073d9
Frame 1: <unknown function @ 0x8000fc16> @ 0x8000fc16
Error: The target did not respond with test list until timeout.

@MabezDev
Copy link
Contributor

MabezDev commented Mar 25, 2024

C2/C3 issue could be a known limitation of defmt where the debugger reads the control block before its fully initialized.

S2 looks fine, but the panic message should be printed somewhere (look at the test outcome).

ESP32, unknown what this issue is.

Edit: We don't yet have ESP32 in CI, so we shouldn't block this PR on it. The C2/C3 issue is intermittent and unlikely to be related to this PR. I think the only thing worth investigating is where the panic message has gone for the S2, this is something that could be relevant to all targets.

@MabezDev
Copy link
Contributor

MabezDev commented Mar 26, 2024

@t-moe I think the only thing to solve here is panic messages disappearing. I was aware of a similar issue in #1890. It looks like the same sort of issue. I did some digging and found https://github.com/probe-rs/probe-rs/blob/cbf1c380c513dc0865004deb1286a7ec9299a6bf/probe-rs/src/bin/probe-rs/cmd/run/mod.rs. When this path is executed we don't poll rtt again (I think) which is probably why the panic never appears. Could you look into this? I need more coffee, that definitely isn't the case. I think the only way we could miss panic messages is if the chip failed to run again. This is likely an Xtensa issue.

@t-moe
Copy link
Contributor Author

t-moe commented Mar 26, 2024

I think you dont see the panic message on the S2 because of the same rtt error as on the C2 +C3.

See the output from the S2 here: #2292 (comment)

@MabezDev
Copy link
Contributor

Ah sorry, I didn't see the logs in that comment 😅

Copy link
Contributor

@MabezDev MabezDev left a comment

Choose a reason for hiding this comment

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

LGTM! We've been using this in esp-hal for a the last week, and no issues so far. Thanks for working on this @t-moe!

@bugadani
Copy link
Contributor

Thanks for working on this, let's hammer out issues separately.

@bugadani bugadani added this pull request to the merge queue Mar 26, 2024
Merged via the queue into master with commit 8e60d01 Mar 26, 2024
18 checks passed
@bugadani bugadani deleted the feature/testing-rebased branch March 26, 2024 12:27
@t-moe
Copy link
Contributor Author

t-moe commented Mar 26, 2024

Yay 🥳 , thanks for merging this.
I'll release a new embedded-test version as soon as probe-rs is released.

@bugadani
Copy link
Contributor

bugadani commented Apr 2, 2024

failures:
    unit_tests::it_fails1
    unit_tests::it_fails2
    unit_tests::it_fails3
    unit_tests::it_timeouts

test result: FAILED. 3 passed; 4 failed; 1 ignored; 0 measured; 0 filtered out; finished in 14.23s

I have been able to run the example embedded-test project on my S2 without too much trouble. The output is a bit weird to read with defmt output (the first message has no preceding newline because the test status doesn't expect one), but that's nothing serious, so good job!

@SergioGasquez do you have a cloneable reproducer for your S2/ESP32 issues? Are you confident that the tests you're running are supposed to pass?

@SergioGasquez
Copy link
Contributor

do you have a cloneable reproducer for your S2/ESP32 issues?

❯ cargo install probe-rs --features cli --git https://github.com/probe-rs/probe-rs --rev ddd59fa
❯ git clone https://github.com/SergioGasquez/esp-hal --branch feat/esp32-hil
❯ cd esp-hal/hil-test/
❯ espflash erase-flash
[2024-04-03T10:35:22Z INFO ] Serial port: '/dev/ttyUSB0'
[2024-04-03T10:35:22Z INFO ] Connecting...
[2024-04-03T10:35:23Z INFO ] Using flash stub
[2024-04-03T10:35:24Z WARN ] Setting baud rate higher than 115,200 can cause issues
[2024-04-03T10:35:24Z INFO ] Erasing Flash...
[2024-04-03T10:35:26Z INFO ] Flash has been erased!
❯ CARGO_BUILD_TARGET=xtensa-esp32-none-elf \
            PROBE_RS_CHIP=esp32-3.3v \
            cargo +esp test --features=esp32 --test spi_full_duplex
    Finished test [optimized + debuginfo] target(s) in 0.09s
     Running tests/spi_full_duplex.rs (target/xtensa-esp32-none-elf/debug/deps/spi_full_duplex-872205df03ecc139)
 WARN probe_rs::config::sequences::esp32: Be careful not to reset your ESP32 while connected to the debugger! Depending on the specific device, this may render it temporarily inoperable or permanently damage it.
      Erasing ✔ [00:00:00] [###] 192.00 KiB/192.00 KiB @ 1.36 MiB/s (eta 0s )
  Programming ✔ [00:00:01] [####] 51.54 KiB/51.54 KiB @ 37.73 KiB/s (eta 0s )    Finished in 1.569s
ERROR probe_rs::cmd::run: Failed to attach to RTT, continuing...
Frame 0: <unknown function @ 0x40009a3c> @ 0x40009a3c
Frame 1: <unknown function @ 0x8000f9f7> @ 0x8000f9f7
Error: The target did not respond with test list until timeout.
error: test failed, to rerun pass `--test spi_full_duplex`

Caused by:
  process didn't exit successfully: `probe-rs run /home/sergio/Documents/Espressif/tests/esp-hal/hil-test/target/xtensa-esp32-none-elf/debug/deps/spi_full_duplex-872205df03ecc139` (exit status: 1)
❯ CARGO_BUILD_TARGET=xtensa-esp32-none-elf \
            PROBE_RS_CHIP=esp32-3.3v \
            cargo +esp test --features=esp32 --test uart
   Compiling hil-test v0.0.0 (/home/sergio/Documents/Espressif/tests/esp-hal/hil-test)
    Finished test [optimized + debuginfo] target(s) in 0.47s
     Running tests/uart.rs (target/xtensa-esp32-none-elf/debug/deps/uart-b19a5891e0111a2a)
 WARN probe_rs::config::sequences::esp32: Be careful not to reset your ESP32 while connected to the debugger! Depending on the specific device, this may render it temporarily inoperable or permanently damage it.
      Erasing ✔ [00:00:00] [###] 192.00 KiB/192.00 KiB @ 1.36 MiB/s (eta 0s )
  Programming ✔ [00:00:01] [####] 48.50 KiB/48.50 KiB @ 38.96 KiB/s (eta 0s )    Finished in 1.448s
ERROR probe_rs::cmd::run: Failed to attach to RTT, continuing...
Frame 0: <unknown function @ 0x4000f979> @ 0x4000f979
Frame 1: <unknown function @ 0x80007b5c> @ 0x80007b5c
Error: The target did not respond with test list until timeout.
error: test failed, to rerun pass `--test uart`

Caused by:
  process didn't exit successfully: `probe-rs run /home/sergio/Documents/Espressif/tests/esp-hal/hil-test/target/xtensa-esp32-none-elf/debug/deps/uart-b19a5891e0111a2a` (exit status: 1)

Are you confident that the tests you're running are supposed to pass?

Same tests are running successfully for other targets, and they should be the same in ESP32.

mahu-wm added a commit to weinmann-emt/probe-rs that referenced this pull request Jun 5, 2024
…l request probe-rs#2292

This reverts commit a4789d5.
This commit was squashed into 8e60d01.
mahu-wm added a commit to weinmann-emt/probe-rs that referenced this pull request Jun 5, 2024
…ll request probe-rs#2292

This reverts commit 3b6a3b1.
This commit was squashed into 8e60d01.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants