Add support for log_format option for defmt_decoder

[andresovela]

This PR depends on knurling-rs/defmt#765.
This is probably an alternative to #413.

This closes #407, and maybe #412, although it seems to me that that would be better fixed by passing a separate --host_log_format option to allow further customization. That's also fairly simple to implement, so I can do it if there's a need for it.

In theory this would allow users to customize the format of the log output by changing the invocation of probe-run in .cargo/config.toml, by changing this line to something like:

runner = "probe-run --chip nrf52832_xxAA --log-format \"{t} [{L}] {f}:{l} {s}\""

However I haven't figured out how to write the command so that it's parsed correctly. If someone has an idea please do let me know :)

[Urhengulas]

However I haven't figured out how to write the command so that it's parsed correctly. If someone has an idea please do let me know :)

Can you please specify what is not working?

[andresovela]

It seems that the escaped double quotes are not interpreted correctly when the command is ran. I'll post the error I get later when I'm at the computer.

[andresovela]

I added a new host_log_format option and I added some default formats for both options. I think with that this PR has feature-parity with the previous setup using verbose and the always_print_location options.

[andresovela]

Can you please specify what is not working?

With

runner = "probe-run --chip nrf52832_xxAA"

I get this:

Running `probe-run --chip nrf52832_xxAA target/thumbv7em-none-eabihf/release/nrf-defmt-test`

With

runner = "probe-run --chip nrf52832_xxAA --log-format \"{t} [{L}] {f}:{l} {s}\""

I get this:

Running `probe-run --chip nrf52832_xxAA --log-format '"{t}' '[{L}]' '{f}:{l}' '{s}"' target/thumbv7em-none-eabihf/release/nrf-defmt-test`
Error: can't find ELF file at `[{L}]`; are you sure you got the right path?

I feel like there's a very simple way to make this work but I don't know which one and I haven't had time to investigate haha.

[Urhengulas]

Can you please specify what is not working?

With

runner = "probe-run --chip nrf52832_xxAA"

I get this:

Running `probe-run --chip nrf52832_xxAA target/thumbv7em-none-eabihf/release/nrf-defmt-test`

With

runner = "probe-run --chip nrf52832_xxAA --log-format \"{t} [{L}] {f}:{l} {s}\""

I get this:

Running `probe-run --chip nrf52832_xxAA --log-format '"{t}' '[{L}]' '{f}:{l}' '{s}"' target/thumbv7em-none-eabihf/release/nrf-defmt-test`
Error: can't find ELF file at `[{L}]`; are you sure you got the right path?

I feel like there's a very simple way to make this work but I don't know which one and I haven't had time to investigate haha.

I can reproduce this error. If I copy the command and run it separately it does work as expected:

$ probe-run --chip nRF52840_xxAA --log-format "{t} [{L}] {f}:{l} {s}" target/thumbv7em-none-eabihf/debug/hello
(HOST) INFO flashing program (2 pages / 8.00 KiB)
(HOST) INFO success!
────────────────────────────────────────────────────────────────────────────────
 [<lvl>] hello.rs:8 Hello, world!
────────────────────────────────────────────────────────────────────────────────
(HOST) INFO program has used at least 0.22/254.93 KiB (0.1%) of stack space
(HOST) INFO device halted without error

So the problem is with how the command from the toml gets escaped.

[Urhengulas]

The solution is in the cargo book:

Some Cargo commands invoke external programs, which can be configured as a path and some number of arguments.

The value may be an array of strings like ['/path/to/program', 'somearg'] or a space-separated string like '/path/to/program somearg'. If the path to the executable contains a space, the list form must be used.

Note the last sentence. Converting the runner to a list solves the problem.

# .cargo/config.toml

runner = [
  "probe-run",
  "--chip",
  "nRF52840_xxAA",
  "--log-format",
  "{t} [{L}] {f}:{l} {s}",
]

$ cargo rb hello
    Finished dev [optimized + debuginfo] target(s) in 0.04s
     Running `probe-run --chip nRF52840_xxAA --log-format '{t} [{L}] {f}:{l} {s}' target/thumbv7em-none-eabihf/debug/hello`
(HOST) INFO flashing program (2 pages / 8.00 KiB)
(HOST) INFO success!
────────────────────────────────────────────────────────────────────────────────
 [<lvl>] hello.rs:8 Hello, world!
────────────────────────────────────────────────────────────────────────────────
(HOST) INFO program has used at least 0.22/254.93 KiB (0.1%) of stack space
(HOST) INFO device halted without error

I think this is a bit annoying, but I don't see how we could change that (except patching cargo). We definitely have to document this everywhere. Also I am wondering if we could catch this error and give a better error message 🤔

[andresovela]

I don't understand what space is the problem. The command without the --log-format option also has a space and it works just fine

[Urhengulas]

I don't understand what space is the problem. The command without the --log-format option also has a space and it works just fine

If the command is just a string, it gets space-separated. Since the format string contains spaces it is not handled as one argument, but split up into multiple and therefore does not work. This is a limitation of cargo not clap.

[Urhengulas]

I think we are almost done.

• At the moment we warn if using {t} in host_log_format. But there is no host timestamp at the moment, so there should be no warning.
• I just noticed that the default log_format triggers the "no timestamp implementation" warning; i think we should remove it from the default format and add another warning (or info) "timestamp implementation available, but not used in log_format". What do you say?
• I am looking into adding a few snapshot tests for this feature.

[Urhengulas]

Can you please temporarily add a [patch.crates-io] section which specifies your other PR for defmt-decoder. This way CI will pass. --> not so important

[Urhengulas]

• I am looking into adding a few snapshot tests for this feature.

I send you a PR to add tests (and some refactoring): andresovela#1

[andresovela]

At the moment we warn if using {t} in host_log_format. But there is no host timestamp at the moment, so there should be no warning.

That should not be the case. The has_timestamp() function just checks the log_format, not the host_log_format. You can check that here.

I just noticed that the default log_format triggers the "no timestamp implementation" warning; i think we should remove it from the default format and add another warning (or info) "timestamp implementation available, but not used in log_format". What do you say?

I'm afraid I don't understand the problem. Is the problem that by default there's no timestamp implementation and therefore there's a warning by default? If that's the case, sure we can remove the timestamp from the default format, I don't mind.

[Urhengulas]

That should not be the case. The has_timestamp() function just checks the log_format, not the host_log_format. You can check that here.

You are right.

Is the problem that by default there's no timestamp implementation and therefore there's a warning by default? If that's the case, sure we can remove the timestamp from the default format, I don't mind.

That's exactly what I mean.

Can you please also remove the file tests/snapshots/snapshot__case_6_panic_verbose.snap.new. It slipped into my PR by accident.

After that I think we are good to merge.

[andresovela]

Done

[Urhengulas]

I will publish a new defmt-decoder release, update this PR, so CI runs through, merge it and will also publish it then.