From 7d469cdd4cd3ab24ba7f471a9a06901aad1d16d1 Mon Sep 17 00:00:00 2001 From: Weiyi Wang Date: Sat, 30 Nov 2019 11:58:24 -0500 Subject: [PATCH] proper logging --- libsave3ds/Cargo.toml | 1 + libsave3ds/src/db.rs | 12 +++++++++++- libsave3ds/src/diff.rs | 5 +++++ libsave3ds/src/difi_partition.rs | 19 +++++++++++++++++++ libsave3ds/src/disa.rs | 6 ++++++ libsave3ds/src/error.rs | 7 +++---- libsave3ds/src/ext_data.rs | 10 ++++++++++ libsave3ds/src/fat.rs | 14 +++++++++++--- libsave3ds/src/save_data.rs | 11 +++++++++++ libsave3ds/src/signed_file.rs | 2 ++ save3ds_fuse/Cargo.toml | 1 + save3ds_fuse/src/main.rs | 8 ++++++++ 12 files changed, 88 insertions(+), 8 deletions(-) diff --git a/libsave3ds/Cargo.toml b/libsave3ds/Cargo.toml index 5fd809a..879c869 100644 --- 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 index aef182d..d5c9580 100644 --- 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 = 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 index 0347243..43246a3 100644 --- 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 index 40dcf18..bb78cd1 100644 --- 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 index 4b10846..d5a2ad6 100644 --- 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 index 54f7344..6af91ef 100644 --- 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 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(e: Error) -> Result { - // println!("Error thrown: {:?}", e); + info!("Error thrown: {:?}", e); Err(e) } diff --git a/libsave3ds/src/ext_data.rs b/libsave3ds/src/ext_data.rs index 90c7e8e..3e0d7f4 100644 --- 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,6 +382,10 @@ 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( @@ -388,6 +393,10 @@ impl ExtData { 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 index b71d92d..3a3fb20 100644 --- 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) -> u32 { fn get_node(table: &dyn RandomAccessFile, index: usize) -> Result { 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,6 +66,7 @@ fn get_node(table: &dyn RandomAccessFile, index: usize) -> Result { || 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); } @@ -71,6 +74,7 @@ fn get_node(table: &dyn RandomAccessFile, index: usize) -> Result { 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, 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 Result 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 index a87daf8..919ce1e 100644 --- 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 index 50724e2..669a459 100644 --- 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 index a17b22c..316db3b 100644 --- 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 } diff --git a/save3ds_fuse/src/main.rs b/save3ds_fuse/src/main.rs index 99b5e5a..e65d87e 100644 --- a/save3ds_fuse/src/main.rs +++ b/save3ds_fuse/src/main.rs @@ -1229,6 +1229,7 @@ fn main_inner() -> Result<(), Box> { opts.optopt("", "sdext", "mount the SD Extdata with the ID", "ID"); opts.optopt("", "sdsave", "mount the SD save with the ID", "ID"); opts.optflag("t", "touch", "just try opening and closing the archive"); + opts.optflagmulti("v", "verbose", "more v for more verbose logging"); let matches = match opts.parse(&args[1..]) { Ok(m) => m, @@ -1239,6 +1240,13 @@ fn main_inner() -> Result<(), Box> { } }; + let verbose = matches.opt_count("verbose"); + stderrlog::new() + .module(module_path!()) + .module("libsave3ds") + .verbosity(verbose) + .init()?; + if matches.opt_present("h") { print_usage(&program, opts); return Ok(());