add tracing crate for logging

Cargo.toml

@@ -30,7 +30,8 @@ getset = "0.1.2"
 mlua = { version = "0.9.7", features = ["lua54", "vendored"], optional = true }
 path-absolutize = "3.1.1"
 serde = { version = "1.0.197", features = ["derive", "rc"], optional = true }
-shulkerbox = { git = "https://github.com/moritz-hoelting/shulkerbox", default-features = false, optional = true, rev = "b79c9ecd6d45f9319c9083a8103ef0186839b0c0" }
+shulkerbox = { git = "https://github.com/moritz-hoelting/shulkerbox", default-features = false, optional = true, rev = "e31f9f904a5f5905e912907d988c189ffc8cf313" }
 strum = { version = "0.26.2", features = ["derive"] }
 strum_macros = "0.26.2"
 thiserror = "1.0.58"
+tracing = "0.1.40"

src/lexical/token_stream.rs

@@ -45,6 +45,7 @@ impl TokenStream {
     /// A tuple containing the stream of successfully tokenized tokens and a list of lexical errors
     /// encountered during tokenization.
     #[must_use]
+    #[tracing::instrument(level = "debug", skip_all, fields(source_file = %source_file.path().display()))]
     pub fn tokenize(source_file: &Arc<SourceFile>, handler: &impl Handler<error::Error>) -> Self {
         // The list of token trees that will be returned.
         let mut tokens = Vec::new();
@@ -57,13 +58,17 @@ impl TokenStream {
                 Err(TokenizeError::EndOfSourceCodeIteratorArgument) => {
                     break;
                 }
-                Err(TokenizeError::FatalLexicalError) => (),
+                Err(TokenizeError::FatalLexicalError) => {
+                    tracing::error!("Fatal lexical error encountered while tokenizing source code");
+                }
             }
         }
 
         // reverse to use pop() instead of remove(0)
         tokens.reverse();
 
+        tracing::debug!("Structuring tokens into trees");
+
         // stucture the tokens into a token stream
         let mut token_trees = Vec::new();
         while let Some(token_tree) = Self::handle_token(&mut tokens, handler) {

src/public_helpers.rs

@@ -15,6 +15,8 @@ use shulkerbox::{datapack::Datapack, util::compile::CompileOptions, virtual_fs::
 
 /// Tokenizes the source code at the given path.
 pub fn tokenize(printer: &Printer, path: &Path) -> Result<TokenStream> {
+    tracing::info!("Tokenizing the source code at path: {}", path.display());
+
     let source_file = SourceFile::load(path)?;
 
     Ok(TokenStream::tokenize(&source_file, printer))
@@ -30,6 +32,8 @@ pub fn parse(printer: &Printer, path: &Path) -> Result<ProgramFile> {
         ));
     }
 
+    tracing::info!("Parsing the source code at path: {}", path.display());
+
     let mut parser = Parser::new(&tokens);
     let program = parser.parse_program(printer).ok_or(Error::Other(
         "An error occured while parsing the source code.",
@@ -67,6 +71,8 @@ where
         .filter_map(Result::ok)
         .collect::<Vec<_>>();
 
+    tracing::info!("Transpiling the source code.");
+
     let mut transpiler = Transpiler::new(27);
     transpiler.transpile(&programs, printer)?;
     let datapack = transpiler.into_datapack();
@@ -88,5 +94,7 @@ where
 {
     let datapack = transpile(printer, script_paths)?;
 
+    tracing::info!("Compiling the source code.");
+
     Ok(datapack.compile(&CompileOptions::default()))
 }

src/syntax/syntax_tree/declaration.rs

@@ -278,6 +278,7 @@ impl<'a> Parser<'a> {
         }
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn parse_declaration(&mut self, handler: &impl Handler<Error>) -> Option<Declaration> {
         match self.stop_at_significant() {
             Reading::Atomic(Token::Keyword(function_keyword))
@@ -285,6 +286,8 @@ impl<'a> Parser<'a> {
             {
                 let function = self.parse_function(handler)?;
 
+                tracing::trace!("Parsed function '{:?}'", function.identifier.span.str());
+
                 Some(Declaration::Function(function))
             }
 
@@ -361,6 +364,8 @@ impl<'a> Parser<'a> {
                 if let Some(items) = items {
                     let semicolon = self.parse_punctuation(';', true, handler)?;
 
+                    tracing::trace!("Parsed import from '{:?}'", module.str_content());
+
                     Some(Declaration::Import(Import {
                         from_keyword,
                         module,

src/syntax/syntax_tree/program.rs

@@ -78,7 +78,10 @@ impl Namespace {
 
 impl<'a> Parser<'a> {
     /// Parses a [`ProgramFile`].
+    #[tracing::instrument(level = "debug", skip_all)]
     pub fn parse_program(&mut self, handler: &impl Handler<Error>) -> Option<ProgramFile> {
+        tracing::debug!("Parsing program");
+
         let namespace = match self.stop_at_significant() {
             Reading::Atomic(Token::Keyword(namespace_keyword))
                 if namespace_keyword.keyword == KeywordKind::Namespace =>
@@ -110,6 +113,11 @@ impl<'a> Parser<'a> {
             }
         }?;
 
+        tracing::debug!(
+            "Found namespace '{}', parsing declarations",
+            namespace.namespace_name.str_content()
+        );
+
         let mut declarations = Vec::new();
 
         while !self.is_exhausted() {

src/syntax/syntax_tree/statement.rs

@@ -249,11 +249,13 @@ impl<'a> Parser<'a> {
     }
 
     /// Parses a [`Statement`].
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn parse_statement(&mut self, handler: &impl Handler<Error>) -> Option<Statement> {
         match self.stop_at_significant() {
             // variable declaration
             Reading::Atomic(Token::CommandLiteral(command)) => {
                 self.forward();
+                tracing::trace!("Parsed literal command '{}'", command.clean_command());
                 Some(Statement::LiteralCommand(command))
             }
             // block statement
@@ -286,6 +288,8 @@ impl<'a> Parser<'a> {
 
                 let block = self.parse_block(handler)?;
 
+                tracing::trace!("Parsed group command");
+
                 Some(Statement::Grouping(Grouping {
                     group_keyword,
                     block,
@@ -302,6 +306,8 @@ impl<'a> Parser<'a> {
                 let expression = self.parse_expression(handler)?;
                 let semicolon = self.parse_punctuation(';', true, handler)?;
 
+                tracing::trace!("Parsed run statement: {:?}", expression);
+
                 Some(Statement::Run(Run {
                     run_keyword,
                     expression,
@@ -314,6 +320,8 @@ impl<'a> Parser<'a> {
                 let expression = self.parse_expression(handler)?;
                 let semicolon = self.parse_punctuation(';', true, handler)?;
 
+                tracing::trace!("Parsed semicolon statement: {:?}", expression);
+
                 Some(Statement::Semicolon(Semicolon {
                     expression,
                     semicolon,

src/transpile/lua.rs

@@ -15,10 +15,13 @@ mod enabled {
         ///
         /// # Errors
         /// - If Lua code evaluation is disabled.
+        #[tracing::instrument(level = "debug", name = "eval_lua", skip_all, ret)]
         pub fn eval_string(
             &self,
             handler: &impl Handler<TranspileError>,
         ) -> TranspileResult<String> {
+            tracing::debug!("Evaluating Lua code");
+
             let lua = Lua::new();
 
             let name = {
@@ -89,6 +92,7 @@ mod disabled {
             handler: &impl Handler<TranspileError>,
         ) -> TranspileResult<String> {
             handler.receive(TranspileError::LuaDisabled);
+            tracing::error!("Lua code evaluation is disabled");
             Err(TranspileError::LuaDisabled)
         }
     }

src/transpile/transpiler.rs

@@ -60,6 +60,7 @@ impl Transpiler {
     ///
     /// # Errors
     /// - [`TranspileError::MissingFunctionDeclaration`] If a called function is missing
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn transpile<Ident>(
         &mut self,
         programs: &[(Ident, ProgramFile)],
@@ -68,6 +69,8 @@ impl Transpiler {
     where
         Ident: AsRef<str>,
     {
+        tracing::trace!("Transpiling program declarations");
+
         for (identifier, program) in programs {
             self.transpile_program_declarations(program, identifier.as_ref(), handler);
         }
@@ -87,6 +90,11 @@ impl Transpiler {
             }
         }
 
+        tracing::trace!(
+            "Transpiling functions requested by user: {:?}",
+            always_transpile_functions
+        );
+
         for (program_identifier, name) in always_transpile_functions {
             self.get_or_transpile_function(&name, &program_identifier, handler)?;
         }
@@ -171,6 +179,7 @@ impl Transpiler {
     /// Gets the function at the given path, or transpiles it if it hasn't been transpiled yet.
     /// Returns the location of the function or None if the function does not exist.
     #[allow(clippy::significant_drop_tightening)]
+    #[tracing::instrument(level = "trace", skip(self, handler))]
     fn get_or_transpile_function(
         &mut self,
         name: &str,
@@ -194,6 +203,8 @@ impl Transpiler {
                 .is_some()
         };
         if !already_transpiled {
+            tracing::trace!("Function not transpiled yet, transpiling.");
+
             let statements = {
                 let functions = self.functions.read().unwrap();
                 let function_data = functions