Fix the printing of ascii codes on tracy and improve some tracing (#341)

Signed-off-by: Tyler Cloutier <cloutiertyler@users.noreply.github.com>
Co-authored-by: Tyler Cloutier <cloutiertyler@users.noreply.github.com>

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"

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;

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<IndexId, DBError> {
         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<ProductValue, DBError> {
         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<SequenceId, DBError> {
         self.inner.create_sequence_mut_tx(tx, seq)
     }

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<u32, NodesError> {
         let stdb = &*self.dbic.relational_db;
         let tx = &mut *self.get_tx()?;

crates/core/src/host/wasm_common/module_host_actor.rs

@@ -354,7 +354,7 @@ impl<T: WasmInstance> ModuleInstance for WasmModuleInstance<T> {
         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<ReducerCallResult> {
         let stdb = &*self.database_instance_context().relational_db;
         let mut tx = stdb.begin_tx();

crates/core/src/sql/execute.rs

@@ -52,7 +52,7 @@ fn collect_result(result: &mut Vec<MemTable>, 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,

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) {

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<Item = QueryExpr> + '_ {
         self.queries.iter().filter_map(move |x| {
             if x.source.get_db_table().map(|x| x.table_id) == Some(table.table_id) {