Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 9 additions & 8 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

8 changes: 4 additions & 4 deletions Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down
2 changes: 1 addition & 1 deletion crates/core/src/db/message_log.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
8 changes: 4 additions & 4 deletions crates/core/src/db/relational_db.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
Expand All @@ -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))]
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The actual table and column names would be useful to capture here, but because we only have the IDs, it's probably ok to just skip_all.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the table id might be useful tbh

pub fn iter_by_col_eq<'a>(
&'a self,
tx: &'a MutTxId,
Expand Down Expand Up @@ -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))]
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Similarly here.

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)
Expand Down Expand Up @@ -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)
}
Expand Down
4 changes: 2 additions & 2 deletions crates/core/src/host/instance_env.rs
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,7 @@ impl InstanceEnv {
}
}

#[tracing::instrument(skip_all)]
#[tracing::instrument(skip_all, fields(reducer=reducer))]
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice!

pub fn schedule(
&self,
reducer: String,
Expand Down Expand Up @@ -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()?;
Expand Down
2 changes: 1 addition & 1 deletion crates/core/src/host/wasm_common/module_host_actor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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))]
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

By calling self.instance.instance_env().dbic.database_id won't this add overhead to the init_database call that won't be reflective of its true characteristics?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually instance_env() shouldn't add any meaningful overhead, but we probably want to avoid calling arbitrary methods as part of trace logging since in general we don't know exactly how much overhead that will add to the span.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks minimal:

    fn instance_env(&self) -> &InstanceEnv {
        &self.env.as_ref(&self.store).instance_env
    }

Also this is only in the init of the db. The rest of the calls should take more time...

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();
Expand Down
2 changes: 1 addition & 1 deletion crates/core/src/sql/execute.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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)]
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should create a ticket to capture the actual sql string here that we compiled earlier.

pub fn execute_single_sql(
db: &RelationalDB,
tx: &mut MutTxId,
Expand Down
3 changes: 2 additions & 1 deletion crates/core/src/startup.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down
2 changes: 1 addition & 1 deletion crates/core/src/subscription/query.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down