notify router: deliveries log, dry-run hit counts, api and page

swarm-notify-router/src/main.rs

@@ -9,10 +9,15 @@
 //!
 //! A `request_reviewer` node is a request to swarm-controller, which holds the
 //! forge token (`swarm_wire::router_sink`). It is sent once, after the event's
-//! ops are queued and its snapshot is written, and the answer is only logged:
+//! ops are queued and its snapshot is written, and the answer is only logged and
+//! recorded:
 //! a controller that is down or slow must not hold up every agent's todos, and
 //! the next push asks again.
 //!
+//! Each delivery, made or failed, is a row of the deliveries log ([`log`]), and
+//! the router answers swarm-controller's requests for the newest rows and for a
+//! dry run of a flows document ([`api`], [`dry_run`]).
+//!
 //! Per issue it keeps a snapshot in its state bucket ([`event::Snapshot`]):
 //! the assignees it last saw and the agents it queued a todo for. An event is
 //! acked once its ops are queued and the snapshot is written, so a crash
@@ -32,14 +37,20 @@ use async_nats::jetstream::{self, consumer::pull, kv, message::PublishMessage};
 use futures_util::{StreamExt as _, TryStreamExt as _};
 use swarm_queue_client::{ClientSecret, QueueConfig};
 use swarm_secret_client::stored_secret::StoredSecret;
+use swarm_wire::router_api::Kind;
 use swarm_wire::router_sink::{self, Outcome, RequestReviewer};
 use swarm_wire::{forge_events, notify_router, router_todo};
 
+mod api;
+mod dry_run;
 mod event;
 mod flow;
+mod log;
 mod route;
 mod settle;
 mod stored;
+#[cfg(test)]
+mod test_nats;
 
 /// The cert-auth role this service logs in to the store as. `swarm-bao.nix`
 /// writes it, matching the leaf's subject.
@@ -93,6 +104,7 @@ async fn main() -> Result<()> {
     .await?;
 
     let mut router = Router::open(&queue).await?;
+    tokio::spawn(api::serve(queue.clone()));
     tracing::info!(
         stream = forge_events::STREAM,
         "notify router: routing forge events"
@@ -126,6 +138,9 @@ impl Router {
         swarm_queue_client::router_todo::open_or_create(queue)
             .await
             .context("opening the router todo stream")?;
+        log::open_or_create(&js)
+            .await
+            .context("opening the deliveries log stream")?;
         let events = events
             .create_consumer(pull::Config {
                 durable_name: Some(forge_events::ROUTER_CONSUMER.to_owned()),
@@ -199,8 +214,13 @@ impl Router {
         let routed = route::route(&event_type, &delivery, &snapshot, &self.flows.active, |a| {
             roster.contains(a)
         });
+        let cause = log::Cause {
+            event: event_type.clone(),
+            repo: delivery.repo.clone(),
+            number: u64::try_from(delivery.number).unwrap_or_default(),
+        };
         for action in &routed.actions {
-            self.queue(seq, action).await.map_err(Skip::Retry)?;
+            self.queue(seq, &cause, action).await.map_err(Skip::Retry)?;
         }
         if !routed.skipped.is_empty() {
             tracing::info!(%event_type, repo = %delivery.repo, number = delivery.number, skipped = ?routed.skipped, "notify router: recipients that are not agents got nothing");
@@ -210,14 +230,14 @@ impl Router {
             self.state.put(&key, bytes.into()).await.map_err(retry)?;
         }
         for request in &routed.requests {
-            self.request_review(request).await;
+            self.request_review(&cause, request).await;
         }
         Ok(())
     }
 
-    /// Ask swarm-controller for one review and log what it answered. One
-    /// attempt: nothing here fails the event.
-    async fn request_review(&self, request: &flow::ReviewRequest) {
+    /// Ask swarm-controller for one review, log what it answered and record
+    /// the delivery. One attempt: nothing here fails the event.
+    async fn request_review(&self, cause: &log::Cause, request: &flow::ReviewRequest) {
         let wire = RequestReviewer {
             repo: request.repo.clone(),
             number: request.number,
@@ -233,7 +253,7 @@ impl Router {
             request.number,
             &request.reviewer,
         );
-        match self
+        let result = match self
             .nats
             .send_request(router_sink::REQUEST_REVIEWER_SUBJECT, sent)
             .await
@@ -241,22 +261,46 @@ impl Router {
             Ok(reply) => match Outcome::decode(&String::from_utf8_lossy(&reply.payload)) {
                 Outcome::Requested => {
                     tracing::info!(%flow, %repo, number, %reviewer, "notify router: review requested");
+                    Ok("requested".to_owned())
                 }
                 Outcome::Skipped(why) => {
                     tracing::info!(%flow, %repo, number, %reviewer, %why, "notify router: review not requested");
+                    Ok(format!("skipped: {why}"))
                 }
                 Outcome::Error(why) => {
                     tracing::warn!(%flow, %repo, number, %reviewer, %why, "notify router: the controller could not request the review");
+                    Err(why)
                 }
             },
             Err(e) => {
                 tracing::warn!(%flow, %repo, number, %reviewer, error = %e, "notify router: no answer to a review request; not retried");
+                Err(format!("no answer: {e}"))
             }
-        }
+        };
+        let row = cause.row(flow, &request.node, Kind::RequestReviewer, reviewer, result);
+        log::append(&self.js, &row).await;
     }
 
-    /// Queue one op on its agent's subject and wait for the stream's ack.
-    async fn queue(&self, seq: u64, action: &flow::Action) -> Result<()> {
+    /// Queue one op on its agent's subject, wait for the stream's ack and
+    /// record the delivery, failed or not.
+    async fn queue(&self, seq: u64, cause: &log::Cause, action: &flow::Action) -> Result<()> {
+        let sent = self.publish(seq, action).await;
+        let result = match &sent {
+            Ok(()) => Ok(format!("{} {}", op_name(action.op.op), action.op.key)),
+            Err(e) => Err(format!("{e:#}")),
+        };
+        let row = cause.row(
+            &action.flow,
+            &action.node,
+            Kind::Todo,
+            &action.agent,
+            result,
+        );
+        log::append(&self.js, &row).await;
+        sent
+    }
+
+    async fn publish(&self, seq: u64, action: &flow::Action) -> Result<()> {
         let subject = router_todo::subject(&action.agent);
         let body = serde_json::to_vec(&action.op).expect("an op encodes");
         let id = format!("{seq}:{}:{}:{}", action.flow, action.node, action.agent);
@@ -319,6 +363,14 @@ fn retry(e: impl std::error::Error + Send + Sync + 'static) -> Skip {
     Skip::Retry(e.into())
 }
 
+/// The word the log uses for an op.
+const fn op_name(op: router_todo::Op) -> &'static str {
+    match op {
+        router_todo::Op::Upsert => "upsert",
+        router_todo::Op::Clear => "clear",
+    }
+}
+
 async fn client_secret(client_id: &str) -> Result<String> {
     use swarm_secret_client::builder::{ClientSecret, client_secret_path};
 
@@ -338,3 +390,148 @@ async fn client_secret(client_id: &str) -> Result<String> {
         ),
     }
 }
+
+#[cfg(test)]
+mod tests {
+    use swarm_wire::notify_flows::builtins;
+    use swarm_wire::router_api::Row;
+
+    use super::*;
+    use crate::test_nats::TestNats;
+
+    fn cause() -> log::Cause {
+        log::Cause {
+            event: "issue_assign".to_owned(),
+            repo: "o/r".to_owned(),
+            number: 9,
+        }
+    }
+
+    fn action() -> flow::Action {
+        let flow = builtins().remove(0);
+        let (agent, op) = (
+            "atlas".to_owned(),
+            router_todo::RouterTodoOp {
+                op: router_todo::Op::Upsert,
+                key: "forge:o/r#9:assignment".to_owned(),
+                prefix: false,
+                summary: "s".to_owned(),
+                source: "router:assigned".to_owned(),
+            },
+        );
+        flow::Action {
+            flow: flow.id,
+            node: "sink".to_owned(),
+            agent,
+            op,
+        }
+    }
+
+    fn review() -> flow::ReviewRequest {
+        flow::ReviewRequest {
+            flow: "head-classifier".to_owned(),
+            node: "request".to_owned(),
+            repo: "o/r".to_owned(),
+            number: 9,
+            reviewer: "review-classifier".to_owned(),
+        }
+    }
+
+    async fn rows(router: &Router) -> Vec<Row> {
+        log::recent(&router.js, 10).await.expect("the log")
+    }
+
+    /// A todo op that was queued is a row that went through; one the stream
+    /// would not take is a row with the error, and the delivery still fails.
+    #[tokio::test]
+    async fn a_queued_todo_is_a_row_and_a_failed_one_is_a_row_with_the_error() {
+        let nats = TestNats::start();
+        let client = nats.client().await;
+        let router = Router::open(&client).await.expect("opens");
+
+        router.queue(5, &cause(), &action()).await.expect("queued");
+        let [row] = &rows(&router).await[..] else {
+            panic!("one row")
+        };
+        assert!(row.ok, "{row:?}");
+        assert_eq!(
+            (row.flow.as_str(), row.node.as_str(), row.target.as_str()),
+            ("assigned", "sink", "atlas")
+        );
+        assert_eq!(
+            (row.event.as_str(), row.repo.as_str(), row.number),
+            ("issue_assign", "o/r", 9)
+        );
+        assert_eq!(row.kind, Kind::Todo);
+        assert_eq!(row.detail, "upsert forge:o/r#9:assignment");
+
+        router
+            .js
+            .delete_stream(router_todo::STREAM)
+            .await
+            .expect("deleted");
+        router
+            .queue(6, &cause(), &action())
+            .await
+            .expect_err("no stream takes it");
+        let rows = rows(&router).await;
+        assert_eq!(rows.len(), 2);
+        assert!(!rows[0].ok && !rows[0].detail.is_empty(), "{:?}", rows[0]);
+    }
+
+    /// Each answer the controller can give is a row: requested and skipped
+    /// went through, an error did not, and no answer at all did not either.
+    #[tokio::test]
+    async fn a_review_request_is_a_row_whatever_the_controller_answers() {
+        let nats = TestNats::start();
+        let client = nats.client().await;
+        let router = Router::open(&client).await.expect("opens");
+
+        // Nobody answers.
+        router.request_review(&cause(), &review()).await;
+        let first = rows(&router).await.remove(0);
+        assert!(
+            !first.ok && first.detail.starts_with("no answer"),
+            "{first:?}"
+        );
+        assert_eq!(first.kind, Kind::RequestReviewer);
+        assert_eq!(first.target, "review-classifier");
+
+        let mut hears = client
+            .subscribe(router_sink::REQUEST_REVIEWER_SUBJECT)
+            .await
+            .expect("subscribed");
+        let answering = client.clone();
+        tokio::spawn(async move {
+            for line in [
+                "requested",
+                "skipped:a review stands",
+                "error:the forge said no",
+            ] {
+                let m = hears.next().await.expect("a request");
+                answering
+                    .publish(m.reply.expect("a reply subject"), line.into())
+                    .await
+                    .expect("answered");
+            }
+        });
+        for _ in 0..3 {
+            router.request_review(&cause(), &review()).await;
+        }
+        let got: Vec<(bool, String)> = rows(&router)
+            .await
+            .into_iter()
+            .take(3)
+            .rev()
+            .map(|r| (r.ok, r.detail))
+            .collect();
+        assert_eq!(
+            got,
+            [
+                (true, "requested".to_owned()),
+                (true, "skipped: a review stands".to_owned()),
+                (false, "the forge said no".to_owned()),
+            ]
+        );
+    }
+}