Add auth{n,z} USDT probes to Nexus

nexus/auth/Cargo.toml

@@ -33,6 +33,7 @@ slog.workspace = true
 strum.workspace = true
 thiserror.workspace = true
 tokio = { workspace = true, features = ["full"] }
+usdt.workspace = true
 uuid.workspace = true
 
 authz-macros.workspace = true

nexus/auth/src/authn/external/mod.rs

@@ -7,6 +7,7 @@
 use super::Details;
 use super::SiloAuthnPolicy;
 use crate::authn;
+use crate::probes;
 use async_trait::async_trait;
 use authn::Reason;
 use slog::trace;
@@ -72,8 +73,18 @@ where
         for scheme_impl in &self.allowed_schemes {
             let scheme_name = scheme_impl.name();
             trace!(log, "authn: trying {:?}", scheme_name);
+            let id = usdt::UniqueId::new();
+            probes::authn__start!(|| {
+                (
+                    &id,
+                    scheme_name.to_string(),
+                    request.method().to_string(),
+                    request.uri().to_string(),
+                )
+            });
             schemes_tried.push(scheme_name);
             let result = scheme_impl.authn(ctx, log, request).await;
+            probes::authn__done!(|| (id, format!("{result:?}")));
             match result {
                 // TODO-security If the user explicitly failed one
                 // authentication scheme (i.e., a signature that didn't match,

nexus/auth/src/context.rs

@@ -8,6 +8,7 @@ use super::authz;
 use crate::authn::ConsoleSessionWithSiloId;
 use crate::authn::external::session_cookie::Session;
 use crate::authz::AuthorizedResource;
+use crate::probes;
 use crate::storage::Storage;
 use chrono::{DateTime, Utc};
 use omicron_common::api::external::Error;
@@ -275,7 +276,17 @@ impl OpContext {
             "action" => ?action,
             "resource" => ?*resource
         );
+        let id = usdt::UniqueId::new();
+        probes::authz__start!(|| {
+            (
+                &id,
+                format!("{:?}", self.authn.actor()),
+                format!("{action:?}"),
+                format!("{resource:?}"),
+            )
+        });
         let result = self.authz.authorize(self, action, resource.clone()).await;
+        probes::authz__done!(|| (&id, format!("{result:?}")));
         debug!(self.log, "authorize result";
             "actor" => ?self.authn.actor(),
             "action" => ?action,

nexus/auth/src/lib.rs

@@ -9,3 +9,31 @@ extern crate newtype_derive;
 #[allow(unused_imports)]
 #[macro_use]
 extern crate slog;
+
+#[usdt::provider(provider = "nexus")]
+mod probes {
+    /// Fires just before attempting to authenticate a request using the given
+    /// scheme.
+    fn authn__start(
+        id: &usdt::UniqueId,
+        scheme: &str,
+        method: &str,
+        uri: &str,
+    ) {
+    }
+
+    /// Fires just after completing the authentication, with the result.
+    fn authn__done(id: &usdt::UniqueId, result: &str) {}
+
+    /// Fires just before attempting to authorize an action on a resource.
+    fn authz__start(
+        id: &usdt::UniqueId,
+        actor: &str,
+        action: &str,
+        resource: &str,
+    ) {
+    }
+
+    /// Fires just after completing an authorization check on a resource.
+    fn authz__done(id: &usdt::UniqueId, result: &str) {}
+}

tools/dtrace/nexus/trace-authn.d

@@ -0,0 +1,41 @@
+#!/usr/sbin/dtrace -qZs
+
+/*
+ * This script prints the result of every authentication request. It
+ * includes the scheme, method, URI, duration, and the result of the
+ * authn attempt. Here is an example of the output:
+ * 
+ * scheme=spoof method=POST URI=/v1/system/ip-pools/default/silos result=Authenticated(Details { actor: Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. } }) duration=23961us
+ * scheme=spoof method=POST URI=/v1/projects result=Authenticated(Details { actor: Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. } }) duration=31087us
+ * scheme=spoof method=DELETE URI=/v1/disks/disky-mcdiskface?project=springfield-squidport result=Authenticated(Details { actor: Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. } }) duration=1033288us
+ * scheme=spoof method=POST URI=/v1/instances?project=carcosa result=Authenticated(Details { actor: Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. } }) duration=14631us
+ * scheme=spoof method=POST URI=/v1/disks?project=springfield-squidport result=Authenticated(Details { actor: Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. } }) duration=25946us
+ */
+
+#pragma D option strsize=4k
+
+nexus*:::authn-start
+{
+        ts[arg0] = timestamp;
+        schemes[arg0] = copyinstr(arg1);
+        methods[arg0] = copyinstr(arg2);
+        uris[arg0] = copyinstr(arg3);
+}
+
+nexus*:::authn-done
+/ts[arg0]/
+{
+        this->t = (timestamp - ts[arg0]) / 1000;
+        printf(
+            "scheme=%s method=%s URI=%s result=%s duration=%dus\n",
+            schemes[arg0],
+            methods[arg0],
+            uris[arg0],
+            copyinstr(arg1),
+            this->t
+        );
+        ts[arg0] = 0;
+        schemes[arg0] = 0;
+        methods[arg0] = 0;
+        uris[arg0] = 0;
+}

tools/dtrace/nexus/trace-authz.d

@@ -0,0 +1,41 @@
+#!/usr/sbin/dtrace -qZs
+
+/*
+ * This script prints the result of every authorization request. It
+ * includes the actor, action, and resource, along with the duration
+ * and result of the authz attempt. Here is an example of the output:
+ *
+ * actor=Some(Actor::SiloUser { silo_user_id: 8b0bc366-958e-43af-a35c-8cb6867a6939, silo_id: 37ab44ad-213c-482d-acf4-98e6a978199d, .. }) action=Query resource=Database result=Ok(()) duration=1351us
+ * actor=Some(Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. }) action=Query resource=Database result=Ok(()) duration=657us
+ * actor=Some(Actor::SiloUser { silo_user_id: 001de000-05e4-4000-8000-000000004007, silo_id: 001de000-5110-4000-8000-000000000000, .. }) action=Query resource=Database result=Ok(()) duration=1640us
+ * actor=Some(Actor::UserBuiltin { user_builtin_id: 001de000-05e4-4000-8000-000000000002, .. }) action=Read resource=DnsConfig result=Ok(()) duration=12268us
+ *
+ */
+
+#pragma D option strsize=4k
+
+nexus*:::authz-start
+{
+        ts[arg0] = timestamp;
+        actors[arg0] = copyinstr(arg1);
+        actions[arg0] = copyinstr(arg2);
+        resources[arg0] = copyinstr(arg3);
+}
+
+nexus*:::authz-done
+/ts[arg0]/
+{
+        t = (timestamp - ts[arg0]);
+        printf(
+            "actor=%s action=%s resource=%s result=%s duration=%dus\n",
+            actors[arg0],
+            actions[arg0],
+            resources[arg0],
+            copyinstr(arg1),
+            t / 1000
+        );
+        ts[arg0] = 0;
+        actors[arg0] = 0;
+        actions[arg0] = 0;
+        resources[arg0] = 0;
+}