% Better debug logs
% Michael Stone
% February 13, 2022

---
header-includes: |
  <meta name="description" content="Improve your debug logs with meaning, context, and search."/>  
---

The standard interfaces in rust for "printf debugging" are traits called
`Debug` and `Display`, each with a method named `fmt()` that look like

```rust
pub trait Debug {
    fn fmt(&self, f: &mut Formatter<'_>) -> Result<(), Error>;
}
```

While a good choice for a general-purpose, portable, standard library,
individual programs may benefit from a logging interface that is more tailored
to their user interface:

![Hierarchical logging with search-based highlighting](./logging.png)

In the case of my recent work on [depict](https://github.com/mstone/depict), I
wanted to experiment with arranging my logs hierarchically (based on the
structure of the computation generating them) and with making them searchable
in my program's user interface.

Ultimately, I wound up deciding to store my logs in records that look like:

```rust
#[derive(Clone, Debug, PartialEq, PartialOrd)]
pub enum Record {
    String { name: Option<String>, ty: Option<String>, names: Vec<String>, val: String, },
    Group { name: Option<String>, ty: Option<String>, names: Vec<String>, val: Vec<Record>, },
    Svg { name: Option<String>, ty: Option<String>, names: Vec<String>, val: String, }
}
```

The idea here is that anything that I would normally have logged on a single
line with `printf()` or a `Display` or `Debug` method call will be recorded as
a `Record::String`, along with metadata about the computation or event whose
value is being recorded and about what *search terms* the value in question
should be indexed under: i.e., what `names` the value being logged is
responsive for.

My logging interface parallels the design of the `Debug` and `Display` traits,
with two modifications:

```rust
pub trait Log<Cx = ()> {
    fn log(&self, cx: Cx, l: &mut Logger) -> Result<(), Error>;
}
```

1. My trait is generic over a type parameter `Cx` of "context" which can be
used by by trait implementors to make extra information -- such as a closure --
available at value logging time, e.g., in order to give meaning to otherwise
opaque integers or other primary keys that may exist in a complex value being
logged as stand-ins or indices for data that live elsewhere by *calculating all
the "names"* that the value being logged should be indexed by.

2. Analogous to the `std::fmt::Formatter` helper, implementations of my trait
delegate the actual mechanics of logging data structured according to their
expectations to a `&mut Logger` object, here with methods for logging sets,
sequences, maps, their associated elements and pairs, as well as strings,
images, and (nested) groups of the above.

Next, by defining a trait like this one yourself, you can:

a. implement it on whatever types you like, including standard library
container types like `HashMap`s and `BTreeMap`s without requiring
newtype/"Printer" logging wrappers,

b. customize the kinds of information to be logged to fit your UI: for example,
logging hierarchical arrangements of text and images if those are easy to
display because you're working in a GUI and so have access to an HTML renderer,
or to nestable widgets, etc.

Finally, to round out the discussion, here's a fairly representative example of
what the trait impl code looks like for a decently complicated data structure,
in this case, a mapping from original to solved box positions implemented via
some nested `BTreeMap`s in which a "context" closure is used to give meaning to
the otherwise meaningless integers stored in the BTrees by logging the names of
the objects that the integers are indices for:

```rust
/// Marker trait for closures mapping LocIx to names
pub(crate) trait L2n : Fn(VerticalRank, OriginalHorizontalRank) -> Vec<Box<dyn Name>> {}
impl<CX: Fn(VerticalRank, OriginalHorizontalRank) -> Vec<Box<dyn Name>>> L2n for CX {}

impl<CX: L2n> log::Log<CX> for BTreeMap<VerticalRank, BTreeMap<OriginalHorizontalRank, SolvedHorizontalRank>> {
    fn log(&self, cx: CX, l: &mut log::Logger) -> Result<(), log::Error> {
       l.with_map("solved_locs", "SolvedLocs", self.iter(), |lvl, row, l| {
           l.with_map(format!("solved_locs[{lvl}]"), "SolvedLocs[i]", row.iter(), |ohr, shr, l| {
               let mut src_names = names![lvl, ohr];
               src_names.append(&mut cx(*lvl, *ohr));
               l.log_pair(
                   "Loc",
                   src_names,
                   format!("{lvl}v, {ohr}h"),
                   "SolvedHorizontalRank",
                   names![shr],
                   format!("{lvl}v, {shr}s")
               )
           })
       })
    }
}
```