[sozo] add trace logs (#1867)

* Added trace logs for Sozo. * Added Sozo trace logs. * Updated Sozo trace logs. * Updated Sozo trace logs. * Updated Sozo trace logs Co-authored-by: glihm <[email protected]> * Updated Sozo trace logs. * Updated Sozo trace logs Co-authored-by: Ammar Arif <[email protected]> * Updated Sozo trace logs. * Removed json for Sozo log. * Removed LOG_TARGET for Sozo trace logs. * Updated Sozo trace logs Co-authored-by: glihm <[email protected]> * Updated Sozo trace logs - removed fetch keyword. * Resolved failing checks. * Updated Sozo trace logs. Co-authored-by: glihm <[email protected]> * Updated Sozo trace logs. * fix: ensure sozo commands return expected Result --------- Co-authored-by: glihm <[email protected]> Co-authored-by: Ammar Arif <[email protected]>
dojoengine · May 1, 2024 · 683620c · 683620c
1 parent 6427cdc
commit 683620c
Show file tree

Hide file tree

Showing 23 changed files with 196 additions and 23 deletions.
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/bin/sozo/Cargo.toml b/bin/sozo/Cargo.toml
@@ -48,6 +48,7 @@ thiserror.workspace = true
 tokio.workspace = true
 tracing-log = "0.1.3"
 tracing.workspace = true
+tracing-subscriber.workspace = true
 url.workspace = true
 katana-rpc-api.workspace = true
 

diff --git a/bin/sozo/src/args.rs b/bin/sozo/src/args.rs
@@ -5,7 +5,9 @@ use scarb::compiler::Profile;
 use scarb_ui::Verbosity;
 use smol_str::SmolStr;
 use tracing::level_filters::LevelFilter;
+use tracing::Subscriber;
 use tracing_log::AsTrace;
+use tracing_subscriber::{fmt, EnvFilter};
 
 use crate::commands::Commands;
 use crate::utils::generate_version;
@@ -50,6 +52,18 @@ impl SozoArgs {
             Verbosity::Quiet
         }
     }
+
+    pub fn init_logging(&self) -> Result<(), Box<dyn std::error::Error>> {
+        const DEFAULT_LOG_FILTER: &str = "info,hyper=off,scarb=off";
+
+        let builder = fmt::Subscriber::builder().with_env_filter(
+            EnvFilter::try_from_default_env().or(EnvFilter::try_new(DEFAULT_LOG_FILTER))?,
+        );
+
+        let subscriber: Box<dyn Subscriber + Send + Sync> = Box::new(builder.finish());
+
+        Ok(tracing::subscriber::set_global_default(subscriber)?)
+    }
 }
 
 /// Profile specifier.

diff --git a/bin/sozo/src/commands/account.rs b/bin/sozo/src/commands/account.rs
@@ -6,6 +6,7 @@ use scarb::core::Config;
 use sozo_ops::account;
 use starknet::signers::LocalWallet;
 use starknet_crypto::FieldElement;
+use tracing::trace;
 
 use super::options::fee::FeeOptions;
 use super::options::signer::SignerOptions;
@@ -83,12 +84,14 @@ pub enum AccountCommand {
 
 impl AccountArgs {
     pub fn run(self, config: &Config) -> Result<()> {
+        trace!(command = ?self.command, "Executing command.");
         let env_metadata = utils::load_metadata_from_config(config)?;
 
         config.tokio_handle().block_on(async {
             match self.command {
                 AccountCommand::New { signer, force, file } => {
                     let signer: LocalWallet = signer.signer(env_metadata.as_ref(), false)?;
+                    trace!(?signer, force, ?file, "Executing New command.");
                     account::new(signer, force, file).await
                 }
                 AccountCommand::Deploy {
@@ -102,8 +105,19 @@ impl AccountArgs {
                     no_confirmation,
                 } => {
                     let provider = starknet.provider(env_metadata.as_ref())?;
-                    let signer = signer.signer(env_metadata.as_ref(), false)?;
+                    let signer: LocalWallet = signer.signer(env_metadata.as_ref(), false)?;
                     let fee_setting = fee.into_setting()?;
+                    trace!(
+                        ?starknet,
+                        ?signer,
+                        ?fee_setting,
+                        simulate,
+                        ?nonce,
+                        poll_interval,
+                        ?file,
+                        no_confirmation,
+                        "Executing Deploy command."
+                    );
                     account::deploy(
                         provider,
                         signer,
@@ -117,6 +131,7 @@ impl AccountArgs {
                     .await
                 }
                 AccountCommand::Fetch { starknet, force, output, address } => {
+                    trace!(?starknet, force, ?output, ?address, "Executing Fetch command.");
                     let provider = starknet.provider(env_metadata.as_ref())?;
                     account::fetch(provider, force, output, address).await
                 }

diff --git a/bin/sozo/src/commands/auth.rs b/bin/sozo/src/commands/auth.rs
@@ -3,6 +3,7 @@ use clap::{Args, Subcommand};
 use dojo_world::metadata::Environment;
 use scarb::core::Config;
 use sozo_ops::auth;
+use tracing::trace;
 
 use super::options::account::AccountOptions;
 use super::options::starknet::StarknetOptions;
@@ -56,7 +57,10 @@ pub enum AuthCommand {
 
 impl AuthArgs {
     pub fn run(self, config: &Config) -> Result<()> {
+        trace!(command=?self.command, "Executing Auth command.", );
+
         let env_metadata = utils::load_metadata_from_config(config)?;
+        trace!(metadata=?env_metadata, "Loaded environment.");
 
         match self.command {
             AuthCommand::Grant { kind, world, starknet, account, transaction } => config
@@ -102,14 +106,23 @@ pub async fn grant(
     kind: AuthKind,
     transaction: TransactionOptions,
 ) -> Result<()> {
+    trace!(?kind, ?world, ?starknet, ?account, ?transaction, "Executing Grant command.");
     let world =
         utils::world_from_env_metadata(world, account, starknet, &env_metadata).await.unwrap();
 
     match kind {
         AuthKind::Writer { models_contracts } => {
+            trace!(
+                contracts=?models_contracts,
+                "Granting Writer permissions."
+            );
             auth::grant_writer(&world, models_contracts, transaction.into()).await
         }
         AuthKind::Owner { owners_resources } => {
+            trace!(
+                resources=?owners_resources,
+                "Granting Owner permissions."
+            );
             auth::grant_owner(&world, owners_resources, transaction.into()).await
         }
     }
@@ -123,13 +136,22 @@ pub async fn revoke(
     kind: AuthKind,
     transaction: TransactionOptions,
 ) -> Result<()> {
+    trace!(?kind, ?world, ?starknet, ?account, ?transaction, "Executing Revoke command.");
     let world =
         utils::world_from_env_metadata(world, account, starknet, &env_metadata).await.unwrap();
     match kind {
         AuthKind::Writer { models_contracts } => {
+            trace!(
+                contracts=?models_contracts,
+                "Revoking Writer permissions."
+            );
             auth::revoke_writer(&world, models_contracts, transaction.into()).await
         }
         AuthKind::Owner { owners_resources } => {
+            trace!(
+                resources=?owners_resources,
+                "Revoking Owner permissions."
+            );
             auth::revoke_owner(&world, owners_resources, transaction.into()).await
         }
     }

diff --git a/bin/sozo/src/commands/build.rs b/bin/sozo/src/commands/build.rs
@@ -7,6 +7,7 @@ use prettytable::{format, Cell, Row, Table};
 use scarb::core::{Config, TargetKind};
 use scarb::ops::CompileOpts;
 use sozo_ops::statistics::{get_contract_statistics_for_dir, ContractStatistics};
+use tracing::trace;
 
 #[derive(Debug, Args)]
 pub struct BuildArgs {
@@ -36,6 +37,7 @@ impl BuildArgs {
             config,
             CompileOpts { include_targets: vec![], exclude_targets: vec![TargetKind::TEST] },
         )?;
+        trace!(?compile_info, "Compiled workspace.");
 
         let mut builtin_plugins = vec![];
         if self.typescript {
@@ -54,6 +56,12 @@ impl BuildArgs {
             let target_dir = &compile_info.target_dir;
             let contracts_statistics = get_contract_statistics_for_dir(target_dir)
                 .context("Error getting contracts stats")?;
+            trace!(
+                ?contracts_statistics,
+                ?target_dir,
+                "Read contract statistics for target directory."
+            );
+
             let table = create_stats_table(contracts_statistics);
             table.printstd()
         }
@@ -69,6 +77,7 @@ impl BuildArgs {
             plugins: vec![],
             builtin_plugins,
         };
+        trace!(pluginManager=?bindgen, "Generating bindings.");
 
         tokio::runtime::Runtime::new()
             .unwrap()
@@ -95,7 +104,6 @@ fn create_stats_table(contracts_statistics: Vec<ContractStatistics>) -> Table {
         let contract_name = contract_stats.contract_name;
         let number_felts = contract_stats.number_felts;
         let file_size = contract_stats.file_size;
-
         table.add_row(Row::new(vec![
             Cell::new_align(&contract_name, format::Alignment::LEFT),
             Cell::new_align(format!("{}", number_felts).as_str(), format::Alignment::RIGHT),

diff --git a/bin/sozo/src/commands/call.rs b/bin/sozo/src/commands/call.rs
@@ -2,6 +2,7 @@ use anyhow::Result;
 use clap::Args;
 use scarb::core::Config;
 use starknet::core::types::FieldElement;
+use tracing::trace;
 
 use super::options::starknet::StarknetOptions;
 use super::options::world::WorldOptions;
@@ -35,8 +36,10 @@ pub struct CallArgs {
 
 impl CallArgs {
     pub fn run(self, config: &Config) -> Result<()> {
-        let env_metadata = utils::load_metadata_from_config(config)?;
+        trace!(contract=?self.contract, entrypoint=self.entrypoint, calldata=?self.calldata, block_id=self.block_id, "Executing Call command.");
 
+        let env_metadata = utils::load_metadata_from_config(config)?;
+        trace!(?env_metadata, "Loaded metadata from config.");
         config.tokio_handle().block_on(async {
             let world_reader =
                 utils::world_reader_from_env_metadata(self.world, self.starknet, &env_metadata)

diff --git a/bin/sozo/src/commands/clean.rs b/bin/sozo/src/commands/clean.rs
@@ -5,6 +5,7 @@ use camino::Utf8PathBuf;
 use clap::Args;
 use dojo_lang::compiler::{ABIS_DIR, BASE_DIR, MANIFESTS_DIR};
 use scarb::core::Config;
+use tracing::trace;
 
 #[derive(Debug, Args)]
 pub struct CleanArgs {
@@ -21,10 +22,12 @@ impl CleanArgs {
     ///
     /// * `profile_dir` - The directory where the profile files are located.
     pub fn clean_manifests(&self, profile_dir: &Utf8PathBuf) -> Result<()> {
+        trace!(?profile_dir, "Cleaning manifests.");
         let dirs = vec![profile_dir.join(BASE_DIR), profile_dir.join(ABIS_DIR).join(BASE_DIR)];
 
         for d in dirs {
             if d.exists() {
+                trace!(directory=?d, "Removing directory.");
                 fs::remove_dir_all(d)?;
             }
         }
@@ -34,6 +37,7 @@ impl CleanArgs {
 
     pub fn run(self, config: &Config) -> Result<()> {
         let ws = scarb::ops::read_workspace(config.manifest_path(), config)?;
+        trace!(ws=?ws, "Workspace read successfully.");
 
         let profile_name =
             ws.current_profile().expect("Scarb profile is expected at this point.").to_string();
@@ -45,10 +49,12 @@ impl CleanArgs {
         let profile_dir = manifest_dir.join(MANIFESTS_DIR).join(profile_name);
 
         // By default, this command cleans the build manifests and scarb artifacts.
+        trace!("Cleaning Scarb artifacts and build manifests.");
         scarb::ops::clean(config)?;
         self.clean_manifests(&profile_dir)?;
 
         if self.all && profile_dir.exists() {
+            trace!(?profile_dir, "Removing entire profile directory.");
             fs::remove_dir_all(profile_dir)?;
         }
 

diff --git a/bin/sozo/src/commands/dev.rs b/bin/sozo/src/commands/dev.rs
@@ -23,15 +23,13 @@ use starknet::accounts::SingleOwnerAccount;
 use starknet::core::types::FieldElement;
 use starknet::providers::Provider;
 use starknet::signers::Signer;
-use tracing::error;
+use tracing::{error, trace};
 
 use super::migrate::setup_env;
 use super::options::account::AccountOptions;
 use super::options::starknet::StarknetOptions;
 use super::options::world::WorldOptions;
 
-pub(crate) const LOG_TARGET: &str = "sozo::cli::commands::dev";
-
 #[derive(Debug, Args)]
 pub struct DevArgs {
     #[arg(long)]
@@ -57,10 +55,12 @@ impl DevArgs {
         let env_metadata = if config.manifest_path().exists() {
             dojo_metadata_from_workspace(&ws).env().cloned()
         } else {
+            trace!("Manifest path does not exist.");
             None
         };
 
         let mut context = load_context(config)?;
+
         let (tx, rx) = channel();
         let mut debouncer = new_debouncer(Duration::from_secs(1), None, tx)?;
 
@@ -88,7 +88,7 @@ impl DevArgs {
             ))
             .ok()
         else {
-            return Err(anyhow!("Failed to setup environment"));
+            return Err(anyhow!("Failed to setup environment."));
         };
 
         match context.ws.config().tokio_handle().block_on(migrate(
@@ -104,7 +104,6 @@ impl DevArgs {
             }
             Err(error) => {
                 error!(
-                    target: LOG_TARGET,
                     error = ?error,
                     address = ?world_address,
                     "Migrating world."
@@ -120,7 +119,7 @@ impl DevArgs {
                     .unwrap_or(DevAction::None),
                 Ok(Err(_)) => DevAction::None,
                 Err(error) => {
-                    error!(target: LOG_TARGET, error = ?error, "Receiving dev action.");
+                    error!(error = ?error, "Receiving dev action.");
                     break;
                 }
             };
@@ -139,7 +138,6 @@ impl DevArgs {
                     }
                     Err(error) => {
                         error!(
-                            target: LOG_TARGET,
                             error = ?error,
                             address = ?world_address,
                             "Migrating world.",
@@ -152,7 +150,7 @@ impl DevArgs {
     }
 }
 
-#[derive(Clone, PartialEq, Eq, PartialOrd, Ord)]
+#[derive(Clone, PartialEq, Eq, PartialOrd, Ord, Debug)]
 enum DevAction {
     None,
     Reload,
@@ -176,6 +174,8 @@ fn handle_event(event: &DebouncedEvent) -> DevAction {
         }
         _ => DevAction::None,
     };
+
+    trace!(?action, "Determined action.");
     action
 }
 
@@ -196,6 +196,7 @@ fn load_context(config: &Config) -> Result<DevContext<'_>> {
 
     // we have only 1 unit in projects
     // TODO: double check if we always have one with the new version and the order if many.
+    trace!(unit_count = compilation_units.len(), "Gathering compilation units.");
     let unit = compilation_units.first().unwrap();
     let db = build_scarb_root_database(unit).unwrap();
     Ok(DevContext { db, unit: unit.clone(), ws })
@@ -267,6 +268,7 @@ where
 }
 
 fn process_event(event: &DebouncedEvent, context: &mut DevContext<'_>) -> DevAction {
+    trace!(event=?event, "Processing event.");
     let action = handle_event(event);
     match &action {
         DevAction::None => {}
@@ -275,6 +277,8 @@ fn process_event(event: &DebouncedEvent, context: &mut DevContext<'_>) -> DevAct
             handle_reload_action(context);
         }
     }
+
+    trace!(action=?action, "Processed action.");
     action
 }
 
@@ -291,8 +295,10 @@ fn handle_build_action(path: &Path, context: &mut DevContext<'_>) {
 }
 
 fn handle_reload_action(context: &mut DevContext<'_>) {
+    trace!("Reloading context.");
     let config = context.ws.config();
     config.ui().print("Reloading project");
     let new_context = load_context(config).expect("Failed to load context");
     let _ = mem::replace(context, new_context);
+    trace!("Context reloaded.");
 }