MGS: Add usdt probes for receiving messages (#799)

Author: jgallagher

Cargo.lock

@@ -9,6 +9,7 @@ futures = "0.3.21"
 ringbuffer = "0.8"
 serde = { version = "1.0", features = ["derive"] }
 thiserror = "1.0.30"
+usdt = "0.3.1"
 uuid = "0.8"
 
 gateway-messages = { path = "../gateway-messages", features = ["std"] }

gateway-sp-comms/Cargo.toml

@@ -0,0 +1,44 @@
+# `gateway-sp-comms`
+
+Communicate with SPs across the management network.
+
+## DTrace Probes
+
+This crate currently provides three DTrace probes: receiving raw packets,
+receiving responses to requests, receiving serial console messages.
+
+Raw packets:
+
+```
+% sudo dtrace -n 'gateway_sp_comms*:::recv_packet { printf("%s, %s", copyinstr(arg0), copyinstr(arg1)); tracemem(copyin(arg2, arg3), 128, arg3); }'
+dtrace: description 'gateway_sp_comms*:::recv_packet ' matched 1 probe
+CPU     ID                    FUNCTION:NAME
+  6   2961 _ZN16gateway_sp_comms17management_switch9recv_task28_$u7b$$u7b$closure$u7d$$u7d$17h2bdb4a0aa5dcced5E:recv_packet {"ok":"127.0.0.1:23457"}, {"ok":1}
+             0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f  0123456789abcdef
+         0: 01 00 00 00 01 73 70 33 00 00 00 00 00 00 00 00  .....sp3........
+        10: 00 00 00 00 00 24 00 00 00 00 00 00 00 06 00 68  .....$.........h
+        20: 65 6c 6c 6f 0a                                   ello.
+```
+
+Responses:
+
+```
+% sudo dtrace -n 'gateway_sp_comms*:::recv_response { printf("%s, %u, %s", copyinstr(arg0), arg1, copyinstr(arg2)); }'
+dtrace: description 'gateway_sp_comms*:::recv_response ' matched 1 probe
+CPU     ID                    FUNCTION:NAME
+  5   2962 _ZN16gateway_sp_comms12recv_handler11RecvHandler15handle_response17h28a3ce4546c4e1bdE:recv_response {"ok":0}, 0, {"ok":{"Ok":{"IgnitionState":{"id":17,"flags":{"bits":3}}}}}
+  2   2962 _ZN16gateway_sp_comms12recv_handler11RecvHandler15handle_response17h28a3ce4546c4e1bdE:recv_response {"ok":1}, 1, {"ok":{"Ok":{"SpState":{"serial_number":[0,0,0,0,1,1,1,1,2,2,2,2,3,3,3,3]}}}}
+```
+
+Serial console messages:
+
+```
+% sudo dtrace -n 'gateway_sp_comms*:::recv_serial_console { printf("%u, %s, %u", arg0, copyinstr(arg0), arg2); tracemem(copyin(arg3, arg4), 128, arg4); }'
+dtrace: description 'gateway_sp_comms*:::recv_serial_console ' matched 1 probe
+CPU     ID                    FUNCTION:NAME
+  2   2963 _ZN16gateway_sp_comms12recv_handler11RecvHandler21handle_serial_console17hba2bd6ac4422e295E:recv_serial_console 105553180037200, {"ok":1}, 42
+             0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f  0123456789abcdef
+         0: 68 65 6c 6c 6f 21 0a                             hello!.
+```
+
+TODO EXPAND

gateway-sp-comms/README.md

@@ -4,6 +4,10 @@
 
 // Copyright 2022 Oxide Computer Company
 
+// Required nightly features for `usdt`
+#![cfg_attr(target_os = "macos", feature(asm_sym))]
+#![feature(asm)]
+
 //! This crate provides UDP-based communication across the Oxide management
 //! switch to a collection of SPs.
 //!
@@ -13,6 +17,8 @@ mod communicator;
 mod management_switch;
 mod recv_handler;
 
+pub use usdt::register_probes;
+
 pub mod error;
 
 pub use communicator::Communicator;

gateway-sp-comms/src/lib.rs

@@ -61,7 +61,13 @@ pub enum SpType {
     Power,
 }
 
-#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash)]
+// We derive `Serialize` to be able to send `SwitchPort`s to usdt probes, but
+// critically we do _not_ implement `Deserialize` - the only way to construct a
+// `SwitchPort` should be to receive one from a `ManagementSwitch`.
+#[derive(
+    Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash, Serialize,
+)]
+#[serde(transparent)]
 pub(crate) struct SwitchPort(usize);
 
 impl SwitchPort {
@@ -359,6 +365,13 @@ where
 
         match sock.try_recv_from(&mut buf) {
             Ok((n, addr)) => {
+                let buf = &buf[..n];
+                probes::recv_packet!(|| (
+                    &addr,
+                    &port,
+                    buf.as_ptr() as usize as u64,
+                    buf.len() as u64
+                ));
                 if Some(addr) != inner.sp_socket(port).map(|s| s.addr) {
                     // TODO-security: we received a packet from an address that
                     // doesn't match what we believe is the SP's address. for
@@ -371,7 +384,7 @@ where
                     );
                 } else {
                     debug!(inner.log, "received {} bytes", n; "port" => ?port);
-                    callback(port, &buf[..n]);
+                    callback(port, buf);
                 }
             }
             // spurious wakeup; no need to log, just continue
@@ -582,3 +595,14 @@ mod tests {
         }
     }
 }
+
+#[usdt::provider(provider = "gateway_sp_comms")]
+mod probes {
+    fn recv_packet(
+        _source: &SocketAddr,
+        _port: &SwitchPort,
+        _data: u64, // TODO actually a `*const u8`, but that isn't allowed by usdt
+        _len: u64,
+    ) {
+    }
+}

gateway-sp-comms/src/management_switch.rs

@@ -184,6 +184,7 @@ impl RecvHandler {
         request_id: u32,
         result: Result<ResponseKind, ResponseError>,
     ) {
+        probes::recv_response!(|| (&port, request_id, &result));
         match self.sp_state(port).requests.ingest_response(&request_id, result)
         {
             ResponseIngestResult::Ok => (),
@@ -199,6 +200,13 @@ impl RecvHandler {
     }
 
     fn handle_serial_console(&self, port: SwitchPort, packet: SerialConsole) {
+        probes::recv_serial_console!(|| (
+            &port,
+            &packet.component,
+            packet.offset,
+            packet.data.as_ptr() as usize as u64,
+            u64::from(packet.len)
+        ));
         debug!(
             &self.log,
             "received serial console data from {:?}: {:?}", port, packet
@@ -216,3 +224,22 @@ struct SingleSpState {
     requests: RequestResponseMap<u32, Result<ResponseKind, ResponseError>>,
     serial_console: Mutex<SerialConsoleHistory>,
 }
+
+#[usdt::provider(provider = "gateway_sp_comms")]
+mod probes {
+    fn recv_response(
+        _port: &SwitchPort,
+        _request_id: u32,
+        _result: &Result<ResponseKind, ResponseError>,
+    ) {
+    }
+
+    fn recv_serial_console(
+        _port: &SwitchPort,
+        _component: &SpComponent,
+        _offset: u64,
+        _data: u64, // TODO actually a `*const u8`, but that isn't allowed by usdt
+        _len: u64,
+    ) {
+    }
+}

gateway-sp-comms/src/recv_handler/mod.rs

@@ -12,7 +12,7 @@ pub mod http_entrypoints; // TODO pub only for testing - is this right?
 pub use config::Config;
 pub use context::ServerContext;
 
-use slog::{debug, error, info, o, Logger};
+use slog::{debug, error, info, o, warn, Logger};
 use std::sync::Arc;
 use uuid::Uuid;
 
@@ -45,6 +45,13 @@ impl Server {
         let log = log.new(o!("name" => config.id.to_string()));
         info!(log, "setting up gateway server");
 
+        match gateway_sp_comms::register_probes() {
+            Ok(_) => debug!(log, "successfully registered DTrace USDT probes"),
+            Err(err) => {
+                warn!(log, "failed to register DTrace USDT probes: {}", err);
+            }
+        }
+
         let apictx =
             ServerContext::new(config, &log).await.map_err(|error| {
                 format!("initializing server context: {}", error)

gateway/src/lib.rs

@@ -224,10 +224,14 @@ impl SerialConsoleTcpTask {
                                 break;
                             }
                         };
+                        if n == 0 {
+                            error!(self.log, "closing serial console TCP connection (read 0 bytes)");
+                            break;
+                        }
                         match self.send_serial_console(&buf[..n]).await {
                             Ok(()) => (),
                             Err(err) => {
-                                error!(self.log, "ignoring UDP send failure {}", err);
+                                error!(self.log, "ignoring UDP send ({} bytes) failure {}", n, err);
                                 continue;
                             }
                         }