Merge pull request #263 from knurling-rs/write

`write!` macro

firmware/qemu/Cargo.toml

@@ -44,6 +44,10 @@ test = false
 name = "log"
 test = false
 
+[[bin]]
+name = "double-write"
+test = false
+
 [[bin]]
 name = "alloc"
 test = false

firmware/qemu/src/bin/double-write.out

@@ -0,0 +1 @@
+0.000000 INFO one

firmware/qemu/src/bin/double-write.release.out

@@ -0,0 +1 @@
+0.000000 INFO one

firmware/qemu/src/bin/double-write.rs

@@ -0,0 +1,35 @@
+#![no_std]
+#![no_main]
+
+use cortex_m_rt::entry;
+
+use defmt::Format;
+use defmt_semihosting as _; // global logger
+
+use cortex_m_semihosting::debug;
+
+struct MyStruct;
+
+impl Format for MyStruct {
+    fn format(&self, fmt: &mut defmt::Formatter) {
+        defmt::write!(fmt, "one");
+        defmt::write!(fmt, "two");
+    }
+}
+
+#[entry]
+fn main() -> ! {
+    defmt::info!("{:?}", MyStruct);
+
+    loop {
+        debug::exit(debug::EXIT_FAILURE);
+    }
+}
+
+#[cfg(target_os = "none")]
+#[panic_handler]
+fn panic(_: &core::panic::PanicInfo) -> ! {
+    loop {
+        debug::exit(debug::EXIT_SUCCESS)
+    }
+}

firmware/qemu/src/bin/log.out

@@ -89,3 +89,5 @@
 0.000088 INFO wrapped: A(A { fld: 200 })
 0.000089 INFO (A(true), B(true)), (A(false), B(true)), (A(true), B(false))
 0.000090 INFO true, [1, 2]: DhcpReprMin { broadcast: true, a: [1, 2] }
+0.000091 INFO nested `Format` impls using `write!`: outer value (inner value (42))
+0.000092 INFO QEMU test finished!

firmware/qemu/src/bin/log.release.out

@@ -87,3 +87,5 @@
 0.000086 INFO wrapped: A(A { fld: 200 })
 0.000087 INFO (A(true), B(true)), (A(false), B(true)), (A(true), B(false))
 0.000088 INFO true, [1, 2]: DhcpReprMin { broadcast: true, a: [1, 2] }
+0.000089 INFO nested `Format` impls using `write!`: outer value (inner value (42))
+0.000090 INFO QEMU test finished!

firmware/qemu/src/bin/log.rs

@@ -4,7 +4,7 @@
 use core::sync::atomic::{AtomicU32, Ordering};
 use cortex_m_rt::entry;
 use cortex_m_semihosting::debug;
-use defmt::Format;
+use defmt::{Format, Formatter};
 
 use defmt_semihosting as _; // global logger
 
@@ -419,6 +419,31 @@ fn main() -> ! {
         defmt::info!("true, [1, 2]: {:?}", dhcp_repr);
     }
 
+    {
+        struct Inner(u8);
+
+        impl Format for Inner {
+            fn format(&self, f: &mut Formatter) {
+                defmt::write!(f, "inner value ({:u8})", self.0);
+            }
+        }
+
+        // `write!` tests
+        struct MyStruct(Inner);
+
+        impl Format for MyStruct {
+            fn format(&self, f: &mut Formatter) {
+                defmt::write!(f, "outer value ({:?})", self.0);
+            }
+        }
+
+        defmt::info!(
+            "nested `Format` impls using `write!`: {:?}",
+            MyStruct(Inner(42)),
+        );
+    }
+
+    defmt::info!("QEMU test finished!");
     loop {
         debug::exit(debug::EXIT_SUCCESS)
     }

firmware/qemu/test.sh

@@ -15,6 +15,7 @@ test "panic"
 test "assert"
 test "assert-eq"
 test "assert-ne"
+test "double-write"
 if rustc -V | grep nightly; then
     test "alloc" "alloc"
 fi

macros/src/lib.rs

@@ -752,44 +752,6 @@ pub fn debug_assert_ne_(ts: TokenStream) -> TokenStream {
     .into()
 }
 
-// TODO share more code with `log`
-#[proc_macro]
-pub fn winfo(ts: TokenStream) -> TokenStream {
-    let write = parse_macro_input!(ts as Write);
-    let ls = write.litstr.value();
-    let fragments = match defmt_parser::parse(&ls) {
-        Ok(args) => args,
-        Err(e) => {
-            return parse::Error::new(write.litstr.span(), e)
-                .to_compile_error()
-                .into()
-        }
-    };
-
-    let args = write
-        .rest
-        .map(|(_, exprs)| exprs.into_iter().collect())
-        .unwrap_or(vec![]);
-
-    let (pats, exprs) = match Codegen::new(&fragments, args.len(), write.litstr.span()) {
-        Ok(cg) => (cg.pats, cg.exprs),
-        Err(e) => return e.to_compile_error().into(),
-    };
-
-    let f = &write.fmt;
-    let sym = mksym(&ls, "info", false /* don't care */);
-    quote!({
-        match (&mut #f, #(&(#args)),*) {
-            (_fmt_, #(#pats),*) => {
-                _fmt_.header(&defmt::export::istr(#sym));
-                #(#exprs;)*
-                _fmt_.finalize();
-            }
-        }
-    })
-    .into()
-}
-
 struct Assert {
     condition: Expr,
     args: Option<FormatArgs>,
@@ -944,9 +906,11 @@ pub fn write(ts: TokenStream) -> TokenStream {
     };
 
     let fmt = &write.fmt;
+    // FIXME: Introduce a new `"write"` tag and decode it in a loop (breaking change).
     let sym = mksym(&ls, "fmt", false);
-    quote!(match (#fmt, #(&(#args)),*) {
-        (ref mut _fmt_, #(#pats),*) => {
+    quote!(match (&mut *#fmt, #(&(#args)),*) {
+        (_fmt_, #(#pats),*) => {
+            _fmt_.write_macro_start();
             // HACK conditional should not be here; see FIXME in `format`
             if _fmt_.needs_tag() {
                 _fmt_.istr(&defmt::export::istr(#sym));
@@ -958,8 +922,8 @@ pub fn write(ts: TokenStream) -> TokenStream {
     .into()
 }
 
-fn mksym(string: &str, section: &str, is_log_statement: bool) -> TokenStream2 {
-    let sym = symbol::Symbol::new(section, string).mangle();
+fn mksym(string: &str, tag: &str, is_log_statement: bool) -> TokenStream2 {
+    let sym = symbol::Symbol::new(tag, string).mangle();
     let section = format!(".defmt.{}", sym);
 
     // NOTE we rely on this variable name when extracting file location information from the DWARF

qemu-run/src/main.rs

@@ -100,7 +100,10 @@ fn decode(frames: &mut Vec<u8>, table: &Table) -> Result<(), DecodeError> {
                 frames.truncate(n - consumed);
             }
             Err(DecodeError::UnexpectedEof) => return Ok(()),
-            Err(DecodeError::Malformed) => return Err(DecodeError::Malformed),
+            Err(DecodeError::Malformed) => {
+                eprintln!("failed to decode defmt data: {:x?}", frames);
+                return Err(DecodeError::Malformed);
+            }
         }
     }
 }

src/export.rs

@@ -22,12 +22,6 @@ pub fn fetch_add_string_index() -> usize {
     (I.with(|i| i.fetch_add(1, core::sync::atomic::Ordering::Relaxed)) & 0x7f) as usize
 }
 
-/// For testing purposes
-#[cfg(target_arch = "x86_64")]
-pub fn fetch_timestamp() -> u8 {
-    T.with(|i| i.load(core::sync::atomic::Ordering::Relaxed)) & 0x7f
-}
-
 #[cfg(target_arch = "x86_64")]
 pub fn acquire() -> Option<Formatter> {
     None

src/lib.rs

@@ -170,6 +170,11 @@ pub use defmt_macros::trace;
 /// [the manual]: https://defmt.ferrous-systems.com/macros.html
 pub use defmt_macros::warn;
 
+/// Writes formatted data to a [`Formatter`].
+///
+/// [`Formatter`]: struct.Formatter.html
+pub use defmt_macros::write;
+
 /// Defines the global defmt logger.
 ///
 /// `#[global_logger]` needs to be put on a unit struct type declaration. This struct has to
@@ -219,8 +224,6 @@ pub use defmt_macros::global_logger;
 /// ```
 pub use defmt_macros::timestamp;
 
-#[doc(hidden)]
-pub use defmt_macros::winfo;
 #[doc(hidden)] // documented as the `Format` trait instead
 pub use defmt_macros::Format;
 
@@ -273,6 +276,11 @@ pub struct Formatter {
     // this is disabled while formatting a `{:[?]}` value (second element on-wards)
     // this is force-enable while formatting enums
     omit_tag: bool,
+    /// Whether the `write!` macro was called in the current `Format` impl. Used to prevent calling
+    /// it twice.
+    /// FIXME: Use a dedicated tag for `write!` invocations, allow calling it multiple times, and
+    /// remove this.
+    called_write_macro: bool,
 }
 
 /// the maximum number of booleans that can be compressed together
@@ -288,6 +296,7 @@ impl Formatter {
             bool_flags: 0,
             bools_left: MAX_NUM_BOOL_FLAGS,
             omit_tag: false,
+            called_write_macro: false,
         }
     }
 
@@ -315,6 +324,7 @@ impl Formatter {
             bool_flags: 0,
             bools_left: MAX_NUM_BOOL_FLAGS,
             omit_tag: false,
+            called_write_macro: false,
         }
     }
 
@@ -328,18 +338,29 @@ impl Formatter {
     /// Implementation detail
     pub fn fmt(&mut self, f: &impl Format, omit_tag: bool) {
         let old_omit_tag = self.omit_tag;
+        let old_called_write_macro = self.called_write_macro;
         if omit_tag {
             self.omit_tag = true;
         }
+        self.called_write_macro = false;
 
         f.format(self);
 
+        self.called_write_macro = old_called_write_macro;
         if omit_tag {
             // restore
             self.omit_tag = old_omit_tag;
         }
     }
 
+    pub fn write_macro_start(&mut self) {
+        if self.called_write_macro {
+            core::panic!("`defmt::write!` may only be called once in a `Format` impl");
+        }
+
+        self.called_write_macro = true;
+    }
+
     /// Implementation detail
     pub fn needs_tag(&self) -> bool {
         !self.omit_tag