Consider opening up more internal info

[diondokter]

Hello!

I'm doing work for 'Big Client' BC and we're running into some trouble with defmt.

BC already has a long established internal logging and event system which they want to keep using. It turns out it's big and opinionated enough that adding defmt support to it is infeasible (or so they tell me at least). So currently BC can't use defmt.

But they do want to use defmt as they want to use open source embedded Rust crates and also open up a lot of their stuff. Embedded Rust has semi-standardized on defmt and so they're tied to using it.

So these goals are incompatible and I'm trying to find a way to harmonize this.
The existing logging tool already has support for custom C-based string interning logs. If we had a way to customize the defmt output slightly, we could make it compatible enough for our needs.

Currently defmt is barely customizable since it doesn't expose any of its internals. There does seem to be a way that likely works for us, can be implemented in defmt in a backward compatible manner and would likely be a tiny maintenance burden (if kept as a 'use at your own risk, it's not covered by semver system).

---

Opening up the formatting internals so we can adapt to our own wire format.

Consider the following Rust code:

defmt::timestamp!("{=u32:us}", 0xDEADBEEF);

fn main() {
    defmt::println!(
        "hello: {} - {}",
        5,
        Test {
            a: 1,
            b: "2",
            c: 3.0
        }
    );
}

#[derive(defmt::Format)]
struct Test {
    a: u32,
    b: &'static str,
    c: f64,
}

Internally this is (part of) the trace it follows:

@istr: BDC8                   // Will contain the "hello: {} - {}" string
-- write: [C8, BD]
@u32: 0xDEADBEEF              // Timestamp
-- write: [EF, BE, AD, DE]
@fmt                          // Formatting the integer
@istr: E9D4                   // The format string for integer (will be "{=i32}")
-- write: [D4, E9]
@i32: 0x5                     // The integer value
-- write: [05, 00, 00, 00]
@fmt                          // Formatting the struct
@istr: BDC9                   // The format string for the struct
-- write: [C9, BD]
@u32: 0x1                     // struct field a
-- write: [01, 00, 00, 00]
@str: "2"                     // struct field b
@usize: 1                     // size of the string
-- write: [01, 00, 00, 00]
-- write: [32]                // Raw string contents
@f64: 3                       // struct field c
-- write: [00, 00, 00, 00, 00, 00, 08, 40]

This is a treasure trove of information. If we had access to this and if it could be modified we could create our own global logger that logs things compatible with our existing logging tool.

So my proposal is this:

• These functions must exist somehow somewhere
• We already forward some of these functions to the logger impl (e.g. acquire, write, etc.)
• We could forward most of these functions to the logger trait so the user can implement them
• We can keep backward-compat by providing the current implementations as default implementations on the trait

So what would that look like? (snippet)

pub unsafe trait Logger {
    fn acquire();
    unsafe fn flush();
    unsafe fn release();
    unsafe fn write(bytes: &[u8]);

    unsafe fn istr(address: u16) {
        write(&address.to_le_bytes());
    }
    unsafe fn bool(b: &bool) {
        u8(&(*b as u8));
    }
    unsafe fn u8(b: &u8) {
        write(&b.to_le_bytes());
    }
    // And more functions
}

If we have something like this we can intercept all the info and handle it as we need it.
For example, we might intercept the string slice and instead of writing a length and bytes, write the bytes and then null terminate it.

There are some things that need some more thought. Some of these functions (like fmt) use generics which is probably not possible using extern "Rust". And some other functions like timestamp don't directly interact with the write function. That's all still very valuable information to have, so maybe there could be some empty 'event' functions.
For example, when the Logger timestamp function is called, you'd know the next value would be the timestamp (which could be given through the u32 or u64 function).

---

I know this exposes a lot of the internals and that might be uncomfortable. However, in our usecase we're fine with pinning the version of defmt. So if this is 'officially' exposed, but semver unstable the onus would be on us to maintain compatibility with new enough versions.

Another thing is that maybe this should be feature gated? That would allow for removing the defmt version tag or setting it to something like 0 so that the defmt decode can refuse to touch any customized wire format.

Let me know what you think of this idea.

[jonathanpallant]

Thank you for this! My initial impressions are positive, but I want to take the time to talk with the team and give you a carefully considered response.

We'll get back to you next week if that's OK?

[jonathanpallant]

Also, if it helps, I attempted to label the various parts of defmt in this blog post: https://ferrous-systems.com/blog/defmt-1-0/

I believe we're talking about the Logging ABI here.

[diondokter]

We'll get back to you next week if that's OK?

Yes, that's perfectly alright!

I'll check out the blogpost.

[diondokter]

Also, to make it clear, if there's a plan and approval I will be able to spend time on it and build it.
I'm not expecting y'all to build it for me.

[jonathanpallant]

Some initial thoughts

1. Mixing the output of byte slices (which is what the global singleton implementation of trait Logger handles) with the generation of bytes (which is currently an internal defmt matter) seems to mix concerns, which might cause maintenance issues down the road.

2. In your example, if someone changed the default fn istr() method in the trait - how would a decoder know this had happened?

3. I wouldn't want to see a degradation in the primary use case (in terms of code size or code run-time performance) to support this secondary use case. So, it feels like this new mode needs to be optional and enabled with compile-time flags.

A possible route forward:

The generation of bytes is largely handled by methods in defmt::export, which the macro emits code to call:

unsafe {
    defmt::export::acquire_and_header(
        &{
            defmt::export::make_istr({
                #[link_section = ".defmt,e418b350dbe229f"]
                #[export_name = "{\"package\":\"test-crate\",\"tag\":\"defmt_println\",\"data\":\"hello: {} - {}\",\"disambiguator\":\"12066308861815510673\",\"crate_name\":\"test_crate\"}"]
                static DEFMT_LOG_STATEMENT: u8 = 0;
                &DEFMT_LOG_STATEMENT as *const u8 as u16
            })
        },
    );
};
defmt::export::fmt(arg0);
defmt::export::fmt(arg1);
unsafe { defmt::export::release() }

I could imagine a feature flag on defmt where instead of those methods having a fixed implementation:

/// Implementation detail
pub fn fmt<T: Format + ?Sized>(f: &T) {
    istr(&T::_format_tag());
    f._format_data();
}

they were instead bounced through a global singleton for custom encoding logic:

#[cfg(feature = "custom-encoding")]
pub fn fmt<T: Format + ?Sized>(f: &T) {
    let enc: &defmt::Encoder = _defmt_global_encoder();
    enc.fmt(f);
}

This would be worse in terms of code size and run-time performance, but I think would give you the flexibility you are looking for.

I think this is also compatible with adding another feature flag that stops the macros doing string-interning, turning all interned string IDs into *const &'static str pointers, and makes them pass the log level and crate name as string literals to the defmt::export::acquire_and_header function.

TL;DR:

Ferrous Systems is happy to review and merge PRs that see defmt expanded to allow for out-of-tree wire formats, especially if it aligns with our desire to support defmt passing on logs to println! or log or similar. However, not at the expense of code-size or run-time performance for the default use-case with the existing encoder, and not at the expense of backwards compatibility.

[jonathanpallant]

Also I should note, currently wire formats are strings, like defmt=5. You could arrange for the defmt crate to specify the wire format as custom or something. Or even let the encoder author use a macro to set it to dion_made_this_123 or whatever.