DebugServ: stream live services activity to the log channel

A pseudo-client that joins the staff log channel and reports what the services
layer is doing in real time: authentication (IDENTIFY and every SASL mechanism,
success and failure, with nick/host/account/reason), sessions (forced logout),
and the account/channel/operator lifecycle — the committed-event audit now
speaks through it, falling back to a server notice when it is off.

The reporting lives in the engine (feed()/who() helpers plus hooks at
complete_authenticate / sasl_login / sasl_deny); the module itself is just the
bot's identity and a STATUS/HELP surface. On by default; the feed is gated on
the configured [log] channel.

Cargo.toml

@@ -18,6 +18,7 @@ members = [
     "modules/groupserv",
     "modules/chanfix",
     "modules/helpserv",
+    "modules/debugserv",
 ]
 
 [package]
@@ -44,6 +45,7 @@ echo-reportserv = { path = "modules/reportserv" }
 echo-groupserv = { path = "modules/groupserv" }
 echo-chanfix = { path = "modules/chanfix" }
 echo-helpserv = { path = "modules/helpserv" }
+echo-debugserv = { path = "modules/debugserv" }
 tokio = { version = "1", features = ["net", "io-util", "rt-multi-thread", "macros", "time", "sync", "process", "signal"] }
 serde = { version = "1", features = ["derive"] }
 serde_json = "1"

modules/debugserv/Cargo.toml

@@ -0,0 +1,8 @@
+[package]
+name = "echo-debugserv"
+version = "0.0.1"
+edition = "2021"
+description = "DebugServ: stream live services activity (auth, sessions, account/channel/oper events) to the staff log channel."
+
+[dependencies]
+echo-api = { path = "../../api" }

modules/debugserv/src/lib.rs

@@ -0,0 +1,61 @@
+//! DebugServ is the network's live observability feed. It sits in the staff log
+//! channel and reports what the services layer is doing in real time —
+//! authentication (IDENTIFY and every SASL mechanism, success and failure),
+//! sessions (logout, nick enforcement, ghosting), and the account / channel /
+//! operator lifecycle. The reporting itself lives in the engine (the only place
+//! that sees every event); this module is DebugServ's identity plus a small
+//! staff-facing command surface.
+//!
+//! Privacy note: the feed names who authenticates from where, so the log channel
+//! it speaks in must be restricted to staff.
+
+use echo_api::{help, HelpEntry, NetView, Priv, Sender, Service, ServiceCtx, Store};
+
+const BLURB: &str = "DebugServ streams live services activity — authentication, sessions, and the account/channel/operator lifecycle — to the staff log channel.";
+
+const TOPICS: &[HelpEntry] = &[
+    HelpEntry {
+        cmd: "STATUS",
+        summary: "what DebugServ is reporting",
+        detail: "Syntax: \x02STATUS\x02\nSummarises the live feed DebugServ streams to the staff log channel. Operators only.",
+    },
+];
+
+pub struct DebugServ {
+    pub uid: String,
+}
+
+impl Service for DebugServ {
+    fn nick(&self) -> &str {
+        "DebugServ"
+    }
+    fn uid(&self) -> &str {
+        &self.uid
+    }
+    fn gecos(&self) -> &str {
+        "Services Activity Feed"
+    }
+
+    fn help_topics(&self) -> (&'static str, &'static [HelpEntry]) {
+        (BLURB, TOPICS)
+    }
+
+    fn on_command(&mut self, from: &Sender, args: &[&str], ctx: &mut ServiceCtx, _net: &dyn NetView, _db: &mut dyn Store) {
+        let me = self.uid.as_str();
+        match args.first().copied() {
+            Some(cmd) if cmd.eq_ignore_ascii_case("STATUS") => {
+                if !from.privs.has(Priv::Auspex) && !from.privs.has(Priv::Admin) {
+                    ctx.notice(me, from.uid, "Access denied — DebugServ is a staff tool.");
+                    return;
+                }
+                ctx.notice(me, from.uid, "I stream live services activity to the staff log channel:");
+                ctx.notice(me, from.uid, "  \x02AUTH\x02  — every IDENTIFY / SASL login attempt, success and failure");
+                ctx.notice(me, from.uid, "  \x02SESS\x02  — logout, nick enforcement, ghosting");
+                ctx.notice(me, from.uid, "  \x02ACCT/CHAN/OPER\x02 — account, channel, and enforcement changes");
+            }
+            Some(cmd) if cmd.eq_ignore_ascii_case("HELP") => help(me, from, ctx, BLURB, TOPICS, args.get(1).copied()),
+            None => help(me, from, ctx, BLURB, TOPICS, None),
+            Some(other) => ctx.notice(me, from.uid, format!("I don't take commands other than \x02STATUS\x02 or \x02HELP\x02 — I just report. ({other} ignored.)")),
+        }
+    }
+}

src/config.rs

@@ -138,7 +138,7 @@ impl Default for Modules {
 fn default_services() -> Vec<String> {
     [
         "nickserv", "chanserv", "botserv", "hostserv", "memoserv", "operserv", "statserv",
-        "groupserv", "infoserv", "reportserv", "helpserv", "chanfix", "diceserv",
+        "groupserv", "infoserv", "reportserv", "helpserv", "chanfix", "diceserv", "debugserv",
     ]
     .iter()
     .map(|s| s.to_string())

src/engine/mod.rs

@@ -131,6 +131,10 @@ pub struct Engine {
     // Staff audit channel: notable service actions are announced here. None =
     // no audit feed.
     log_channel: Option<String>,
+    // DebugServ's uid, when that module is enabled — the live activity feed
+    // (auth, sessions, lifecycle) speaks as it. Empty = DebugServ isn't running,
+    // and the committed-event feed falls back to a server notice.
+    debugserv_uid: String,
     // Inactivity-expiry thresholds in seconds. None = that kind never expires.
     account_ttl: Option<u64>,
     channel_ttl: Option<u64>,
@@ -244,6 +248,7 @@ impl Engine {
             pending_unbans: Vec::new(),
             votes: HashMap::new(),
             log_channel: None,
+            debugserv_uid: String::new(),
             account_ttl: None,
             channel_ttl: None,
             expire_warn: None,
@@ -327,6 +332,37 @@ impl Engine {
         self.log_channel = channel;
     }
 
+    // DebugServ's uid — the live activity feed is sent as PRIVMSGs from it into
+    // the log channel. Set from main.rs when the module is enabled.
+    pub fn set_debugserv_uid(&mut self, uid: impl Into<String>) {
+        self.debugserv_uid = uid.into();
+    }
+
+    // Build a DebugServ feed line for the log channel, or None when DebugServ
+    // isn't running (no uid) / there's no log channel / we're not linked yet.
+    // `cat` is a short category tag (AUTH, SESS, ACCT, CHAN, OPER, NET).
+    fn feed(&self, cat: &str, text: String) -> Option<NetAction> {
+        let channel = self.log_channel.as_deref()?;
+        if self.debugserv_uid.is_empty() || self.sid.is_empty() {
+            return None;
+        }
+        Some(NetAction::Privmsg {
+            from: self.debugserv_uid.clone(),
+            to: channel.to_string(),
+            text: format!("\x02[{cat}]\x02 {text}"),
+        })
+    }
+
+    // "nick (host)" for a live uid, for the feed — the host makes an auth line
+    // actionable (where did this login come from). Falls back gracefully.
+    fn who(&self, uid: &str) -> String {
+        let nick = self.network.nick_of(uid).unwrap_or("?");
+        match self.network.host_of(uid) {
+            Some(host) => format!("\x02{nick}\x02 ({host})"),
+            None => format!("\x02{nick}\x02"),
+        }
+    }
+
     // Inactivity-expiry thresholds (seconds); None leaves that kind never
     // expiring. `warn` is the lead time before expiry to email a warning (None =
     // no warning emails).
@@ -412,11 +448,23 @@ impl Engine {
     }
 
     // Finish a SASL login, unless the account is suspended.
-    fn sasl_login(&self, agent: &str, client: &str, account: String) -> Vec<NetAction> {
+    fn sasl_login(&self, mech: &str, agent: &str, client: &str, account: String) -> Vec<NetAction> {
         if self.db.is_suspended(&account) {
-            return sasl_fail(agent, client);
+            let mut out = sasl_fail(agent, client);
+            out.extend(self.feed("AUTH", format!("\x0304✗\x03 {} — {mech} rejected for \x02{account}\x02 (account suspended)", self.who(client))));
+            return out;
         }
-        sasl_success(agent, client, account)
+        let mut out = sasl_success(agent, client, account.clone());
+        out.extend(self.feed("AUTH", format!("\x0303✓\x03 {} authenticated as \x02{account}\x02 via {mech}", self.who(client))));
+        out
+    }
+
+    // A SASL rejection plus a DebugServ line naming why — for the credential
+    // failures worth surfacing (bad password, bad/unknown cert, unknown account).
+    fn sasl_deny(&self, mech: &str, agent: &str, client: &str, reason: &str) -> Vec<NetAction> {
+        let mut out = sasl_fail(agent, client);
+        out.extend(self.feed("AUTH", format!("\x0304✗\x03 {} — {mech} failed ({reason})", self.who(client))));
+        out
     }
 
     // The login side-effects — auto-join, vhost, and a waiting-memo notice — for a
@@ -563,6 +611,9 @@ impl Engine {
 
     // Log a single session out of `account`, telling them why (services-sourced).
     fn logout_uid(&mut self, uid: &str, account: &str, reason: &str) {
+        if let Some(action) = self.feed("SESS", format!("{} logged out of \x02{account}\x02 ({reason})", self.who(uid))) {
+            self.emit_irc(action);
+        }
         self.network.clear_account(uid);
         self.emit_irc(NetAction::Metadata { target: uid.to_string(), key: "accountname".to_string(), value: String::new() });
         if let Some(ns) = self.nick_service.clone() {
@@ -748,7 +799,10 @@ impl Engine {
     fn audit(&mut self, text: String) {
         let now = self.now_secs();
         self.network.record_incident(text.clone(), now);
-        if let (Some(channel), false) = (&self.log_channel, self.sid.is_empty()) {
+        // Prefer DebugServ's voice; fall back to a server notice when it's off.
+        if let Some(action) = self.feed("SVC", text.clone()) {
+            self.emit_irc(action);
+        } else if let (Some(channel), false) = (&self.log_channel, self.sid.is_empty()) {
             self.emit_irc(NetAction::Notice { from: self.sid.clone(), to: channel.clone(), text });
         }
     }
@@ -825,6 +879,11 @@ impl Engine {
         // clients in CAP LS (IRCv3 SASL 3.2).
         // Introduce the registered bots too.
         out.extend(self.reconcile_bots());
+        // DebugServ joins the log channel so its live feed lands there — it must be
+        // a member to speak, unlike the server-sourced audit notice.
+        if let (false, Some(chan)) = (self.debugserv_uid.is_empty(), self.log_channel.clone()) {
+            out.push(NetAction::ServiceJoin { uid: self.debugserv_uid.clone(), channel: chan });
+        }
         // Re-assert the network bans over the fresh link, each with its remaining
         // duration so the ircd expires it at the right time (permanent = 0).
         let now = self.now_secs();
@@ -1216,8 +1275,10 @@ impl Engine {
     // configured — announce each to it, sourced from the services server. Private
     // and purely cosmetic events are deliberately not surfaced.
     fn audit_feed(&mut self, mark: usize, nick: &str, account: Option<&str>) -> Vec<NetAction> {
-        let summaries: Vec<String> = self.db.events_since(mark).iter().filter_map(audit_summary).collect();
+        let tagged: Vec<(&'static str, String)> = self.db.events_since(mark).iter()
-        if summaries.is_empty() {
+            .filter_map(|e| audit_summary(e).map(|s| (event_category(e), s)))
+            .collect();
+        if tagged.is_empty() {
             return Vec::new();
         }
         // Name the actor by nick, plus the account they are identified to when it
@@ -1228,11 +1289,15 @@ impl Engine {
         };
         let now = self.now_secs();
         let mut out = Vec::new();
-        for summary in summaries {
+        for (cat, summary) in tagged {
             let line = format!("{actor} {summary}");
             self.network.record_incident(line.clone(), now);
-            if let (Some(channel), false) = (&self.log_channel, self.sid.is_empty()) {
+            // Prefer DebugServ's voice; fall back to a server notice when it's off.
-                out.push(NetAction::Notice { from: self.sid.clone(), to: channel.clone(), text: line });
+            match self.feed(cat, line.clone()) {
+                Some(action) => out.push(action),
+                None => if let (Some(channel), false) = (&self.log_channel, self.sid.is_empty()) {
+                    out.push(NetAction::Notice { from: self.sid.clone(), to: channel.clone(), text: line });
+                },
             }
         }
         out
@@ -1282,6 +1347,26 @@ fn human_duration(secs: u64) -> String {
     }
 }
 
+// A coarse category tag for the DebugServ feed, sorting committed events into
+// account, channel, or operator/enforcement lanes (the catch-all). Purely
+// cosmetic — a miscategorised line is harmless.
+fn event_category(event: &db::Event) -> &'static str {
+    use db::Event::*;
+    match event {
+        AccountRegistered(_) | AccountDropped { .. } | AccountVerified { .. }
+        | AccountPasswordSet { .. } | AccountEmailSet { .. } | CertAdded { .. }
+        | CertRemoved { .. } | AccountSuspended { .. } | AccountUnsuspended { .. }
+        | NickGrouped { .. } | NickUngrouped { .. } | VhostSet { .. } | VhostDeleted { .. }
+        | AccountOperNoteSet { .. } => "ACCT",
+        ChannelRegistered { .. } | ChannelDropped { .. } | ChannelFounderSet { .. }
+        | ChannelSuccessorSet { .. } | ChannelAccessAdd { .. } | ChannelAccessDel { .. }
+        | ChannelAkickAdd { .. } | ChannelAkickDel { .. } | ChannelSuspended { .. }
+        | ChannelUnsuspended { .. } | ChannelBotAssigned { .. } | ChannelBotUnassigned { .. }
+        | ChannelOperNoteSet { .. } => "CHAN",
+        _ => "OPER",
+    }
+}
+
 // A one-line, human-readable summary of a logged event for the staff audit
 // feed, or None for events that are private (memos), cosmetic self-service
 // (greets, auto-join, personal settings), or otherwise not worth surfacing.

src/engine/register.rs

@@ -304,13 +304,20 @@ impl Engine {
                 for key in std::mem::take(&mut ctx.stats) {
                     self.bump(&key);
                 }
-                ctx.actions
+                let feed = if ok {
+                    self.feed("AUTH", format!("\x0303✓\x03 {} identified to \x02{account}\x02 via IDENTIFY", self.who(&uid)))
+                } else {
+                    self.feed("AUTH", format!("\x0304✗\x03 {} — IDENTIFY failed for \x02{name}\x02 (bad password)", self.who(&uid)))
+                };
+                let mut actions = ctx.actions;
+                actions.extend(feed);
+                actions
             }
             AuthThen::Sasl { agent, client, account } => {
                 if ok {
-                    self.sasl_login(&agent, &client, account)
+                    self.sasl_login("SASL PLAIN", &agent, &client, account)
                 } else {
-                    sasl_fail(&agent, &client)
+                    self.sasl_deny("SASL PLAIN", &agent, &client, "bad password")
                 }
             }
         }

src/engine/sasl.rs

@@ -131,7 +131,7 @@ impl Engine {
                 }
             }
             // Client acknowledged our server-final ("+"); apply the login.
-            ScramStep::Ack { account } => self.sasl_login(agent, client, account),
+            ScramStep::Ack { account } => self.sasl_login(&format!("SASL {}", hash.mech()), agent, client, account),
         }
     }
 
@@ -144,15 +144,15 @@ impl Engine {
         } else {
             match STANDARD.decode(chunk).ok().and_then(|b| String::from_utf8(b).ok()) {
                 Some(a) => a,
-                None => return sasl_fail(agent, client),
+                None => return self.sasl_deny("SASL EXTERNAL", agent, client, "malformed authzid"),
             }
         };
         match fingerprints.iter().find_map(|fp| self.db.certfp_owner(fp)) {
             Some(account) if authzid.is_empty() || authzid.eq_ignore_ascii_case(account) => {
                 let account = account.to_string();
-                self.sasl_login(agent, client, account)
+                self.sasl_login("SASL EXTERNAL", agent, client, account)
             }
-            _ => sasl_fail(agent, client),
+            _ => self.sasl_deny("SASL EXTERNAL", agent, client, "unknown certificate"),
         }
     }
 }

src/engine/tests.rs

@@ -43,6 +43,44 @@
         assert!(is_success(&out), "{out:?}");
     }
 
+    // DebugServ streams auth outcomes into the log channel, and stays silent when
+    // it isn't running.
+    #[test]
+    fn debugserv_feeds_auth_events() {
+        let mut e = engine_with("dbgfeed", "foo", "sesame");
+        e.set_sid("42S".into());
+        e.set_log_channel(Some("#services".into()));
+        e.set_debugserv_uid("42SAAAAAO");
+        e.handle(NetEvent::UserConnect { uid: "000AAAAAB".into(), nick: "foo".into(), host: "host.example".into(), ip: "0.0.0.0".into() });
+
+        sasl(&mut e, "S", "PLAIN");
+        let ok = sasl(&mut e, "C", &plain(b"", b"foo", b"sesame"));
+        assert!(is_success(&ok), "login should still work: {ok:?}");
+        assert!(
+            ok.iter().any(|a| matches!(a, NetAction::Privmsg { from, to, text }
+                if from == "42SAAAAAO" && to == "#services" && text.contains("[AUTH]") && text.contains("SASL PLAIN"))),
+            "expected an AUTH feed line from DebugServ, got {ok:?}"
+        );
+
+        sasl(&mut e, "S", "PLAIN");
+        let bad = sasl(&mut e, "C", &plain(b"", b"foo", b"wrongpass"));
+        assert!(!is_success(&bad), "wrong password must not log in: {bad:?}");
+        assert!(
+            bad.iter().any(|a| matches!(a, NetAction::Privmsg { from, text, .. }
+                if from == "42SAAAAAO" && text.contains("[AUTH]") && text.contains("bad password"))),
+            "expected an AUTH failure line, got {bad:?}"
+        );
+
+        // Disabled (no uid) -> the feed is silent.
+        e.set_debugserv_uid("");
+        sasl(&mut e, "S", "PLAIN");
+        let quiet = sasl(&mut e, "C", &plain(b"", b"foo", b"sesame"));
+        assert!(
+            !quiet.iter().any(|a| matches!(a, NetAction::Privmsg { to, .. } if to == "#services")),
+            "no feed line when DebugServ is off: {quiet:?}"
+        );
+    }
+
     // A response that is not a multiple of 400 splits into 400 + remainder.
     #[test]
     fn plain_chunked_412() {

src/main.rs

@@ -31,6 +31,7 @@ use echo_helpserv::HelpServ;
 use echo_example::ExampleServ;
 use echo_inspircd::InspIrcd;
 use echo_nickserv::NickServ;
+use echo_debugserv::DebugServ;
 
 #[tokio::main]
 async fn main() -> Result<()> {
@@ -154,6 +155,11 @@ async fn main() -> Result<()> {
             uid: format!("{}AAAAAN", cfg.server.sid),
         }));
     }
+    if enabled("debugserv") {
+        services.push(Box::new(DebugServ {
+            uid: format!("{}AAAAAO", cfg.server.sid),
+        }));
+    }
     if enabled("example") {
         services.push(Box::new(ExampleServ {
             uid: format!("{}AAAAAC", cfg.server.sid),
@@ -182,6 +188,10 @@ async fn main() -> Result<()> {
     let service_host = if cfg.server.service_host.is_empty() { &cfg.server.name } else { &cfg.server.service_host };
     engine.lock().await.set_service_host(service_host);
     engine.lock().await.set_log_channel(cfg.log.as_ref().map(|l| l.channel.clone()));
+    if enabled("debugserv") {
+        // DebugServ speaks the live feed into the log channel; give the engine its uid.
+        engine.lock().await.set_debugserv_uid(format!("{}AAAAAO", cfg.server.sid));
+    }
     if let Some(expire) = &cfg.expire {
         engine.lock().await.set_expiry(expire.account_ttl(), expire.channel_ttl(), expire.warn_ttl());
     }