Seeing what happened

What you want to do

When an order ends the way it did, you want to know who decided what, and when: which step reported which outcome, what the executor decided because of it, and in what order. And you want every journey of every workflow to tell you that the same way, so that one log reads them all, without a println! in any step.

The code

Everything that happens in a journey is an event, and the executor reports every one. A reporter receives them, one at a time, and decides what to do with each. The shop's log is a reporter: a struct implementing the Reporter trait, whose report writes a line for each event. The line gives the event's number and its kind, and, for the kinds the log says more about, the step the event is about and what it names.

/// The shop's log: it writes a line for every event of a journey.
#[derive(Default)]
struct Log;

impl Reporter for Log {
    fn report(&mut self, event: &Event) -> Result<(), Error> {
        match detail(&event.body) {
            Some(detail) => println!("log #{} {} {detail}", event.sequence, event.kind()),
            None => println!("log #{} {}", event.sequence, event.kind()),
        }
        Ok(())
    }
}

/// What the log says after an event's kind, for the kinds it says more about: the step the event
/// is about, and what it names.
fn detail(body: &EventBody) -> Option<String> {
    match body {
        EventBody::JourneyStarted { initial_keys, .. } => Some(initial_keys.join(", ")),
        EventBody::AttemptStarted { step, .. }
        | EventBody::StepSucceeded { step, .. }
        | EventBody::StepGivenUp { step, .. } => Some(step.step.to_string()),
        EventBody::ServiceProvided {
            step,
            key,
            provider,
            implementation,
            ..
        } => Some(format!(
            "{} gets {key} from {provider}, a {implementation}",
            step.step
        )),
        EventBody::StepFailed { step, reason, .. } => {
            Some(format!("{}: {}", step.step, reason.code()))
        }
        EventBody::ContributionCommitted { key, .. } => Some(key.clone()),
        EventBody::JourneyFailed { step, .. } => Some(step.to_string()),
        _ => None,
    }
}

The workflow lists the log in #[workflow(...)], with reporters = [Log]. Its providers no longer print, since the log now says so, and the carrier's is now called main_carrier, with key = "carrier":

/// The shop's workflow: it charges, then ships, and every journey is logged.
#[workflow(name = "orders", reporters = [Log])]
#[with_step(Charge, name = "charge")]
#[with_step(Ship, name = "ship")]
struct Orders;

#[workflow]
impl Orders {
    /// The bank, as the payment client of the journey.
    #[provider(key = "payments")]
    fn bank(&self) -> Result<Provided<dyn Payments>, Error> {
        Ok(provide!(Bank))
    }

    /// The main carrier, as the carrier of the journey.
    #[provider(key = "carrier")]
    fn main_carrier(&self) -> Result<Provided<dyn Carrier>, Error> {
        Ok(provide!(MainCarrier { max_weight: 20 }))
    }
}

Everything else is chapter 7's shop, run for Ann's and Gil's orders. The faked bank and carrier still print what they do. It prints:

Ann's order:
log #1 journey_started order, price, weight
log #2 attempt_started charge
log #3 service_provided charge gets payments from bank, a ch08_seeing_what_happened::Bank
the bank charges 40 for order A-1
log #4 step_succeeded charge
log #5 contribution_committed receipt
log #6 attempt_started ship
log #7 service_provided ship gets carrier from main_carrier, a ch08_seeing_what_happened::MainCarrier
the carrier books order A-1
the parcel leaves with receipt R-A-1
log #8 step_succeeded ship
log #9 contribution_committed tracking
log #10 journey_succeeded
the journey succeeded, with receipt R-A-1 and tracking T-A-1
Gil's order:
log #1 journey_started order, price, weight
log #2 attempt_started charge
log #3 service_provided charge gets payments from bank, a ch08_seeing_what_happened::Bank
the bank charges 45 for order A-7
log #4 step_succeeded charge
log #5 contribution_committed receipt
log #6 attempt_started ship
log #7 service_provided ship gets carrier from main_carrier, a ch08_seeing_what_happened::MainCarrier
the carrier books order A-7
log #8 step_failed ship: too-heavy
log #9 step_given_up ship
log #10 journey_failed ship
the journey failed, with receipt R-A-7 and tracking none

How it works

1. Every event says who decided what, and when. An event records one thing that happened, and who it came from. Some are facts: the journey started, an attempt of a step started, a service was provided, a contribution was committed, and the step's own outcome, which the step decided and returned, and which the executor records, as step_failed with too-heavy for Gil's shipping. Others are the executor's decisions about that outcome: step_given_up says it won't run the shipping again, and journey_failed that the journey failed because of it. Each event's number says when, in the journey's order, and its timestamp when on the clock.
2. The executor records which provider served which step. When a step asks for a service, the executor calls its provider, lends the service, and records service_provided, naming the step, the key, the provider and the implementation it made: ship gets carrier from main_carrier, a ch08_seeing_what_happened::MainCarrier. That is the name Rust gives the instance's type, its path included, which starts with the program's name; provide! kept it before the box hid it, for people to read rather than for code to match on. This fact says which tool a step got, never the service itself: like your data, a service never goes into an event.
3. Every journey reports the same stream. The events come in a fixed order and shape, whoever wrote the steps: a step's outcome, then what the executor decided about it. So one reporter reads every journey of every workflow the same way. This is one of the things Itinera is for: since every decision has its place, every decision is reported in the journey's events, naming who made it.
4. Every event carries the same fields. In Rust, an event is an Event: sequence, which numbers the journey's events from 1; a timestamp; the journey_id and the workflow it belongs to; and its body, which says what happened. event.kind() names its kind, such as step_failed. The log leaves out the timestamp and the journey ID, which change on every run.
5. What an event says is an enum. body is an EventBody, with one variant for each kind, holding what that kind carries, such as the step and the reason in StepFailed. EventBody is marked #[non_exhaustive], since later versions may add kinds, so the log's match ends with a _ arm, for every kind it says nothing more about.
6. The executor's events name your data, and never carry its value. journey_started lists order, price and weight, but not Ann's price, and contribution_committed names receipt, not the receipt. A step's reason is carried, since the step wrote it, as too-heavy is for Gil's shipping. The executor's events only say what happened to your data.
7. A reporter decides where events go. Its report receives each &Event and returns Result<(), Error>; the log always returns Ok(()). The workflow lists the reporters every journey gets, and each journey gets its own, made with Default, which is why Log derives it. A reporter only ever sees the events of its own journey.
8. Events are delivered as they happen. Each event reaches the log at once, before the journey goes on, so the log's lines and the bank's interleave in the order things happened.

But one line in Ann's output still comes from a println! in a step: "the parcel leaves with receipt R-A-1". Only the shipping knows the parcel left, and it says so outside the log, unnumbered and tied to no journey.

Outcomes

We have shown how a reporter sees who decided what in a journey, and when, as events.