feat: hook in runtime logs (#568)

* feat: simple wasm log to send over unix socket * feat: hook up logs subscription * refactor: extra comments * refactor: simpler interface * refactor: combine JsonVisitors * refactor: clippy suggestions * refactor: update tests * refactor: extra comment * refactor: increase channel for better performance * refactor: move off stderr
shuttle-hq · Jan 10, 2023 · 5b033d0 · 5b033d0
1 parent 8324824
commit 5b033d0
Show file tree

Hide file tree

Showing 15 changed files with 640 additions and 159 deletions.
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/codegen/src/next/mod.rs b/codegen/src/next/mod.rs
@@ -262,26 +262,36 @@ pub(crate) fn wasi_bindings(app: App) -> proc_macro2::TokenStream {
         #[no_mangle]
         #[allow(non_snake_case)]
         pub extern "C" fn __SHUTTLE_Axum_call(
-            fd_3: std::os::wasi::prelude::RawFd,
-            fd_4: std::os::wasi::prelude::RawFd,
-            fd_5: std::os::wasi::prelude::RawFd,
+            logs_fd: std::os::wasi::prelude::RawFd,
+            parts_fd: std::os::wasi::prelude::RawFd,
+            body_read_fd: std::os::wasi::prelude::RawFd,
+            body_write_fd: std::os::wasi::prelude::RawFd,
         ) {
             use axum::body::HttpBody;
+            use shuttle_common::wasm::Logger;
             use std::io::{Read, Write};
             use std::os::wasi::io::FromRawFd;
+            use tracing_subscriber::prelude::*;
 
-            println!("inner handler awoken; interacting with fd={},{},{}", fd_3, fd_4, fd_5);
+            println!("inner handler awoken; interacting with fd={},{},{},{}", logs_fd, parts_fd, body_read_fd, body_write_fd);
+
+            // file descriptor 2 for writing logs to
+            let logs_fd = unsafe { std::fs::File::from_raw_fd(logs_fd) };
+
+            tracing_subscriber::registry()
+                .with(Logger::new(logs_fd))
+                .init(); // this sets the subscriber as the global default and also adds a compatibility layer for capturing `log::Record`s
 
             // file descriptor 3 for reading and writing http parts
-            let mut parts_fd = unsafe { std::fs::File::from_raw_fd(fd_3) };
+            let mut parts_fd = unsafe { std::fs::File::from_raw_fd(parts_fd) };
 
             let reader = std::io::BufReader::new(&mut parts_fd);
 
             // deserialize request parts from rust messagepack
             let wrapper: shuttle_common::wasm::RequestWrapper = rmp_serde::from_read(reader).unwrap();
 
             // file descriptor 4 for reading http body into wasm
-            let mut body_read_stream = unsafe { std::fs::File::from_raw_fd(fd_4) };
+            let mut body_read_stream = unsafe { std::fs::File::from_raw_fd(body_read_fd) };
 
             let mut reader = std::io::BufReader::new(&mut body_read_stream);
             let mut body_buf = Vec::new();
@@ -306,7 +316,7 @@ pub(crate) fn wasi_bindings(app: App) -> proc_macro2::TokenStream {
             parts_fd.write_all(&response_parts).unwrap();
 
             // file descriptor 5 for writing http body to host
-            let mut body_write_stream = unsafe { std::fs::File::from_raw_fd(fd_5) };
+            let mut body_write_stream = unsafe { std::fs::File::from_raw_fd(body_write_fd) };
 
             // write body if there is one
             if let Some(body) = futures_executor::block_on(body.data()) {

diff --git a/common/Cargo.toml b/common/Cargo.toml
@@ -23,13 +23,16 @@ serde = { workspace = true, features = ["derive"] }
 serde_json = { workspace = true, optional = true }
 strum = { version = "0.24.1", features = ["derive"] }
 tracing = { workspace = true }
+tracing-subscriber = { workspace = true, optional = true }
 uuid = { workspace = true, features = ["v4", "serde"] }
 
 [dev-dependencies]
+cap-std = "1.0.2"
 hyper = "0.14.3"
 
 [features]
 backend = ["async-trait", "axum"]
 display = ["comfy-table", "crossterm"]
-axum-wasm = ["http-serde", "http", "rmp-serde"]
+tracing = ["serde_json"]
+axum-wasm = ["http-serde", "http", "rmp-serde", "tracing", "tracing-subscriber"]
 models = ["anyhow", "async-trait", "display", "http", "reqwest", "serde_json"]
diff --git a/common/src/lib.rs b/common/src/lib.rs
@@ -7,6 +7,8 @@ pub mod log;
 pub mod models;
 pub mod project;
 pub mod storage_manager;
+#[cfg(feature = "tracing")]
+pub mod tracing;
 #[cfg(feature = "axum-wasm")]
 pub mod wasm;
 

diff --git a/common/src/tracing.rs b/common/src/tracing.rs
@@ -0,0 +1,53 @@
+use serde_json::json;
+use tracing::field::Visit;
+
+// Boilerplate for extracting the fields from the event
+#[derive(Default)]
+pub struct JsonVisitor {
+    pub fields: serde_json::Map<String, serde_json::Value>,
+    pub target: Option<String>,
+    pub file: Option<String>,
+    pub line: Option<u32>,
+}
+
+impl JsonVisitor {
+    /// Ignores log metadata as it is included in the other LogItem fields (target, file, line...)
+    fn filter_insert(&mut self, field: &tracing::field::Field, value: serde_json::Value) {
+        match field.name() {
+            "log.line" => self.line = value.as_u64().map(|u| u as u32),
+            "log.target" => self.target = value.as_str().map(ToOwned::to_owned),
+            "log.file" => self.file = value.as_str().map(ToOwned::to_owned),
+            "log.module_path" => {}
+            name => {
+                self.fields.insert(name.to_string(), json!(value));
+            }
+        }
+    }
+}
+impl Visit for JsonVisitor {
+    fn record_str(&mut self, field: &tracing::field::Field, value: &str) {
+        self.filter_insert(field, json!(value));
+    }
+    fn record_bool(&mut self, field: &tracing::field::Field, value: bool) {
+        self.filter_insert(field, json!(value));
+    }
+    fn record_u64(&mut self, field: &tracing::field::Field, value: u64) {
+        self.filter_insert(field, json!(value));
+    }
+    fn record_i64(&mut self, field: &tracing::field::Field, value: i64) {
+        self.filter_insert(field, json!(value));
+    }
+    fn record_f64(&mut self, field: &tracing::field::Field, value: f64) {
+        self.filter_insert(field, json!(value));
+    }
+    fn record_error(
+        &mut self,
+        field: &tracing::field::Field,
+        value: &(dyn std::error::Error + 'static),
+    ) {
+        self.filter_insert(field, json!(value.to_string()));
+    }
+    fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
+        self.filter_insert(field, json!(format!("{value:?}")));
+    }
+}