tracing: added calling of tracing macros for logging

Also
- added env variables displaying to command
  which is used to run the game
- added `#[inline]` macros to some functions

anime-game-core

@@ -1 +1 @@
-Subproject commit bd10a7505f5709183b9858c581fe6bc210fa860d
+Subproject commit a81e5bbecf99c9bc6003a915dd1266783661ca58

src/components/dxvk.rs

@@ -32,19 +32,23 @@ pub struct Version {
 
 impl Version {
     /// Get latest recommended dxvk version
+    #[inline]
     pub fn latest() -> Self {
         get_groups()[0].versions[0].clone()
     }
 
     /// Check is current dxvk downloaded in specified folder
-    #[tracing::instrument(level = "trace")]
+    #[inline]
     pub fn is_downloaded_in<T: Into<PathBuf> + std::fmt::Debug>(&self, folder: T) -> bool {
         folder.into().join(&self.name).exists()
     }
 
     /// Install current dxvk
     #[tracing::instrument(level = "debug")]
+    #[inline]
     pub fn install<T: Into<PathBuf> + std::fmt::Debug>(&self, dxvks_folder: T, wine: &Wine, params: InstallParams) -> std::io::Result<()> {
+        tracing::debug!("Installing DXVK");
+
         Dxvk::install(
             wine,
             dxvks_folder.into().join(&self.name),
@@ -54,7 +58,10 @@ impl Version {
 
     /// Uninstall current dxvk
     #[tracing::instrument(level = "debug")]
+    #[inline]
     pub fn uninstall(&self, wine: &Wine, params: InstallParams) -> std::io::Result<()> {
+        tracing::debug!("Uninstalling DXVK");
+
         Dxvk::uninstall(
             wine,
             params
@@ -63,13 +70,13 @@ impl Version {
 }
 
 /// Get dxvk groups
+#[inline]
 pub fn get_groups() -> Vec<Group> {
     GROUPS.clone()
 }
 
 /// List downloaded dxvk versions in some specific folder
-#[tracing::instrument(level = "trace")]
-pub fn get_downloaded<T: Into<PathBuf> + std::fmt::Debug>(folder: T) -> std::io::Result<Vec<Version>> {
+pub fn get_downloaded<T: Into<PathBuf>>(folder: T) -> std::io::Result<Vec<Version>> {
     let mut downloaded = Vec::new();
 
     let list = get_groups()

src/components/wine.rs

@@ -41,12 +41,13 @@ pub struct Version {
 
 impl Version {
     /// Get latest recommended wine version
+    #[inline]
     pub fn latest() -> Self {
         get_groups()[0].versions[0].clone()
     }
 
     /// Check is current wine downloaded in specified folder
-    #[tracing::instrument(level = "trace")]
+    #[inline]
     pub fn is_downloaded_in<T: Into<PathBuf> + std::fmt::Debug>(&self, folder: T) -> bool {
         folder.into().join(&self.name).exists()
     }
@@ -54,6 +55,7 @@ impl Version {
     /// Convert current wine struct to one from `wincompatlib`
     /// 
     /// `wine_folder` should point to the folder with wine binaries, so e.g. `/path/to/runners/wine-proton-ge-7.11`
+    #[inline]
     pub fn to_wine<T: Into<PathBuf>>(&self, wine_folder: Option<T>) -> Wine {
         let wine_folder = wine_folder.map(|folder| folder.into()).unwrap_or_default();
 
@@ -78,12 +80,12 @@ pub struct Files {
 }
 
 /// Get wine groups
+#[inline]
 pub fn get_groups() -> Vec<Group> {
     GROUPS.clone()
 }
 
 /// List downloaded wine versions in some specific folder
-#[tracing::instrument(level = "trace")]
 pub fn get_downloaded<T: Into<PathBuf> + std::fmt::Debug>(folder: T) -> std::io::Result<Vec<Version>> {
     let mut downloaded = Vec::new();
 

src/config/mod.rs

@@ -43,8 +43,10 @@ pub fn get() -> anyhow::Result<Config> {
 /// Get config data
 /// 
 /// This method will always load data directly from the file and update in-memory config
-#[tracing::instrument(level = "debug")]
+#[tracing::instrument(level = "debug", ret)]
 pub fn get_raw() -> anyhow::Result<Config> {
+    tracing::debug!("Reading config data from file");
+
     match config_file() {
         Some(path) => {
             // Try to read config if the file exists
@@ -64,7 +66,11 @@ pub fn get_raw() -> anyhow::Result<Config> {
 
                         Ok(config)
                     },
-                    Err(err) => Err(anyhow::anyhow!("Failed to decode data from json format: {}", err.to_string()))
+                    Err(err) => {
+                        tracing::error!("Failed to decode config data from json format: {}", err.to_string());
+
+                        Err(anyhow::anyhow!("Failed to decode config data from json format: {}", err.to_string()))
+                    }
                 }
             }
 
@@ -75,7 +81,11 @@ pub fn get_raw() -> anyhow::Result<Config> {
                 Ok(Config::default())
             }
         },
-        None => Err(anyhow::anyhow!("Failed to get config file path"))
+        None => {
+            tracing::error!("Failed to get config file path");
+
+            Err(anyhow::anyhow!("Failed to get config file path"))
+        }
     }
 }
 
@@ -84,6 +94,8 @@ pub fn get_raw() -> anyhow::Result<Config> {
 /// Use `update_raw` if you want to update config file itself
 #[tracing::instrument(level = "trace")]
 pub fn update(config: Config) {
+    tracing::trace!("Updating hot config record");
+
     unsafe {
         CONFIG = Some(config);
     }
@@ -92,8 +104,10 @@ pub fn update(config: Config) {
 /// Update config file
 /// 
 /// This method will also update in-memory config data
-#[tracing::instrument(level = "debug")]
+#[tracing::instrument(level = "debug", ret)]
 pub fn update_raw(config: Config) -> anyhow::Result<()> {
+    tracing::debug!("Updating config data");
+
     update(config.clone());
 
     match config_file() {
@@ -106,20 +120,34 @@ pub fn update_raw(config: Config) -> anyhow::Result<()> {
 
                     Ok(())
                 },
-                Err(err) => Err(anyhow::anyhow!("Failed to encode data into json format: {}", err.to_string()))
+                Err(err) => {
+                    tracing::error!("Failed to encode config data into json format: {}", err.to_string());
+
+                    Err(anyhow::anyhow!("Failed to encode config data into json format: {}", err.to_string()))
+                }
             }
         },
-        None => Err(anyhow::anyhow!("Failed to get config file path"))
+        None => {
+            tracing::error!("Failed to get config file path");
+
+            Err(anyhow::anyhow!("Failed to get config file path"))
+        }
     }
 }
 
 /// Update config file from the in-memory saved config
-#[tracing::instrument(level = "debug")]
+#[tracing::instrument(level = "debug", ret)]
 pub fn flush() -> anyhow::Result<()> {
+    tracing::debug!("Flushing config data");
+
     unsafe {
         match &CONFIG {
             Some(config) => update_raw(config.clone()),
-            None => Err(anyhow::anyhow!("Config wasn't loaded into the memory"))
+            None => {
+                tracing::error!("Config wasn't loaded into the memory");
+
+                Err(anyhow::anyhow!("Config wasn't loaded into the memory"))
+            }
         }
     }
 }
@@ -162,7 +190,6 @@ use crate::components::dxvk::{self, Version as DxvkVersion};
 
 #[cfg(feature = "components")]
 impl Config {
-    #[tracing::instrument(level = "debug")]
     pub fn try_get_selected_wine_info(&self) -> Option<WineVersion> {
         match &self.game.wine.selected {
             Some(selected) => {
@@ -180,7 +207,6 @@ impl Config {
     /// Returns `Some("wine64")` if:
     /// 1) `game.wine.selected = None`
     /// 2) wine64 installed and available in system
-    #[tracing::instrument(level = "debug")]
     pub fn try_get_wine_executable(&self) -> Option<PathBuf> {
         match self.try_get_selected_wine_info() {
             Some(selected) => Some(self.game.wine.builds.join(selected.name).join(selected.files.wine64)),
@@ -200,7 +226,6 @@ impl Config {
     /// 1) `Ok(Some(..))` if version was found
     /// 2) `Ok(None)` if version wasn't found, so too old or dxvk is not applied
     /// 3) `Err(..)` if failed to get applied dxvk version, likely because wrong prefix path specified
-    #[tracing::instrument(level = "debug")]
     pub fn try_get_selected_dxvk_info(&self) -> std::io::Result<Option<DxvkVersion>> {
         Ok(match wincompatlib::dxvk::Dxvk::get_version(&self.game.wine.prefix)? {
             Some(version) => {
@@ -213,3 +238,4 @@ impl Config {
         })
     }
 }
+

src/consts.rs

@@ -10,7 +10,7 @@ pub const PATCH_FETCHING_TIMEOUT: Option<Duration> = Some(Duration::from_secs(5)
 /// Get default launcher dir path
 /// 
 /// `$HOME/.local/share/anime-game-launcher`
-#[tracing::instrument(level = "trace")]
+#[inline]
 pub fn launcher_dir() -> Option<PathBuf> {
     dirs::data_dir().map(|dir| dir.join("anime-game-launcher"))
 }
@@ -18,7 +18,7 @@ pub fn launcher_dir() -> Option<PathBuf> {
 /// Get default config file path
 /// 
 /// `$HOME/.local/share/anime-game-launcher/config.json`
-#[tracing::instrument(level = "trace")]
+#[inline]
 pub fn config_file() -> Option<PathBuf> {
     launcher_dir().map(|dir| dir.join("config.json"))
 }

src/fps_unlocker/mod.rs

@@ -23,7 +23,6 @@ impl FpsUnlocker {
     /// - `Err(..)` if failed to read `unlocker.exe` file
     /// - `Ok(None)` if version is not latest
     /// - `Ok(..)` if version is latest
-    #[tracing::instrument(level = "trace")]
     pub fn from_dir<T: Into<PathBuf> + std::fmt::Debug>(dir: T) -> anyhow::Result<Option<Self>> {
         let dir = dir.into();
 
@@ -39,6 +38,8 @@ impl FpsUnlocker {
     /// Download FPS unlocker to specified directory
     #[tracing::instrument(level = "debug")]
     pub fn download<T: Into<PathBuf> + std::fmt::Debug>(dir: T) -> anyhow::Result<Self> {
+        tracing::debug!("Downloading FPS unlocker");
+
         let mut downloader = Downloader::new(LATEST_INFO.1)?;
 
         let dir = dir.into();
@@ -55,6 +56,8 @@ impl FpsUnlocker {
             Err(err) => {
                 let err: std::io::Error = err.into();
 
+                tracing::error!("Downloading failed: {}", err.to_string());
+
                 Err(err.into())
             }
         }
@@ -73,8 +76,10 @@ impl FpsUnlocker {
     }
 
     /// Generate and save FPS unlocker config file to the game's directory
-    #[tracing::instrument(level = "debug")]
+    #[tracing::instrument(level = "debug", ret)]
     pub fn update_config(&self, config: FpsUnlockerConfig) -> anyhow::Result<()> {
+        tracing::debug!("Updating FPS unlocker config");
+
         let config = config_schema::ConfigSchema::from_config(config);
 
         Ok(std::fs::write(
@@ -83,3 +88,4 @@ impl FpsUnlocker {
         )?)
     }
 }
+

src/game/mod.rs

@@ -11,8 +11,10 @@ use super::fps_unlocker::FpsUnlocker;
 /// Try to run the game
 /// 
 /// If `debug = true`, then the game will be run in the new terminal window
-#[tracing::instrument(level = "info")]
+#[tracing::instrument(level = "info", ret)]
 pub fn run() -> anyhow::Result<()> {
+    tracing::info!("Preparing to run the game");
+
     let config = config::get()?;
 
     if !config.game.path.exists() {
@@ -26,6 +28,8 @@ pub fn run() -> anyhow::Result<()> {
 
     // Check telemetry servers
 
+    tracing::info!("Checking telemetry");
+
     if let Some(server) = telemetry::is_disabled(consts::TELEMETRY_CHECK_TIMEOUT) {
         return Err(anyhow::anyhow!("Telemetry server is not disabled: {server}"));
     }
@@ -37,6 +41,8 @@ pub fn run() -> anyhow::Result<()> {
 
     #[cfg(feature = "fps-unlocker")]
     if config.game.enhancements.fps_unlocker.enabled {
+        tracing::info!("Preparing FPS unlocker");
+
         let unlocker = match FpsUnlocker::from_dir(&config.game.enhancements.fps_unlocker.path) {
             Ok(Some(unlocker)) => unlocker,
 
@@ -47,6 +53,8 @@ pub fn run() -> anyhow::Result<()> {
                     std::fs::remove_file(FpsUnlocker::get_binary_in(&config.game.enhancements.fps_unlocker.path))?;
                 }
 
+                tracing::info!("Unlocker is not downloaded. Downloading");
+
                 match FpsUnlocker::download(&config.game.enhancements.fps_unlocker.path) {
                     Ok(unlocker) => unlocker,
                     Err(err) => return Err(anyhow::anyhow!("Failed to download FPS unlocker: {err}"))
@@ -133,7 +141,12 @@ pub fn run() -> anyhow::Result<()> {
 
     // Run command
 
-    println!("Running command: bash -c \"{}\"", bash_chain);
+    let variables = command
+        .get_envs()
+        .map(|(key, value)| format!("{:?}=\"{:?}\"", key, value.unwrap_or_default()))
+        .fold(String::new(), |acc, env| acc + " " + &env);
+
+    tracing::info!("Running the game with command: {variables} bash -c \"{bash_chain}\"");
 
     command.current_dir(config.game.path).spawn()?;
 

src/lib.rs

@@ -26,8 +26,10 @@ pub mod fps_unlocker;
 /// assert!(anime_launcher_sdk::is_available("bash"));
 /// ```
 #[allow(unused_must_use)]
-#[tracing::instrument(level = "trace")]
+#[tracing::instrument(level = "trace", ret)]
 pub fn is_available(binary: &str) -> bool {
+    tracing::trace!("Checking package availability");
+
     match Command::new(binary).stdout(Stdio::null()).stderr(Stdio::null()).spawn() {
         Ok(mut child) => {
             child.kill();

src/states/mod.rs

@@ -57,13 +57,15 @@ pub enum StateUpdating {
 }
 
 impl LauncherState {
-    #[tracing::instrument(level = "debug", skip(status))]
+    #[tracing::instrument(level = "debug", skip(status), ret)]
     pub fn get<T, F, S>(wine_prefix: T, game_path: T, voices: Vec<VoiceLocale>, patch_servers: Vec<S>, status: F) -> anyhow::Result<Self>
     where
         T: Into<PathBuf> + std::fmt::Debug,
         F: Fn(StateUpdating),
         S: ToString + std::fmt::Debug
     {
+        tracing::debug!("Trying to get launcher state");
+
         let wine_prefix = wine_prefix.into();
         let game_path = game_path.into();
 
@@ -137,8 +139,10 @@ impl LauncherState {
     }
 
     #[cfg(feature = "config")]
-    #[tracing::instrument(level = "debug", skip(status))]
+    #[tracing::instrument(level = "debug", skip(status), ret)]
     pub fn get_from_config<T: Fn(StateUpdating)>(status: T) -> anyhow::Result<Self> {
+        tracing::debug!("Trying to get launcher state");
+
         let config = crate::config::get()?;
 
         // Check wine existence