Obnam → blog → 2025 → Obnam 3: Logging
  1. Goal
  2. Plan
  3. Notes
  4. Summary
  5. Comments?

Goal

Today I want to address some long-standing, but fairly minor issues in the Obnam project.

Plan

  • Add some logging and remove debug prints. This requires picking a logging system. That's a decision that can be changed later, so I'm going pick log and env_logger. It's possible we'll want tracing later, for structured logs if nothing else, but I want to start small.
  • The obnam.org web site needs updating. As part of that, the subplot and architecture documents should be rendered as HTML and published by CI on the doc.obnam.org site.

I might do more, if I have time.

Notes

Preparation

  • Run make to ensure everything is still OK. It is.

Logging

  • Create branch logging.
  • cargo add log
  • cargo add env_logger
  • make
  • Commit changes.
  • I need a systematic approach to how logging is used.
    • trace is for debug information aimed at Obnam developers
    • everything else is aimed at those running Obnam
    • debug is for detailed information aimed at troubleshooting
    • info is for high-level "what's happening" information
    • warn is for things that aren't wrong, but should be looked at, and for non-fatal errors
    • error is for fatal errors
  • At least for now I'll use the log macros directly. I may some day want to have wrappers around them, but for now I'll keep things simple. I like simple.
  • Add set up of env_logger in src/bin/obnam.rs. The default log level is info, and can be set with the OBNAM_LOG environment variable or the --log-level global option. To test this, I'll make obnam log messages at all log levels at start up.
  • I'm not adding setting of configuration level to the configuration file, for now. It'll be an easy addition if someone actually needs it.
  • After this, I merely need to add logging everywhere it's needed. However, I'm not making these acceptance criteria, that'd be way too much work for how important these are.
  • From some quick grepping, there doesn't seem to be any debug printing in the code base any more. Good.
  • Error messages in main should be error logs.
  • I'll add a "subcommand invoked" debug message to every subcommand. I don't to just do a debug-formatted dump of the subcommand, I want to make the log message more useful.
  • Today I'm not adding any trace messages, and only do a little to make the debug logging useful. Tweaking log messages is going to continue forever.
  • Committed changes, pushed to Radicle patch, failed.
  • Ran rad ci to emulate CI locally. I should do this more diligently.
  • Hm, the log level scenario fails in CI, but works on my laptop.
  • Oh, no it doesn't. CI runs more tests than make does. Oops.
  • My logic for deteremining what log level to use is just broken. I'd use clap to set a default value for obnam --log-level that overrides the environment variable.
  • Fixed that. CI now runs successfully.
  • Merged.

All this debugging took long enough that I ran out of time, again. Bummer. I'll do the document publishing some later time.

Summary

Comments?

If you have feedback on this development session, please use the following fediverse thread: https://toot.liw.fi/@liw/115320733479998146.