From 3d1d98c13768fa3555fcfe51c2a641b0acee4ec5 Mon Sep 17 00:00:00 2001 From: Mario Montoya Date: Sat, 30 Sep 2023 01:23:31 -0500 Subject: [PATCH] Fix the printing of ascii codes on tracy and improve some tracing (#341) Signed-off-by: Tyler Cloutier Co-authored-by: Tyler Cloutier --- Cargo.lock | 17 +++++++++-------- Cargo.toml | 8 ++++---- crates/core/src/db/message_log.rs | 2 +- crates/core/src/db/relational_db.rs | 8 ++++---- crates/core/src/host/instance_env.rs | 4 ++-- .../src/host/wasm_common/module_host_actor.rs | 2 +- crates/core/src/sql/execute.rs | 2 +- crates/core/src/startup.rs | 3 ++- crates/core/src/subscription/query.rs | 2 +- 9 files changed, 25 insertions(+), 23 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index b1fc8e0eae1..7a991dabeab 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -530,11 +530,12 @@ checksum = "37b2a672a2cb129a2e41c10b1224bb368f9f37a2b16b612598138befd7b37eb5" [[package]] name = "cc" -version = "1.0.79" +version = "1.0.83" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "50d30906286121d95be3d479533b458f87493b30a4b5f79a607db8f5d11aa91f" +checksum = "f1174fb0b6ec23863f8b971027804a42614e347eafb0a95bf0b12cdae21fc4d0" dependencies = [ "jobserver", + "libc", ] [[package]] @@ -5200,9 +5201,9 @@ dependencies = [ [[package]] name = "tracing-tracy" -version = "0.10.2" +version = "0.10.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "55c48ef3e655220d4e43a6be44aa84f078c3004357251cab45f9cc15551a593e" +checksum = "fc6c7bf057d67aa107e076129a4f331aaac47ec379952d9f0775c6b1d838ee97" dependencies = [ "tracing-core", "tracing-subscriber", @@ -5211,9 +5212,9 @@ dependencies = [ [[package]] name = "tracy-client" -version = "0.15.2" +version = "0.16.3" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "434ecabbda9f67eeea1eab44d52f4a20538afa3e2c2770f2efc161142b25b608" +checksum = "03684af8fb393cc7903210d868e4cb9f5c1e156737be38f52c4217fb21b86bf6" dependencies = [ "loom", "once_cell", @@ -5222,9 +5223,9 @@ dependencies = [ [[package]] name = "tracy-client-sys" -version = "0.21.0" +version = "0.21.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "0d99f5fc382239d08b6bf05bb6206a585bfdb988c878f2499081d0f285ef7819" +checksum = "2cb915ea3af048554640d76dd6f1492589a6401a41a30d789b983c1ec280455a" dependencies = [ "cc", ] diff --git a/Cargo.toml b/Cargo.toml index 82f6a0d6cab..723adb80ae5 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -166,11 +166,11 @@ tokio-postgres = { version = "0.7.8", features = ["with-chrono-0_4"] } tokio-tungstenite = { version = "0.19", features = ["native-tls"] } toml = "0.5" tower-http = { version = "0.4.1", features = ["cors"] } -tracing = "0.1" +tracing = "0.1.37" tracing-appender = "0.2.2" -tracing-core = "0.1" -tracing-flame = "0.2" -tracing-log = "0.1" +tracing-core = "0.1.31" +tracing-flame = "0.2.0" +tracing-log = "0.1.3" tracing-subscriber = { version = "0.3.17", features = ["env-filter"] } url = "2.3.1" urlencoding = "2.1.2" diff --git a/crates/core/src/db/message_log.rs b/crates/core/src/db/message_log.rs index 7e090c10a54..f5eb743c1c0 100644 --- a/crates/core/src/db/message_log.rs +++ b/crates/core/src/db/message_log.rs @@ -124,7 +124,7 @@ impl MessageLog { Ok(()) } - #[tracing::instrument(skip(message))] + #[tracing::instrument(skip_all)] pub fn append(&mut self, message: impl AsRef<[u8]>) -> Result<(), DBError> { let message = message.as_ref(); let mess_size = message.len() as u32; diff --git a/crates/core/src/db/relational_db.rs b/crates/core/src/db/relational_db.rs index a9231e16454..0a8783f250e 100644 --- a/crates/core/src/db/relational_db.rs +++ b/crates/core/src/db/relational_db.rs @@ -442,7 +442,7 @@ impl RelationalDB { /// Returns the `index_id` /// /// NOTE: It loads the data from the table into it before returning - #[tracing::instrument(skip(self, tx))] + #[tracing::instrument(skip(self, tx, index), fields(index=index.name))] pub fn create_index(&self, tx: &mut MutTxId, index: IndexDef) -> Result { self.inner.create_index_mut_tx(tx, index) } @@ -466,7 +466,7 @@ impl RelationalDB { /// where the column data identified by `cols` matches `value`. /// /// Matching is defined by `Ord for AlgebraicValue`. - #[tracing::instrument(skip(self, tx))] + #[tracing::instrument(skip(self, tx, value))] pub fn iter_by_col_eq<'a>( &'a self, tx: &'a MutTxId, @@ -494,7 +494,7 @@ impl RelationalDB { .iter_by_col_range_mut_tx(tx, TableId(table_id), ColId(col_id), range) } - #[tracing::instrument(skip(self, tx))] + #[tracing::instrument(skip(self, tx, row))] pub fn insert(&self, tx: &mut MutTxId, table_id: u32, row: ProductValue) -> Result { measure(&RDB_INSERT_TIME, table_id); self.inner.insert_mut_tx(tx, TableId(table_id), row) @@ -549,7 +549,7 @@ impl RelationalDB { } /// Add a [Sequence] into the database instance, generates a stable [SequenceId] for it that will persist on restart. - #[tracing::instrument(skip(self, tx))] + #[tracing::instrument(skip(self, tx, seq), fields(seq=seq.sequence_name))] pub fn create_sequence(&self, tx: &mut MutTxId, seq: SequenceDef) -> Result { self.inner.create_sequence_mut_tx(tx, seq) } diff --git a/crates/core/src/host/instance_env.rs b/crates/core/src/host/instance_env.rs index 29c73e28cca..a8367562c3a 100644 --- a/crates/core/src/host/instance_env.rs +++ b/crates/core/src/host/instance_env.rs @@ -43,7 +43,7 @@ impl InstanceEnv { } } - #[tracing::instrument(skip_all)] + #[tracing::instrument(skip_all, fields(reducer=reducer))] pub fn schedule( &self, reducer: String, @@ -143,7 +143,7 @@ impl InstanceEnv { /// where the column identified by `cols` equates to `value`. /// /// Returns an error if no columns were deleted or if the column wasn't found. - #[tracing::instrument(skip_all)] + #[tracing::instrument(skip(self, value))] pub fn delete_by_col_eq(&self, table_id: u32, col_id: u32, value: &[u8]) -> Result { let stdb = &*self.dbic.relational_db; let tx = &mut *self.get_tx()?; diff --git a/crates/core/src/host/wasm_common/module_host_actor.rs b/crates/core/src/host/wasm_common/module_host_actor.rs index b7d61f7117e..446969c51de 100644 --- a/crates/core/src/host/wasm_common/module_host_actor.rs +++ b/crates/core/src/host/wasm_common/module_host_actor.rs @@ -354,7 +354,7 @@ impl ModuleInstance for WasmModuleInstance { self.trapped } - #[tracing::instrument(skip(args))] + #[tracing::instrument(skip(self, args), fields(db_id=self.instance.instance_env().dbic.database_id))] fn init_database(&mut self, fence: u128, args: ArgsTuple) -> anyhow::Result { let stdb = &*self.database_instance_context().relational_db; let mut tx = stdb.begin_tx(); diff --git a/crates/core/src/sql/execute.rs b/crates/core/src/sql/execute.rs index cde8a3fafbf..fbaaa9e391f 100644 --- a/crates/core/src/sql/execute.rs +++ b/crates/core/src/sql/execute.rs @@ -52,7 +52,7 @@ fn collect_result(result: &mut Vec, r: CodeResult) -> Result<(), DBErr Ok(()) } -#[tracing::instrument(skip(db, tx, auth))] +#[tracing::instrument(skip_all)] pub fn execute_single_sql( db: &RelationalDB, tx: &mut MutTxId, diff --git a/crates/core/src/startup.rs b/crates/core/src/startup.rs index 697a372b14f..b3d86d0b17e 100644 --- a/crates/core/src/startup.rs +++ b/crates/core/src/startup.rs @@ -58,9 +58,10 @@ pub fn configure_tracing() { (None, None) }; + // Is important for `tracy_layer` to be before `fmt_layer` to not print ascii codes... let subscriber = tracing_subscriber::Registry::default() - .with(fmt_layer) .with(tracy_layer) + .with(fmt_layer) .with(flame_layer); if cfg!(debug_assertions) { diff --git a/crates/core/src/subscription/query.rs b/crates/core/src/subscription/query.rs index fde840bb818..c0115b009e4 100644 --- a/crates/core/src/subscription/query.rs +++ b/crates/core/src/subscription/query.rs @@ -24,7 +24,7 @@ pub struct Query { } impl Query { - #[tracing::instrument(skip(self))] + #[tracing::instrument(skip_all, fields(table = table.table_name))] pub fn queries_of_table_id<'a>(&'a self, table: &'a DatabaseTableUpdate) -> impl Iterator + '_ { self.queries.iter().filter_map(move |x| { if x.source.get_db_table().map(|x| x.table_id) == Some(table.table_id) {