proper logging

wwylele · Nov 30, 2019 · 7d469cd · 7d469cd
1 parent ce29996
commit 7d469cd
Show file tree

Hide file tree

Showing 12 changed files with 88 additions and 8 deletions.
diff --git a/libsave3ds/Cargo.toml b/libsave3ds/Cargo.toml
@@ -10,6 +10,7 @@ aes = "0.3"
 cmac = "0.2"
 byte_struct = "0.6"
 lru = "0.4"
+log = "0.4"
 
 [dev-dependencies]
 rand = "0.7"
diff --git a/libsave3ds/src/db.rs b/libsave3ds/src/db.rs
@@ -8,6 +8,7 @@ use crate::random_access_file::*;
 use crate::signed_file::*;
 use crate::sub_file::SubFile;
 use byte_struct::*;
+use log::*;
 use std::rc::Rc;
 
 #[derive(ByteStruct, Clone, PartialEq)]
@@ -213,6 +214,7 @@ impl Db {
             let mut magic = [0; 4];
             diff.partition().read(0, &mut magic)?;
             if magic != *b"TICK" {
+                error!("Unexpected TICK magic {:?}", magic);
                 return make_error(Error::MagicMismatch);
             }
         } else {
@@ -229,6 +231,7 @@ impl Db {
                     _ => unreachable!(),
                 }
             {
+                error!("Unexpected database magic {:?}", magic);
                 return make_error(Error::MagicMismatch);
             }
         }
@@ -241,10 +244,15 @@ impl Db {
 
         let header: DbHeader = read_struct(without_pre.as_ref(), 0)?;
         if header.magic != *b"BDRI" || header.version != 0x30000 {
+            error!("Unexpected magic {:?} {:X}", header.magic, header.version);
             return make_error(Error::MagicMismatch);
         }
         let fs_info: FsInfo = read_struct(without_pre.as_ref(), header.fs_info_offset as usize)?;
         if fs_info.data_block_count != fs_info.fat_size {
+            error!(
+                "Unexpected data_block_count={}, fat_size={}",
+                fs_info.data_block_count, fs_info.fat_size
+            );
             return make_error(Error::SizeMismatch);
         }
 
@@ -275,7 +283,7 @@ impl Db {
             0
         };
 
-        println!("Database file end fixup: 0x{:x}", data_delta);
+        info!("Database file end fixup: 0x{:x}", data_delta);
 
         let data: Rc<dyn RandomAccessFile> = Rc::new(FakeSizeFile {
             parent: Rc::new(SubFile::new(
@@ -326,12 +334,14 @@ impl File {
         let len = info.size as usize;
         let data = if info.block == 0x8000_0000 {
             if len != 0 {
+                error!("Non-empty file with invalid pointer");
                 return make_error(Error::SizeMismatch);
             }
             None
         } else {
             let fat_file = FatFile::open(center.fat.clone(), info.block as usize)?;
             if len == 0 || len > fat_file.len() {
+                error!("Empty file with valid pointer");
                 return make_error(Error::SizeMismatch);
             }
             Some(fat_file)

diff --git a/libsave3ds/src/diff.rs b/libsave3ds/src/diff.rs
@@ -7,6 +7,7 @@ use crate::random_access_file::*;
 use crate::signed_file::*;
 use crate::sub_file::SubFile;
 use byte_struct::*;
+use log::*;
 use std::rc::Rc;
 
 #[derive(ByteStruct)]
@@ -136,6 +137,10 @@ impl Diff {
 
         let header: DiffHeader = read_struct(header_file.as_ref(), 0)?;
         if header.magic != *b"DIFF" || header.version != 0x30000 {
+            error!(
+                "Unexpected DIFF magic {:?} {:X}",
+                header.magic, header.version
+            );
             return make_error(Error::MagicMismatch);
         }
 

diff --git a/libsave3ds/src/difi_partition.rs b/libsave3ds/src/difi_partition.rs
@@ -6,6 +6,7 @@ use crate::misc::*;
 use crate::random_access_file::*;
 use crate::sub_file::SubFile;
 use byte_struct::*;
+use log::*;
 use std::rc::Rc;
 
 #[derive(ByteStruct)]
@@ -291,27 +292,45 @@ impl DifiPartition {
         let header: DifiHeader = read_struct(descriptor.as_ref(), 0)?;
 
         if header.magic != *b"DIFI" || header.version != 0x10000 {
+            error!(
+                "Unexpected DIFI magic {:?} {:X}",
+                header.magic, header.version
+            );
             return make_error(Error::MagicMismatch);
         }
 
         if header.ivfc_descriptor_size as usize != IvfcDescriptor::BYTE_LEN {
+            error!(
+                "Unexpected ivfc_descriptor_size {}",
+                header.ivfc_descriptor_size
+            );
             return make_error(Error::SizeMismatch);
         }
         let ivfc: IvfcDescriptor =
             read_struct(descriptor.as_ref(), header.ivfc_descriptor_offset as usize)?;
         if ivfc.magic != *b"IVFC" || ivfc.version != 0x20000 {
+            error!("Unexpected IVFC magic {:?} {:X}", ivfc.magic, ivfc.version);
             return make_error(Error::MagicMismatch);
         }
         if header.partition_hash_size != ivfc.master_hash_size {
+            error!(
+                "Unexpected partition_hash_size {}",
+                header.partition_hash_size
+            );
             return make_error(Error::SizeMismatch);
         }
 
         if header.dpfs_descriptor_size as usize != DpfsDescriptor::BYTE_LEN {
+            error!(
+                "Unexpected dpfs_descriptor_size {}",
+                header.dpfs_descriptor_size
+            );
             return make_error(Error::SizeMismatch);
         }
         let dpfs: DpfsDescriptor =
             read_struct(descriptor.as_ref(), header.dpfs_descriptor_offset as usize)?;
         if dpfs.magic != *b"DPFS" || dpfs.version != 0x10000 {
+            error!("Unexpected DPFS magic {:?} {:X}", dpfs.magic, dpfs.version);
             return make_error(Error::MagicMismatch);
         }
 

diff --git a/libsave3ds/src/disa.rs b/libsave3ds/src/disa.rs
@@ -7,6 +7,7 @@ use crate::random_access_file::*;
 use crate::signed_file::*;
 use crate::sub_file::SubFile;
 use byte_struct::*;
+use log::*;
 use std::ops::Index;
 use std::rc::Rc;
 
@@ -219,9 +220,14 @@ impl Disa {
 
         let header: DisaHeader = read_struct(header_file.as_ref(), 0)?;
         if header.magic != *b"DISA" || header.version != 0x40000 {
+            error!(
+                "Unexpected DISA magic {:?} {:X}",
+                header.magic, header.version
+            );
             return make_error(Error::MagicMismatch);
         }
         if header.partition_count != 1 && header.partition_count != 2 {
+            error!("Unexpected partition_count {}", header.partition_count);
             return make_error(Error::InvalidValue);
         }
 

diff --git a/libsave3ds/src/error.rs b/libsave3ds/src/error.rs
@@ -1,3 +1,4 @@
+use log::*;
 use std::fmt;
 
 #[derive(Debug)]
@@ -75,14 +76,12 @@ impl std::error::Error for Error {}
 
 impl From<std::io::Error> for Error {
     fn from(e: std::io::Error) -> Error {
-        {
-            println!("Host IO error: {:?}", e);
-        }
+        error!("Host IO error: {:?}", e);
         Error::IO(e)
     }
 }
 
 pub(crate) fn make_error<T>(e: Error) -> Result<T, Error> {
-    // println!("Error thrown: {:?}", e);
+    info!("Error thrown: {:?}", e);
     Err(e)
 }
diff --git a/libsave3ds/src/ext_data.rs b/libsave3ds/src/ext_data.rs
@@ -11,6 +11,7 @@ use crate::sd_nand_common::*;
 use crate::signed_file::*;
 use crate::sub_file::SubFile;
 use byte_struct::*;
+use log::*;
 use std::rc::Rc;
 
 #[derive(ByteStruct, Clone)]
@@ -381,13 +382,21 @@ impl ExtData {
 
         let header: ExtHeader = read_struct(meta_file.partition().as_ref(), 0)?;
         if header.magic != *b"VSXE" || header.version != 0x30000 {
+            error!(
+                "Unexpected VSXE magic {:?} {:X}",
+                header.magic, header.version
+            );
             return make_error(Error::MagicMismatch);
         }
         let fs_info: FsInfo = read_struct(
             meta_file.partition().as_ref(),
             header.fs_info_offset as usize,
         )?;
         if fs_info.data_block_count != fs_info.fat_size {
+            error!(
+                "Unexpected data_block_count={}, fat_size={}",
+                fs_info.data_block_count, fs_info.fat_size
+            );
             return make_error(Error::SizeMismatch);
         }
 
@@ -531,6 +540,7 @@ impl File {
 
         let info = meta.get_info()?;
         if data.is_some() && info.unique_id != data.as_ref().unwrap().unique_id() {
+            error!("Unique ID mismatch");
             return make_error(Error::UniqueIdMismatch);
         }
         Ok(File { center, meta, data })

diff --git a/libsave3ds/src/fat.rs b/libsave3ds/src/fat.rs
@@ -2,6 +2,7 @@ use crate::error::*;
 use crate::misc::*;
 use crate::random_access_file::*;
 use byte_struct::*;
+use log::*;
 use std::cell::Cell;
 use std::rc::Rc;
 
@@ -53,6 +54,7 @@ fn index_good_to_bad(index: Option<usize>) -> u32 {
 fn get_node(table: &dyn RandomAccessFile, index: usize) -> Result<Node, Error> {
     let node_start: Entry = read_struct(table, (index + 1) * Entry::BYTE_LEN)?;
     if (node_start.u.flag == 1) != (node_start.u.index == 0) {
+        error!("Node has broken entry");
         return make_error(Error::BrokenFat);
     }
 
@@ -64,13 +66,15 @@ fn get_node(table: &dyn RandomAccessFile, index: usize) -> Result<Node, Error> {
             || expand_start.v.flag == 1
             || expand_start.u.index as usize != index + 1
         {
+            error!("Expanded node has broken starting entry");
             return make_error(Error::BrokenFat);
         }
 
         let end_i = expand_start.v.index as usize;
         let expand_end: Entry = read_struct(table, end_i * Entry::BYTE_LEN)?;
 
         if expand_start != expand_end {
+            error!("Expanded node has broken end entry");
             return make_error(Error::BrokenFat);
         }
         (expand_start.v.index - expand_start.u.index + 1) as usize
@@ -119,6 +123,7 @@ fn set_node(table: &dyn RandomAccessFile, index: usize, node: Node) -> Result<()
 fn get_head(table: &dyn RandomAccessFile) -> Result<Option<usize>, Error> {
     let head: Entry = read_struct(table, 0)?;
     if head.u.index != 0 || head.u.flag != 0 || head.v.flag != 0 {
+        error!("FAT has broken head");
         return make_error(Error::BrokenFat);
     }
     Ok(index_bad_to_good(head.v.index))
@@ -203,6 +208,7 @@ fn allocate(table: &dyn RandomAccessFile, mut block_count: usize) -> Result<Vec<
             if let Some(next) = node.next {
                 let mut next_node = get_node(table, next)?;
                 if next_node.prev != Some(cur) {
+                    error!("FAT has less space than it should");
                     return make_error(Error::BrokenFat);
                 }
                 next_node.prev = Some(cur + block_count);
@@ -226,7 +232,7 @@ fn allocate(table: &dyn RandomAccessFile, mut block_count: usize) -> Result<Vec<
     Ok(block_list)
 }
 
-// Takes some blocks from free blocks.
+// Frees a block list.
 // Precondition: the first node has prev=None, block_list contain well-formed node.
 // Remember to modify the first node if this list is split from a larger list!
 fn free(table: &dyn RandomAccessFile, block_list: &[BlockMap]) -> Result<(), Error> {
@@ -235,6 +241,7 @@ fn free(table: &dyn RandomAccessFile, block_list: &[BlockMap]) -> Result<(), Err
     if let Some(free_front_index) = maybe_free_front_index {
         let mut free_front = get_node(table, free_front_index)?;
         if free_front.prev.is_some() {
+            error!("Trying to free a block list from middle");
             return make_error(Error::BrokenFat);
         }
         free_front.prev = Some(last_node_index);
@@ -243,6 +250,7 @@ fn free(table: &dyn RandomAccessFile, block_list: &[BlockMap]) -> Result<(), Err
 
     let mut last_node = get_node(table, last_node_index)?;
     if last_node.next.is_some() {
+        error!("Trying to free a block list that ends too early");
         return make_error(Error::BrokenFat);
     }
     last_node.next = maybe_free_front_index;
@@ -262,7 +270,7 @@ fn iterate_fat_entry(
     while let Some(cur) = cur_entry {
         let node = get_node(table, cur)?;
         if node.prev != prev {
-            assert_eq!(node.prev, prev);
+            error!("Inconsistent prev pointer detected while iterating");
             return make_error(Error::BrokenFat);
         }
 
@@ -449,6 +457,7 @@ impl FatFile {
                 if let Some(next_index) = next {
                     let mut next = get_node(table, next_index)?;
                     if next.prev != Some(tail_index) {
+                        error!("Inconsistent prev pointer detected while resizing");
                         return make_error(Error::BrokenFat);
                     }
                     next.prev = Some(head_index);
@@ -652,5 +661,4 @@ mod test {
             }
         }
     }
-
 }
diff --git a/libsave3ds/src/save_data.rs b/libsave3ds/src/save_data.rs
@@ -10,6 +10,7 @@ use crate::save_ext_common::*;
 use crate::signed_file::*;
 use crate::sub_file::SubFile;
 use byte_struct::*;
+use log::*;
 use std::rc::Rc;
 
 #[derive(ByteStruct, Clone)]
@@ -424,10 +425,18 @@ impl SaveData {
         let disa = Rc::new(Disa::new(file, SaveData::get_signer(save_data_type))?);
         let header: SaveHeader = read_struct(disa[0].as_ref(), 0)?;
         if header.magic != *b"SAVE" || header.version != 0x40000 {
+            error!(
+                "Unexpected SAVE magic {:?} {:X}",
+                header.magic, header.version
+            );
             return make_error(Error::MagicMismatch);
         }
         let fs_info: FsInfo = read_struct(disa[0].as_ref(), header.fs_info_offset as usize)?;
         if fs_info.data_block_count != fs_info.fat_size {
+            error!(
+                "Unexpected data_block_count={}, fat_size={}",
+                fs_info.data_block_count, fs_info.fat_size
+            );
             return make_error(Error::SizeMismatch);
         }
 
@@ -511,12 +520,14 @@ impl File {
         let len = info.size as usize;
         let data = if info.block == 0x8000_0000 {
             if len != 0 {
+                error!("Non-empty file with invalid pointer");
                 return make_error(Error::SizeMismatch);
             }
             None
         } else {
             let fat_file = FatFile::open(center.fat.clone(), info.block as usize)?;
             if len == 0 || len > fat_file.len() {
+                error!("Empty file with valid pointer");
                 return make_error(Error::SizeMismatch);
             }
             Some(fat_file)

diff --git a/libsave3ds/src/signed_file.rs b/libsave3ds/src/signed_file.rs
@@ -3,6 +3,7 @@ use crate::random_access_file::*;
 use aes::*;
 use cmac::crypto_mac::generic_array::*;
 use cmac::*;
+use log::*;
 use sha2::*;
 use std::rc::Rc;
 
@@ -67,6 +68,7 @@ impl SignedFile {
         let mut signature = [0; 16];
         file.signature.read(0, &mut signature)?;
         if signature != file.calculate_signature()? {
+            error!("Signature mismatch");
             return make_error(Error::SignatureMismatch);
         }
 

diff --git a/save3ds_fuse/Cargo.toml b/save3ds_fuse/Cargo.toml
@@ -11,6 +11,7 @@ unixfuse = ["libc", "fuse", "time"]
 [dependencies]
 libsave3ds = { path = "../libsave3ds" }
 getopts = "0.2"
+stderrlog = "0.4"
 
 [target.'cfg(unix)'.dependencies]
 libc = { version = "0.2", optional = true }