From 1ba00f0b15c1c5bc189bbbff6993104a5897661a Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Wed, 5 Jun 2024 13:08:55 +0200 Subject: [PATCH 01/10] add tracer in global logger and send logs to tracer --- runtimes/core/src/lib.rs | 2 + runtimes/core/src/log/logger.rs | 72 +++++++++++++++++++++++++++-- runtimes/core/src/log/mod.rs | 7 +++ runtimes/core/src/model/mod.rs | 50 ++++++++++++++++++++ runtimes/core/src/trace/eventbuf.rs | 7 +++ runtimes/core/src/trace/protocol.rs | 43 ++++++++++++++++- 6 files changed, 177 insertions(+), 4 deletions(-) diff --git a/runtimes/core/src/lib.rs b/runtimes/core/src/lib.rs index cad0952838..6a84480821 100644 --- a/runtimes/core/src/lib.rs +++ b/runtimes/core/src/lib.rs @@ -248,6 +248,8 @@ impl Runtime { trace::Tracer::noop() }; + log::set_tracer(tracer.clone()); + let pubsub = pubsub::Manager::new(tracer.clone(), resources.pubsub_clusters, &md); let sqldb = sqldb::Manager::new( resources.sql_clusters, diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index 17bb7d5337..06e97f3897 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -1,12 +1,15 @@ use crate::error::AppError; use crate::log::fields::{FieldConfig, DEFAULT_FIELDS, GCP_FIELDS}; use crate::log::writers::{default_writer, Writer}; -use crate::model; +use crate::log::LogLevel; +use crate::model::{self, LogField}; +use crate::trace::protocol::LogMessageData; +use crate::trace::Tracer; use anyhow::Context; use env_logger::filter::Filter; use log::{Log, Metadata, Record}; use std::collections::BTreeMap; -use std::sync::Arc; +use std::sync::{Arc, RwLock}; use std::time::SystemTime; pub type Fields = BTreeMap; @@ -19,6 +22,7 @@ pub struct Logger { field_config: &'static FieldConfig, writer: Arc, extra_fields: Fields, + tracer: Arc>, } impl Logger { @@ -34,9 +38,15 @@ impl Logger { field_config, writer: default_writer(field_config), extra_fields: Fields::new(), + tracer: Arc::new(RwLock::new(Tracer::noop())), } } + pub fn set_tracer(&self, tracer: Tracer) { + let mut t = self.tracer.write().expect("tracer lock poisoned"); + *t = tracer; + } + /// Returns a new logger with the given log level. pub fn with_level(&self, level: log::LevelFilter) -> Self { Self { @@ -134,7 +144,7 @@ impl Logger { ); values.insert( self.field_config.message_field_name.to_string(), - serde_json::Value::from(msg), + serde_json::Value::from(msg.clone()), ); if let Some(req) = request { @@ -202,6 +212,8 @@ impl Logger { } } + self.write_to_trace(request, level, &msg, &values); + // Now write the log to the configured writer. self.writer .write(level, &values) @@ -236,6 +248,60 @@ impl Logger { Some(visitor.0), ) } + + /// Writes the log to trace + fn write_to_trace( + &self, + request: Option<&model::Request>, + level: LogLevel, + msg: &str, + fields: &Fields, + ) { + let mut trace_fields = Vec::new(); + + fields.iter().for_each(|(ref key, val)| match val { + serde_json::Value::Number(num) => { + if num.is_i64() { + trace_fields.push(LogField { + key, + value: model::LogFieldValue::I64(num.as_i64().unwrap()), + }); + } + if num.is_u64() { + trace_fields.push(LogField { + key, + value: model::LogFieldValue::U64(num.as_u64().unwrap()), + }); + } + if num.is_f64() { + trace_fields.push(LogField { + key, + value: model::LogFieldValue::F64(num.as_f64().unwrap()), + }); + } + } + serde_json::Value::Bool(b) => trace_fields.push(LogField { + key, + value: model::LogFieldValue::Bool(b.to_owned()), + }), + serde_json::Value::String(ref str) => trace_fields.push(LogField { + key, + value: model::LogFieldValue::String(str), + }), + _ => {} + }); + + let _ = self + .tracer + .read() + .expect("tracer lock poisoned") + .log_message(LogMessageData { + source: request, + msg: &msg, + level: level.into(), + fields: trace_fields, + }); + } } /// This trait defines the logging functions that are available on the `Logger` type. diff --git a/runtimes/core/src/log/mod.rs b/runtimes/core/src/log/mod.rs index 24dfc1a684..4ec7a9b2f9 100644 --- a/runtimes/core/src/log/mod.rs +++ b/runtimes/core/src/log/mod.rs @@ -8,6 +8,8 @@ mod writers; use crate::log::fields::FieldConfig; pub use logger::{Fields, LogFromExternalRuntime, LogFromRust, Logger}; +use crate::trace::Tracer; + /// The global root logger instance that is used by both the `log` crate /// and all other code in the Encore runtime. static ROOT: OnceCell<&Logger> = OnceCell::new(); @@ -20,6 +22,11 @@ pub fn init() { _ = root(); } +/// Set the tracer on the global logger +pub fn set_tracer(tracer: Tracer) { + root().set_tracer(tracer); +} + /// Returns a reference to the global root logger instance. pub fn root() -> &'static Logger { ROOT.get_or_init(|| { diff --git a/runtimes/core/src/model/mod.rs b/runtimes/core/src/model/mod.rs index 7810b69858..afcf2978d8 100644 --- a/runtimes/core/src/model/mod.rs +++ b/runtimes/core/src/model/mod.rs @@ -288,3 +288,53 @@ pub struct AuthSuccessResponse { /// The user data. pub user_data: serde_json::Map, } + +// matches go runtime +pub enum LogLevel { + Trace = 0, + Debug, + Info, + Warn, + Error, +} + +pub enum LogFieldValue<'a> { + String(&'a str), + U64(u64), + I64(i64), + F64(f64), + Bool(bool), +} + +pub struct LogField<'a> { + pub key: &'a str, + pub value: LogFieldValue<'a>, +} + +impl LogField<'_> { + pub fn type_byte(&self) -> u8 { + match self.value { + LogFieldValue::String(_) => 2, + LogFieldValue::Bool(_) => 3, + LogFieldValue::I64(_) => 8, + LogFieldValue::U64(_) => 9, + LogFieldValue::F64(_) => 11, + } + } +} + +impl From for LogLevel { + fn from(level: crate::log::LogLevel) -> Self { + match level { + crate::log::LogLevel::Trace => LogLevel::Trace, + crate::log::LogLevel::Debug => LogLevel::Debug, + crate::log::LogLevel::Info => LogLevel::Info, + crate::log::LogLevel::Warn => LogLevel::Warn, + crate::log::LogLevel::Error => LogLevel::Error, + + // TODO(fredr): these are not supported by the go runtime + crate::log::LogLevel::Fatal => LogLevel::Error, + crate::log::LogLevel::Disabled => LogLevel::Trace, + } + } +} diff --git a/runtimes/core/src/trace/eventbuf.rs b/runtimes/core/src/trace/eventbuf.rs index 230bc3852c..b78e505ce3 100644 --- a/runtimes/core/src/trace/eventbuf.rs +++ b/runtimes/core/src/trace/eventbuf.rs @@ -138,6 +138,13 @@ impl EventBuffer { self.buf.extend_from_slice(&self.scratch[..i]); } + /// Writes a float, always as 8 bytes. + #[inline] + pub fn f64(&mut self, f: f64) { + let data: [u8; 8] = f.to_le_bytes(); + self.buf.extend_from_slice(&data); + } + /// Writes a signed integer, always as 8 bytes. #[inline] pub fn i64(&mut self, i: i64) { diff --git a/runtimes/core/src/trace/protocol.rs b/runtimes/core/src/trace/protocol.rs index 00c9454be2..a8b10f9ba1 100644 --- a/runtimes/core/src/trace/protocol.rs +++ b/runtimes/core/src/trace/protocol.rs @@ -4,7 +4,7 @@ use std::sync::atomic::{AtomicU64, Ordering}; use crate::api; -use crate::model::{Request, TraceEventId}; +use crate::model::{LogField, LogFieldValue, LogLevel, Request, TraceEventId}; use crate::trace::eventbuf::EventBuffer; use crate::trace::log::TraceEvent; use crate::{model, EncoreName}; @@ -57,6 +57,47 @@ impl Tracer { } } +pub struct LogMessageData<'a> { + pub source: Option<&'a Request>, + pub msg: &'a str, + pub level: LogLevel, + pub fields: Vec>, +} + +impl Tracer { + #[inline] + pub fn log_message(&self, data: LogMessageData) -> Option { + let Some(source) = data.source else { + return None; + }; + + let mut eb = BasicEventData { + correlation_event_id: None, + extra_space: 4 + 4 + data.msg.len() + 1 + 64 * data.fields.len(), + } + .to_eb(); + + eb.byte(data.level as u8); + eb.str(&data.msg); + eb.uvarint(data.fields.len() as u64); + for field in data.fields { + eb.byte(field.type_byte()); + eb.str(field.key); + + match field.value { + LogFieldValue::String(str) => eb.str(str), + LogFieldValue::U64(n) => eb.u64(n), + LogFieldValue::I64(n) => eb.i64(n), + LogFieldValue::F64(n) => eb.f64(n), + LogFieldValue::Bool(b) => eb.bool(b), + } + } + eb.nyi_stack_pcs(); + + Some(self.send(EventType::LogMessage, source.span, eb)) + } +} + impl Tracer { #[inline] pub fn request_span_start(&self, req: &model::Request) { From 57e2659db78dfeaed7366d837350e5c9bd963735 Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Wed, 5 Jun 2024 15:00:30 +0200 Subject: [PATCH 02/10] add json field support and fix numbers --- runtimes/core/src/log/logger.rs | 15 ++++++++++----- runtimes/core/src/model/mod.rs | 2 ++ runtimes/core/src/trace/protocol.rs | 14 ++++++++++++-- 3 files changed, 24 insertions(+), 7 deletions(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index 06e97f3897..948716365a 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -42,6 +42,7 @@ impl Logger { } } + /// Sets the loggers tracer pub fn set_tracer(&self, tracer: Tracer) { let mut t = self.tracer.write().expect("tracer lock poisoned"); *t = tracer; @@ -266,14 +267,13 @@ impl Logger { key, value: model::LogFieldValue::I64(num.as_i64().unwrap()), }); - } - if num.is_u64() { + } else if num.is_u64() { trace_fields.push(LogField { key, value: model::LogFieldValue::U64(num.as_u64().unwrap()), }); - } - if num.is_f64() { + } else if num.is_f64() { + println!("is_f64"); trace_fields.push(LogField { key, value: model::LogFieldValue::F64(num.as_f64().unwrap()), @@ -288,7 +288,12 @@ impl Logger { key, value: model::LogFieldValue::String(str), }), - _ => {} + serde_json::Value::Array(_) + | serde_json::Value::Object(_) + | serde_json::Value::Null => trace_fields.push(LogField { + key, + value: model::LogFieldValue::Json(&val), + }), }); let _ = self diff --git a/runtimes/core/src/model/mod.rs b/runtimes/core/src/model/mod.rs index afcf2978d8..1bb85143c2 100644 --- a/runtimes/core/src/model/mod.rs +++ b/runtimes/core/src/model/mod.rs @@ -304,6 +304,7 @@ pub enum LogFieldValue<'a> { I64(i64), F64(f64), Bool(bool), + Json(&'a serde_json::Value), } pub struct LogField<'a> { @@ -317,6 +318,7 @@ impl LogField<'_> { LogFieldValue::String(_) => 2, LogFieldValue::Bool(_) => 3, LogFieldValue::I64(_) => 8, + LogFieldValue::Json(_) => 7, LogFieldValue::U64(_) => 9, LogFieldValue::F64(_) => 11, } diff --git a/runtimes/core/src/trace/protocol.rs b/runtimes/core/src/trace/protocol.rs index a8b10f9ba1..80381cdacc 100644 --- a/runtimes/core/src/trace/protocol.rs +++ b/runtimes/core/src/trace/protocol.rs @@ -86,10 +86,20 @@ impl Tracer { match field.value { LogFieldValue::String(str) => eb.str(str), - LogFieldValue::U64(n) => eb.u64(n), - LogFieldValue::I64(n) => eb.i64(n), + LogFieldValue::U64(n) => eb.uvarint(n), + LogFieldValue::I64(n) => eb.ivarint(n), LogFieldValue::F64(n) => eb.f64(n), LogFieldValue::Bool(b) => eb.bool(b), + LogFieldValue::Json(json) => match serde_json::to_vec(json) { + Ok(bytes) => { + eb.byte_string(&bytes); + eb.nyi_stack_pcs() + } + Err(err) => { + eb.byte_string(&[]); + eb.err_with_legacy_stack(Some(&err)) + } + }, } } eb.nyi_stack_pcs(); From 1f7e3351fda64fdd47e54e748fa046f4341dd9dd Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 09:10:53 +0200 Subject: [PATCH 03/10] remove debug print --- runtimes/core/src/log/logger.rs | 1 - 1 file changed, 1 deletion(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index 948716365a..51b3c6fc33 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -273,7 +273,6 @@ impl Logger { value: model::LogFieldValue::U64(num.as_u64().unwrap()), }); } else if num.is_f64() { - println!("is_f64"); trace_fields.push(LogField { key, value: model::LogFieldValue::F64(num.as_f64().unwrap()), From c291d6b5f45d44f3c702a70559028f43c91405e1 Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 09:16:33 +0200 Subject: [PATCH 04/10] no need to return event id --- runtimes/core/src/trace/protocol.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/runtimes/core/src/trace/protocol.rs b/runtimes/core/src/trace/protocol.rs index 80381cdacc..12c6dfff58 100644 --- a/runtimes/core/src/trace/protocol.rs +++ b/runtimes/core/src/trace/protocol.rs @@ -66,9 +66,9 @@ pub struct LogMessageData<'a> { impl Tracer { #[inline] - pub fn log_message(&self, data: LogMessageData) -> Option { + pub fn log_message(&self, data: LogMessageData) { let Some(source) = data.source else { - return None; + return; }; let mut eb = BasicEventData { @@ -104,7 +104,7 @@ impl Tracer { } eb.nyi_stack_pcs(); - Some(self.send(EventType::LogMessage, source.span, eb)) + _ = self.send(EventType::LogMessage, source.span, eb); } } From 2c7cdde57411c37a48bba5de2958bb510a6abc01 Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 09:59:43 +0200 Subject: [PATCH 05/10] only log user specified log fields --- runtimes/core/src/log/logger.rs | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index 51b3c6fc33..c57ccdbbe2 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -99,6 +99,10 @@ impl Logger { caller: Option, fields: Option, ) -> anyhow::Result<()> { + if let Some(ref fields) = fields { + self.write_to_trace(request, level, &msg, fields); + } + let mut values = Fields::new(); // Copy the extra fields into the values map. @@ -145,7 +149,7 @@ impl Logger { ); values.insert( self.field_config.message_field_name.to_string(), - serde_json::Value::from(msg.clone()), + serde_json::Value::from(msg), ); if let Some(req) = request { @@ -213,8 +217,6 @@ impl Logger { } } - self.write_to_trace(request, level, &msg, &values); - // Now write the log to the configured writer. self.writer .write(level, &values) @@ -301,7 +303,7 @@ impl Logger { .expect("tracer lock poisoned") .log_message(LogMessageData { source: request, - msg: &msg, + msg, level: level.into(), fields: trace_fields, }); From 52be8fbf8302df505b23b6884dff14fae3f07089 Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 10:14:09 +0200 Subject: [PATCH 06/10] use rust log levels --- runtimes/core/src/log/logger.rs | 7 +++---- runtimes/core/src/model/mod.rs | 16 ---------------- runtimes/core/src/trace/protocol.rs | 18 +++++++++++++++--- 3 files changed, 18 insertions(+), 23 deletions(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index c57ccdbbe2..c607d2d9d7 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -1,7 +1,6 @@ use crate::error::AppError; -use crate::log::fields::{FieldConfig, DEFAULT_FIELDS, GCP_FIELDS}; +use crate::log::fields::FieldConfig; use crate::log::writers::{default_writer, Writer}; -use crate::log::LogLevel; use crate::model::{self, LogField}; use crate::trace::protocol::LogMessageData; use crate::trace::Tracer; @@ -256,7 +255,7 @@ impl Logger { fn write_to_trace( &self, request: Option<&model::Request>, - level: LogLevel, + level: log::Level, msg: &str, fields: &Fields, ) { @@ -304,7 +303,7 @@ impl Logger { .log_message(LogMessageData { source: request, msg, - level: level.into(), + level, fields: trace_fields, }); } diff --git a/runtimes/core/src/model/mod.rs b/runtimes/core/src/model/mod.rs index 1bb85143c2..02d2b7c802 100644 --- a/runtimes/core/src/model/mod.rs +++ b/runtimes/core/src/model/mod.rs @@ -324,19 +324,3 @@ impl LogField<'_> { } } } - -impl From for LogLevel { - fn from(level: crate::log::LogLevel) -> Self { - match level { - crate::log::LogLevel::Trace => LogLevel::Trace, - crate::log::LogLevel::Debug => LogLevel::Debug, - crate::log::LogLevel::Info => LogLevel::Info, - crate::log::LogLevel::Warn => LogLevel::Warn, - crate::log::LogLevel::Error => LogLevel::Error, - - // TODO(fredr): these are not supported by the go runtime - crate::log::LogLevel::Fatal => LogLevel::Error, - crate::log::LogLevel::Disabled => LogLevel::Trace, - } - } -} diff --git a/runtimes/core/src/trace/protocol.rs b/runtimes/core/src/trace/protocol.rs index 12c6dfff58..0481f06546 100644 --- a/runtimes/core/src/trace/protocol.rs +++ b/runtimes/core/src/trace/protocol.rs @@ -4,7 +4,7 @@ use std::sync::atomic::{AtomicU64, Ordering}; use crate::api; -use crate::model::{LogField, LogFieldValue, LogLevel, Request, TraceEventId}; +use crate::model::{LogField, LogFieldValue, Request, TraceEventId}; use crate::trace::eventbuf::EventBuffer; use crate::trace::log::TraceEvent; use crate::{model, EncoreName}; @@ -60,10 +60,22 @@ impl Tracer { pub struct LogMessageData<'a> { pub source: Option<&'a Request>, pub msg: &'a str, - pub level: LogLevel, + pub level: log::Level, pub fields: Vec>, } +impl LogMessageData<'_> { + fn level_byte(&self) -> u8 { + match self.level { + log::Level::Error => 4, + log::Level::Warn => 3, + log::Level::Info => 2, + log::Level::Debug => 1, + log::Level::Trace => 0, + } + } +} + impl Tracer { #[inline] pub fn log_message(&self, data: LogMessageData) { @@ -77,7 +89,7 @@ impl Tracer { } .to_eb(); - eb.byte(data.level as u8); + eb.byte(data.level_byte()); eb.str(&data.msg); eb.uvarint(data.fields.len() as u64); for field in data.fields { From 04c9845e1b46b9a282c159facefbc280fc76ea8f Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 10:18:10 +0200 Subject: [PATCH 07/10] dont skip log lines without fields --- runtimes/core/src/log/logger.rs | 74 ++++++++++++++++----------------- 1 file changed, 37 insertions(+), 37 deletions(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index c607d2d9d7..61b6e11edf 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -98,9 +98,7 @@ impl Logger { caller: Option, fields: Option, ) -> anyhow::Result<()> { - if let Some(ref fields) = fields { - self.write_to_trace(request, level, &msg, fields); - } + self.write_to_trace(request, level, &msg, &fields); let mut values = Fields::new(); @@ -257,44 +255,46 @@ impl Logger { request: Option<&model::Request>, level: log::Level, msg: &str, - fields: &Fields, + fields: &Option, ) { let mut trace_fields = Vec::new(); - fields.iter().for_each(|(ref key, val)| match val { - serde_json::Value::Number(num) => { - if num.is_i64() { - trace_fields.push(LogField { - key, - value: model::LogFieldValue::I64(num.as_i64().unwrap()), - }); - } else if num.is_u64() { - trace_fields.push(LogField { - key, - value: model::LogFieldValue::U64(num.as_u64().unwrap()), - }); - } else if num.is_f64() { - trace_fields.push(LogField { - key, - value: model::LogFieldValue::F64(num.as_f64().unwrap()), - }); + if let Some(ref fields) = fields { + fields.iter().for_each(|(ref key, val)| match val { + serde_json::Value::Number(num) => { + if num.is_i64() { + trace_fields.push(LogField { + key, + value: model::LogFieldValue::I64(num.as_i64().unwrap()), + }); + } else if num.is_u64() { + trace_fields.push(LogField { + key, + value: model::LogFieldValue::U64(num.as_u64().unwrap()), + }); + } else if num.is_f64() { + trace_fields.push(LogField { + key, + value: model::LogFieldValue::F64(num.as_f64().unwrap()), + }); + } } - } - serde_json::Value::Bool(b) => trace_fields.push(LogField { - key, - value: model::LogFieldValue::Bool(b.to_owned()), - }), - serde_json::Value::String(ref str) => trace_fields.push(LogField { - key, - value: model::LogFieldValue::String(str), - }), - serde_json::Value::Array(_) - | serde_json::Value::Object(_) - | serde_json::Value::Null => trace_fields.push(LogField { - key, - value: model::LogFieldValue::Json(&val), - }), - }); + serde_json::Value::Bool(b) => trace_fields.push(LogField { + key, + value: model::LogFieldValue::Bool(b.to_owned()), + }), + serde_json::Value::String(ref str) => trace_fields.push(LogField { + key, + value: model::LogFieldValue::String(str), + }), + serde_json::Value::Array(_) + | serde_json::Value::Object(_) + | serde_json::Value::Null => trace_fields.push(LogField { + key, + value: model::LogFieldValue::Json(&val), + }), + }); + } let _ = self .tracer From eac2b42b863f7ba4ab94996f1a3db64f744b380a Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 13:18:51 +0200 Subject: [PATCH 08/10] pass an iterator instead of collecting into a vec --- runtimes/core/src/log/logger.rs | 45 +++++++++++---------- runtimes/core/src/trace/protocol.rs | 62 ++++++++++++++++------------- 2 files changed, 60 insertions(+), 47 deletions(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index 61b6e11edf..a505d49d3e 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -257,46 +257,51 @@ impl Logger { msg: &str, fields: &Option, ) { - let mut trace_fields = Vec::new(); - - if let Some(ref fields) = fields { - fields.iter().for_each(|(ref key, val)| match val { + let fields = fields.as_ref().map(|fields| { + fields.iter().map(|(ref key, val)| match val { serde_json::Value::Number(num) => { if num.is_i64() { - trace_fields.push(LogField { + LogField { key, value: model::LogFieldValue::I64(num.as_i64().unwrap()), - }); + } } else if num.is_u64() { - trace_fields.push(LogField { + LogField { key, value: model::LogFieldValue::U64(num.as_u64().unwrap()), - }); + } } else if num.is_f64() { - trace_fields.push(LogField { + LogField { key, value: model::LogFieldValue::F64(num.as_f64().unwrap()), - }); + } + } else { + // this can't happen as we have handle all the cases above, + // but we need to handle this case for the iterator to function + LogField { + key, + value: model::LogFieldValue::I64(0), + } } } - serde_json::Value::Bool(b) => trace_fields.push(LogField { + serde_json::Value::Bool(b) => LogField { key, value: model::LogFieldValue::Bool(b.to_owned()), - }), - serde_json::Value::String(ref str) => trace_fields.push(LogField { + }, + serde_json::Value::String(ref str) => LogField { key, value: model::LogFieldValue::String(str), - }), + }, serde_json::Value::Array(_) | serde_json::Value::Object(_) - | serde_json::Value::Null => trace_fields.push(LogField { + | serde_json::Value::Null => LogField { key, value: model::LogFieldValue::Json(&val), - }), - }); - } + }, + }) + }); - let _ = self + _ = self .tracer .read() .expect("tracer lock poisoned") @@ -304,7 +309,7 @@ impl Logger { source: request, msg, level, - fields: trace_fields, + fields, }); } } diff --git a/runtimes/core/src/trace/protocol.rs b/runtimes/core/src/trace/protocol.rs index 0481f06546..1496d5104f 100644 --- a/runtimes/core/src/trace/protocol.rs +++ b/runtimes/core/src/trace/protocol.rs @@ -57,14 +57,14 @@ impl Tracer { } } -pub struct LogMessageData<'a> { +pub struct LogMessageData<'a, I> { pub source: Option<&'a Request>, pub msg: &'a str, pub level: log::Level, - pub fields: Vec>, + pub fields: Option, } -impl LogMessageData<'_> { +impl<'a, I> LogMessageData<'a, I> { fn level_byte(&self) -> u8 { match self.level { log::Level::Error => 4, @@ -78,42 +78,50 @@ impl LogMessageData<'_> { impl Tracer { #[inline] - pub fn log_message(&self, data: LogMessageData) { + pub fn log_message<'a, I>(&self, data: LogMessageData) + where + I: ExactSizeIterator>, + { let Some(source) = data.source else { return; }; + let fields_count = data.fields.as_ref().map(|fields| fields.len()).unwrap_or(0); + let mut eb = BasicEventData { correlation_event_id: None, - extra_space: 4 + 4 + data.msg.len() + 1 + 64 * data.fields.len(), + extra_space: 4 + 4 + data.msg.len() + 1 + 64 * fields_count, } .to_eb(); eb.byte(data.level_byte()); eb.str(&data.msg); - eb.uvarint(data.fields.len() as u64); - for field in data.fields { - eb.byte(field.type_byte()); - eb.str(field.key); - - match field.value { - LogFieldValue::String(str) => eb.str(str), - LogFieldValue::U64(n) => eb.uvarint(n), - LogFieldValue::I64(n) => eb.ivarint(n), - LogFieldValue::F64(n) => eb.f64(n), - LogFieldValue::Bool(b) => eb.bool(b), - LogFieldValue::Json(json) => match serde_json::to_vec(json) { - Ok(bytes) => { - eb.byte_string(&bytes); - eb.nyi_stack_pcs() - } - Err(err) => { - eb.byte_string(&[]); - eb.err_with_legacy_stack(Some(&err)) - } - }, + eb.uvarint(fields_count as u64); + + data.fields.map(|fields| { + for field in fields { + eb.byte(field.type_byte()); + eb.str(field.key); + + match field.value { + LogFieldValue::String(str) => eb.str(str), + LogFieldValue::U64(n) => eb.uvarint(n), + LogFieldValue::I64(n) => eb.ivarint(n), + LogFieldValue::F64(n) => eb.f64(n), + LogFieldValue::Bool(b) => eb.bool(b), + LogFieldValue::Json(json) => match serde_json::to_vec(json) { + Ok(bytes) => { + eb.byte_string(&bytes); + eb.nyi_stack_pcs() + } + Err(err) => { + eb.byte_string(&[]); + eb.err_with_legacy_stack(Some(&err)) + } + }, + } } - } + }); eb.nyi_stack_pcs(); _ = self.send(EventType::LogMessage, source.span, eb); From b98fb000e2347833273194e671b90494037c89f6 Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 13:25:27 +0200 Subject: [PATCH 09/10] remove unused LogLevel enum --- runtimes/core/src/model/mod.rs | 9 --------- 1 file changed, 9 deletions(-) diff --git a/runtimes/core/src/model/mod.rs b/runtimes/core/src/model/mod.rs index 02d2b7c802..1aeb510bb7 100644 --- a/runtimes/core/src/model/mod.rs +++ b/runtimes/core/src/model/mod.rs @@ -289,15 +289,6 @@ pub struct AuthSuccessResponse { pub user_data: serde_json::Map, } -// matches go runtime -pub enum LogLevel { - Trace = 0, - Debug, - Info, - Warn, - Error, -} - pub enum LogFieldValue<'a> { String(&'a str), U64(u64), From 9a75967471f42234fafee28bdf954ab443e1ebf5 Mon Sep 17 00:00:00 2001 From: Fredrik Enestad Date: Fri, 7 Jun 2024 13:41:37 +0200 Subject: [PATCH 10/10] set field to null --- runtimes/core/src/log/logger.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/runtimes/core/src/log/logger.rs b/runtimes/core/src/log/logger.rs index a505d49d3e..09d61b173e 100644 --- a/runtimes/core/src/log/logger.rs +++ b/runtimes/core/src/log/logger.rs @@ -280,7 +280,7 @@ impl Logger { // but we need to handle this case for the iterator to function LogField { key, - value: model::LogFieldValue::I64(0), + value: model::LogFieldValue::Json(&serde_json::Value::Null), } } }