Skip to content

Commit

Permalink
Update loggersto be namespaced and use structured logging
Browse files Browse the repository at this point in the history
  • Loading branch information
Jonatan Chaverri committed Mar 26, 2024
1 parent 4af8b03 commit 0312566
Show file tree
Hide file tree
Showing 13 changed files with 93 additions and 77 deletions.
1 change: 1 addition & 0 deletions bin/katana/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,7 @@ fn print_intro(args: &KatanaArgs, genesis: &Genesis, address: SocketAddr) {

if args.json_log {
info!(
target: "katana::cli",
"{}",
serde_json::json!({
"accounts": accounts.map(|a| serde_json::json!(a)).collect::<Vec<_>>(),
Expand Down
6 changes: 3 additions & 3 deletions bin/sozo/src/commands/dev.rs
Original file line number Diff line number Diff line change
Expand Up @@ -243,7 +243,7 @@ impl DevArgs {
world_address = address;
}
Err(error) => {
log::error!("Error: {error:?}");
log::error!(target: "sozo::cli::commands::dev", "Error", error = ?error);
}
}
loop {
Expand All @@ -255,7 +255,7 @@ impl DevArgs {
.unwrap_or(DevAction::None),
Ok(Err(_)) => DevAction::None,
Err(error) => {
log::error!("Error: {error:?}");
log::error!(target: "sozo::cli::commands::dev", "Error", error = ?error);
break;
}
};
Expand All @@ -273,7 +273,7 @@ impl DevArgs {
world_address = address;
}
Err(error) => {
log::error!("Error: {error:?}");
log::error!(target: "sozo::cli::commands::dev", "Error", error = ?error);
}
}
}
Expand Down
8 changes: 4 additions & 4 deletions bin/torii/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -217,13 +217,13 @@ async fn main() -> anyhow::Result<()> {
form_urlencoded::byte_serialize(gql_endpoint.replace("0.0.0.0", "localhost").as_bytes())
.collect();
let explorer_url = format!("https://worlds.dev/torii?url={}", encoded);
info!(target: "torii::cli", "Starting torii endpoint: {}", endpoint);
info!(target: "torii::cli", "Serving Graphql playground: {}", gql_endpoint);
info!(target: "torii::cli", "World Explorer is available on: {}\n", explorer_url);
info!(target: "torii::cli", "Starting torii endpoint.", endpoint = %endpoint);
info!(target: "torii::cli", "Serving Graphql playground.", endpoint = %gql_endpoint);
info!(target: "torii::cli", "World Explorer is available", url = %explorer_url);

if args.explorer {
if let Err(e) = webbrowser::open(&explorer_url) {
error!("Failed to open World Explorer in the browser: {e}");
error!(target: "torii::cli", "Failed to open World Explorer in the browser", error = %e);
}
}

Expand Down
6 changes: 5 additions & 1 deletion crates/katana/core/src/backend/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -171,7 +171,11 @@ impl Backend {
receipts,
)?;

info!(target: "backend", "⛏️ Block {block_number} mined with {tx_count} transactions");
info!(
target: "backend", "⛏️ Block mined with transactions",
block_number = %block_number,
tx_count = %tx_count,
);

Ok(MinedBlockOutcome { block_number })
}
Expand Down
6 changes: 3 additions & 3 deletions crates/katana/core/src/service/messaging/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -177,7 +177,7 @@ impl MessengerMode {
Ok(MessengerMode::Ethereum(m_eth))
}
Err(e) => {
error!(target: LOG_TARGET, "Ethereum messenger init failed: {e}");
error!(target: LOG_TARGET, "Ethereum messenger init failed.", error = %e);
Err(Error::InitError)
}
},
Expand All @@ -189,13 +189,13 @@ impl MessengerMode {
Ok(MessengerMode::Starknet(m_sn))
}
Err(e) => {
error!(target: LOG_TARGET, "Starknet messenger init failed: {e}");
error!(target: LOG_TARGET, "Starknet messenger init failed.", error = %e);
Err(Error::InitError)
}
},

chain => {
error!(target: LOG_TARGET, "Unsupported settlement chain: {}", chain);
error!(target: LOG_TARGET, "Unsupported settlement chain.", chain = %chain);
Err(Error::UnsupportedChain)
}
}
Expand Down
49 changes: 16 additions & 33 deletions crates/katana/core/src/service/messaging/service.rs
Original file line number Diff line number Diff line change
Expand Up @@ -270,17 +270,11 @@ fn trace_msg_to_l1_sent(messages: &Vec<MessageToL1>, hashes: &Vec<String>) {
#[rustfmt::skip]
info!(
target: LOG_TARGET,
r"Message executed on settlement layer:
| from_address | {}
| to_address | {}
| selector | {}
| payload | [{}]
",
m.from_address,
to_address,
selector,
payload_str.join(", ")
"Message executed on settlement layer",
from_address = %m.from_address,
to_address = %to_address,
selector = %selector,
payload = %payload_str.join(", ")
);

continue;
Expand All @@ -296,18 +290,13 @@ fn trace_msg_to_l1_sent(messages: &Vec<MessageToL1>, hashes: &Vec<String>) {
#[rustfmt::skip]
info!(
target: LOG_TARGET,
r#"Message sent to settlement layer:
| hash | {}
| from_address | {}
| to_address | {}
| payload | [{}]
"#,
hash.as_str(),
m.from_address,
to_address,
payload_str.join(", ")
"Message sent to settlement layer",
hash = %hash.as_str(),
from_address = %m.from_address,
to_address = %to_address,
payload = %payload_str.join(", ")
);

}
}

Expand All @@ -317,16 +306,10 @@ fn trace_l1_handler_tx_exec(hash: TxHash, tx: &L1HandlerTx) {
#[rustfmt::skip]
info!(
target: LOG_TARGET,
r"L1Handler transaction added to the pool:
| tx_hash | {:#x}
| contract_address | {}
| selector | {:#x}
| calldata | [{}]
",
hash,
tx.contract_address,
tx.entry_point_selector,
calldata_str.join(", ")
"L1Handler transaction added to the pool",
tx_hash = %format!("{:#x}", hash),
contract_address = %tx.contract_address,
selector = %format!("{:#x}", tx.entry_point_selector),
calldata = %calldata_str.join(", ")
);
}
8 changes: 4 additions & 4 deletions crates/katana/core/src/service/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -49,10 +49,10 @@ impl Future for NodeService {
while let Poll::Ready(Some(outcome)) = messaging.poll_next_unpin(cx) {
match outcome {
MessagingOutcome::Gather { msg_count, .. } => {
trace!(target: "node", "collected {msg_count} messages from settlement chain");
trace!(target: "node", "Collected messages from settlement chain", msg_count = %msg_count);
}
MessagingOutcome::Send { msg_count, .. } => {
trace!(target: "node", "sent {msg_count} messages to the settlement chain");
trace!(target: "node", "Sent messages to the settlement chain", msg_count = %msg_count);
}
}
}
Expand All @@ -64,11 +64,11 @@ impl Future for NodeService {
while let Poll::Ready(Some(res)) = pin.block_producer.poll_next_unpin(cx) {
match res {
Ok(outcome) => {
trace!(target: "node", "mined block {}", outcome.block_number)
trace!(target: "node", "Mined block", block_number = %outcome.block_number);
}

Err(err) => {
error!(target: "node", "failed to mine block: {err}");
error!(target: "node", "Failed to mine block", error = %err);
}
}
}
Expand Down
6 changes: 5 additions & 1 deletion crates/torii/core/src/processors/event_message.rs
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,11 @@ where
Err(_) => return Ok(()),
};

info!("store event message: {}", model.name());
info!(
target: "torii_core::processors::event_message",
"store event message",
model = %model.name()
);

// skip the first key, as its the event selector
// and dont include last key as its the system key
Expand Down
34 changes: 27 additions & 7 deletions crates/torii/core/src/processors/metadata_update.rs
Original file line number Diff line number Diff line change
Expand Up @@ -35,9 +35,10 @@ where
fn validate(&self, event: &Event) -> bool {
if event.keys.len() > 1 {
info!(
"invalid keys for event {}: {}",
<MetadataUpdateProcessor as EventProcessor<P>>::event_key(self),
<MetadataUpdateProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
target: "torii_core::processors::metadata_update",
"Invalid keys for event",
event_key = %<MetadataUpdateProcessor as EventProcessor<P>>::event_key(self),
invalid_keys = %<MetadataUpdateProcessor as EventProcessor<P>>::event_keys_as_string(self, event)
);
return false;
}
Expand Down Expand Up @@ -67,7 +68,12 @@ where
"".to_string()
};

info!("Resource {:#x} metadata set: {}", resource, uri_str);
info!(
target: "torii_core::processors::metadata_update",
"Resource metadata set",
resource = %format!("{:#x}", resource),
uri = %uri_str
);
db.set_metadata(resource, &uri_str, block_timestamp);

let db = db.clone();
Expand All @@ -86,10 +92,20 @@ async fn try_retrieve(mut db: Sql, resource: FieldElement, uri_str: String) {
db.update_metadata(&resource, &uri_str, &metadata, &icon_img, &cover_img)
.await
.unwrap();
info!("Updated resource {resource:#x} metadata from ipfs");
info!(
target: "torii_core::processors::metadata_update",
"Updated resource metadata from ipfs",
resource = %format!("{:#x}", resource)
);
}
Err(e) => {
error!("Error retrieving resource {resource:#x} uri {uri_str}: {e}")
error!(
target: "torii_core::processors::metadata_update",
"Error retrieving resource uri",
resource = %format!("{:#x}", resource),
uri = %uri_str,
error = %e
);
}
}
}
Expand Down Expand Up @@ -126,7 +142,11 @@ async fn fetch_content(cid: &str, mut retries: u8) -> Result<Bytes> {
Err(e) => {
retries -= 1;
if retries > 0 {
info!("Fetch uri failure: {}", e);
info!(
target: "torii_core::processors::metadata_update",
"Fetch uri failure",
error = %e
);
tokio::time::sleep(Duration::from_secs(3)).await;
}
}
Expand Down
26 changes: 14 additions & 12 deletions crates/torii/core/src/processors/register_model.rs
Original file line number Diff line number Diff line change
Expand Up @@ -25,9 +25,10 @@ where
fn validate(&self, event: &Event) -> bool {
if event.keys.len() > 1 {
info!(
"invalid keys for event {}: {}",
<RegisterModelProcessor as EventProcessor<P>>::event_key(self),
<RegisterModelProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
target: "torii_core::processors::register_model",
"Invalid keys for event",
event_key = %<RegisterModelProcessor as EventProcessor<P>>::event_key(self),
invalid_keys = %<RegisterModelProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
);
return false;
}
Expand Down Expand Up @@ -56,16 +57,17 @@ where
let class_hash = event.data[1];
let contract_address = event.data[3];

info!(name, "Registered model");
info!(target: "torii_core::processors::register_model", "Registered model", name = %name);
debug!(
name,
?schema,
?layout,
?class_hash,
?contract_address,
packed_size,
unpacked_size,
"Registered model content"
target: "torii_core::processors::register_model",
"Registered model content",
name = %name,
schema = ?schema,
layout = ?layout,
class_hash = ?class_hash,
contract_address = ?contract_address,
packed_size = %packed_size,
unpacked_size = %unpacked_size
);

db.register_model(
Expand Down
9 changes: 5 additions & 4 deletions crates/torii/core/src/processors/store_del_record.rs
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,10 @@ where
fn validate(&self, event: &Event) -> bool {
if event.keys.len() > 1 {
info!(
"invalid keys for event {}: {}",
<StoreDelRecordProcessor as EventProcessor<P>>::event_key(self),
<StoreDelRecordProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
target: "torii_core::processors::store_del_record",
"Invalid keys for event",
event_key = %<StoreDelRecordProcessor as EventProcessor<P>>::event_key(self),
invalid_keys = %<StoreDelRecordProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
);
return false;
}
Expand All @@ -46,7 +47,7 @@ where
event: &Event,
) -> Result<(), Error> {
let name = parse_cairo_short_string(&event.data[MODEL_INDEX])?;
info!("store delete record: {}", name);
info!(target: "torii_core::processors::store_del_record", "Store delete record", name = %name);

// this is temporary until the model name hash is precomputed
let model = db.model(&format!("{:#x}", get_selector_from_name(&name)?)).await?;
Expand Down
9 changes: 5 additions & 4 deletions crates/torii/core/src/processors/store_set_record.rs
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,10 @@ where
fn validate(&self, event: &Event) -> bool {
if event.keys.len() > 1 {
info!(
"invalid keys for event {}: {}",
<StoreSetRecordProcessor as EventProcessor<P>>::event_key(self),
<StoreSetRecordProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
target: "torii_core::processors::store_set_record",
"Invalid keys for event",
event_key = %<StoreSetRecordProcessor as EventProcessor<P>>::event_key(self),
invalid_keys = %<StoreSetRecordProcessor as EventProcessor<P>>::event_keys_as_string(self, event),
);
return false;
}
Expand All @@ -46,7 +47,7 @@ where
event: &Event,
) -> Result<(), Error> {
let name = parse_cairo_short_string(&event.data[MODEL_INDEX])?;
info!("store set record: {}", name);
info!(target: "torii_core::processors::store_set_record", "Store set record", name = %name);

// this is temporary until the model name hash is precomputed
let model = db.model(&format!("{:#x}", get_selector_from_name(&name)?)).await?;
Expand Down
2 changes: 1 addition & 1 deletion crates/torii/grpc/src/server/logger.rs
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ where
let uri = req.uri().path();
let method = req.method();

info!(target: "grpc", ?method, ?uri);
info!(target: "torii_grpc", "gRPC request", method = ?method, uri = ?uri);
inner.call(req).await
})
}
Expand Down

0 comments on commit 0312566

Please sign in to comment.