Improve debug output in vfs/src/dokan/mod.rs

vfs/src/dokan/mod.rs

@@ -188,7 +188,7 @@ impl VirtualFilesystem {
         delete_on_close: bool,
         delete_access: bool,
     ) -> Result<(Entry, bool, u64), Error> {
-        tracing::trace!("create_entry");
+        tracing::trace!("enter");
 
         let (shared, id) = self.get_or_set_shared(path.clone(), delete_on_close).await;
 
@@ -310,7 +310,7 @@ impl VirtualFilesystem {
 
     // https://learn.microsoft.com/en-us/windows/win32/api/fileapi/nf-fileapi-createfilea
     // https://learn.microsoft.com/en-us/windows/win32/api/winternl/nf-winternl-ntcreatefile
-    #[instrument(skip_all, fields(file_name = ?to_path(file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?file_name), err(Debug))]
     #[allow(clippy::too_many_arguments)]
     async fn async_create_file<'c, 'h: 'c>(
         &'h self,
@@ -322,7 +322,7 @@ impl VirtualFilesystem {
         create_disposition: u32,
         create_options: u32,
     ) -> Result<CreateFileInfo<EntryHandle>, Error> {
-        tracing::trace!("async_create_file");
+        tracing::debug!("enter");
 
         let create_disposition = create_disposition.try_into()?;
         let delete_on_close = create_options & FILE_DELETE_ON_CLOSE > 0;
@@ -374,14 +374,14 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _file_name, _info, context), fields(file_name = ?to_path(_file_name)))]
+    #[instrument(skip_all, fields(?file_name))]
     async fn async_close_file<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
-        _file_name: &U16CStr,
+        file_name: &U16CStr,
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) {
-        tracing::trace!("async_close_file");
+        tracing::debug!("enter");
 
         match &context.entry {
             Entry::File(entry) => {
@@ -434,7 +434,7 @@ impl VirtualFilesystem {
             .block_on(self.async_close_file(file_name, info, context))
     }
 
-    #[instrument(skip(self, _file_name, buffer, _info, context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name, offset), err(Debug))]
     async fn async_read_file<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
@@ -443,7 +443,7 @@ impl VirtualFilesystem {
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<u32, Error> {
-        tracing::trace!("async_read_file");
+        tracing::trace!("enter");
 
         let entry = match &context.entry {
             Entry::File(entry) => entry,
@@ -475,7 +475,7 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _file_name, buffer, info, context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name, offset), err(Debug))]
     async fn async_write_file<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
@@ -502,7 +502,6 @@ impl VirtualFilesystem {
             file.seek(SeekFrom::Start(offset));
         }
 
-        tracing::trace!("L{} async_write_file", line!());
         file.fork(local_branch).await?;
         file.write_all(buffer).await?;
 
@@ -522,14 +521,14 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _info, context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name), err(Debug))]
     async fn async_flush_file_buffers<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_flush_file_buffers");
+        tracing::debug!("enter");
         match &context.entry {
             Entry::File(entry) => {
                 let mut lock = entry.file.lock().await;
@@ -553,14 +552,14 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _info, context), fields(file_name = ?to_path(file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?file_name), err(Debug))]
     async fn async_get_file_information<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         file_name: &U16CStr,
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<FileInfo, Error> {
-        tracing::trace!("async_get_file_information");
+        tracing::debug!("enter");
 
         let (attributes, file_size) = match &context.entry {
             Entry::File(entry) => {
@@ -600,15 +599,15 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, file_name, fill_find_data, _info, context), fields(file_name = ?to_path(file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?file_name), err(Debug))]
     async fn async_find_files<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         file_name: &U16CStr,
         fill_find_data: impl FnMut(&FindData) -> FillDataResult,
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_find_files");
+        tracing::trace!("enter");
         let dir_entry = context.entry.as_directory()?;
         self.find_files_impl(fill_find_data, dir_entry, None).await
     }
@@ -625,7 +624,7 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, file_name, pattern, fill_find_data, _info, context), fields(file_name = ?to_path(file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?file_name), err(Debug))]
     async fn async_find_files_with_pattern<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         file_name: &U16CStr,
@@ -634,7 +633,7 @@ impl VirtualFilesystem {
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_find_files_with_pattern");
+        tracing::trace!("enter");
         let dir_entry = context.entry.as_directory()?;
         self.find_files_impl(fill_find_data, dir_entry, Some(pattern))
             .await
@@ -659,15 +658,15 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _file_name, _file_attributes, _info, _context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name), err(Debug))]
     async fn async_set_file_attributes<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
         _file_attributes: u32,
         _info: &OperationInfo<'c, 'h, Super>,
         _context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_set_file_attributes");
+        tracing::trace!("enter");
         Err(STATUS_NOT_IMPLEMENTED.into())
     }
 
@@ -683,7 +682,7 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _file_name, _creation_time, _last_access_time, _last_write_time, _info, _context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name), err(Debug))]
     async fn async_set_file_time<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
@@ -693,7 +692,7 @@ impl VirtualFilesystem {
         _info: &OperationInfo<'c, 'h, Super>,
         _context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::warn!("set_file_time not implemented yet");
+        tracing::warn!("enter - not implemented yet");
         Ok(())
     }
 
@@ -718,14 +717,14 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _file_name, info, context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name), err(Debug))]
     async fn async_delete_file<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
         info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_delete_file");
+        tracing::debug!("enter");
         let file_entry = context.entry.as_file()?;
         file_entry.shared.write().await.delete_on_close = info.delete_on_close();
         Ok(())
@@ -742,14 +741,14 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, file_name, info, context), fields(file_name = ?to_path(file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?file_name), err(Debug))]
     async fn async_delete_directory<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         file_name: &U16CStr,
         info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_delete_directory");
+        tracing::debug!("enter");
         let dir_entry = context.entry.as_directory()?;
         let path = to_path(file_name)?;
         let mut shared = dir_entry.shared.write().await;
@@ -777,9 +776,7 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, file_name, new_file_name, _replace_if_existing, _info, handle),
-        fields(file_name = ?to_path(file_name), new_file_name = ?to_path(new_file_name)),
-        err(Debug))]
+    #[instrument(skip_all, fields(?file_name, ?new_file_name), err(Debug))]
     async fn async_move_file<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         file_name: &U16CStr,
@@ -788,7 +785,7 @@ impl VirtualFilesystem {
         _info: &OperationInfo<'c, 'h, Super>,
         handle: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_move_file");
+        tracing::debug!("enter");
 
         let src_path = to_path(file_name)?;
         let dst_path = to_path(new_file_name)?;
@@ -852,15 +849,15 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, file_name, info, context), fields(file_name = ?to_path(file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?file_name), err(Debug))]
     async fn async_set_end_of_file<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         file_name: &U16CStr,
         offset: i64,
         info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_set_end_of_file");
+        tracing::debug!("enter");
         // TODO: How do the fwo functions differ?
         self.async_set_allocation_size(file_name, offset, info, context)
             .await
@@ -878,15 +875,15 @@ impl VirtualFilesystem {
             .map_err(Error::into)
     }
 
-    #[instrument(skip(self, _file_name, _info, context), fields(file_name = ?to_path(_file_name)), err(Debug))]
+    #[instrument(skip_all, fields(?_file_name), err(Debug))]
     async fn async_set_allocation_size<'c, 'h: 'c, Super: FileSystemHandler<'c, 'h>>(
         &self,
         _file_name: &U16CStr,
         alloc_size: i64,
         _info: &OperationInfo<'c, 'h, Super>,
         context: &'c EntryHandle,
     ) -> Result<(), Error> {
-        tracing::trace!("async_set_allocation_size");
+        tracing::debug!("enter");
         let desired_len: u64 = alloc_size
             .try_into()
             .map_err(|_| STATUS_INVALID_PARAMETER)?;
@@ -949,7 +946,7 @@ impl VirtualFilesystem {
         &self,
         _info: &OperationInfo<'c, 'h, Super>,
     ) -> Result<DiskSpaceInfo, Error> {
-        tracing::trace!("async_get_disk_free_space");
+        tracing::trace!("enter");
         // TODO
         Ok(DiskSpaceInfo {
             byte_count: 1024 * 1024 * 1024,
@@ -972,7 +969,7 @@ impl VirtualFilesystem {
         &self,
         _info: &OperationInfo<'c, 'h, Super>,
     ) -> Result<VolumeInfo, Error> {
-        tracing::trace!("async_get_volume_information");
+        tracing::debug!("enter");
         Ok(VolumeInfo {
             name: U16CString::from_str("ouisync").unwrap(),
             serial_number: 0,

vfs/src/dokan/multi_repo_mount.rs

@@ -1014,7 +1014,7 @@ impl<'c, 'h: 'c> FileSystemHandler<'c, 'h> for Handler {
         if self.debug_type == DebugType::Full {
             println!(
                 "{debug_id} Enter: find_files_with_pattern {:?}",
-                file_name.to_string_lossy()
+                file_name.as_ustr()
             );
         }
 
@@ -1054,7 +1054,7 @@ impl<'c, 'h: 'c> FileSystemHandler<'c, 'h> for Handler {
         if self.debug_type == DebugType::Full {
             println!(
                 "{debug_id} Enter: set_file_attributes {:?}",
-                file_name.to_string_lossy()
+                file_name.as_ustr()
             );
         }
 
@@ -1094,10 +1094,7 @@ impl<'c, 'h: 'c> FileSystemHandler<'c, 'h> for Handler {
         let debug_id = self.generate_debug_id();
 
         if self.debug_type == DebugType::Full {
-            println!(
-                "{debug_id} Enter: set_file_time {:?}",
-                file_name.to_string_lossy()
-            );
+            println!("{debug_id} Enter: set_file_time {:?}", file_name.as_ustr());
         }
 
         let r = self.set_file_time_(
@@ -1140,10 +1137,7 @@ impl<'c, 'h: 'c> FileSystemHandler<'c, 'h> for Handler {
         let debug_id = self.generate_debug_id();
 
         if self.debug_type == DebugType::Full {
-            println!(
-                "{debug_id} Enter: delete_file {:?}",
-                file_name.to_string_lossy()
-            );
+            println!("{debug_id} Enter: delete_file {:?}", file_name.as_ustr());
         }
 
         let r = self.delete_file_(file_name, info, context);
@@ -1181,7 +1175,7 @@ impl<'c, 'h: 'c> FileSystemHandler<'c, 'h> for Handler {
         if self.debug_type == DebugType::Full {
             println!(
                 "{debug_id} Enter: delete_directory {:?}",
-                file_name.to_string_lossy()
+                file_name.as_ustr()
             );
         }