diff --git a/src/formats/amlogic/mod.rs b/src/formats/amlogic/mod.rs index 8f3cce2..b70638a 100644 --- a/src/formats/amlogic/mod.rs +++ b/src/formats/amlogic/mod.rs @@ -73,4 +73,4 @@ pub fn extract_amlogic(app_ctx: &AppContext, _ctx: Box) -> Result<(), B } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/android_ota_payload/mod.rs b/src/formats/android_ota_payload/mod.rs index d450241..0a7928a 100644 --- a/src/formats/android_ota_payload/mod.rs +++ b/src/formats/android_ota_payload/mod.rs @@ -87,4 +87,4 @@ pub fn extract_android_ota_payload(app_ctx: &AppContext, _ctx: Box) -> } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/bdl/mod.rs b/src/formats/bdl/mod.rs index 7cf6ae6..2abe8d3 100644 --- a/src/formats/bdl/mod.rs +++ b/src/formats/bdl/mod.rs @@ -71,4 +71,4 @@ pub fn extract_bdl(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box) -> Result<(), Box Result>, Box f, None => return Ok(None)}; let versions = common::read_file(&file, 1712, 36)?; + debug!("epk: version bytes at 1712: {:02X?}", versions); if let Some(epk_version) = check_epk_version(&versions) { + debug!("epk: matched EPK v{}", epk_version); Ok(Some(Box::new(EpkContext {epk_version, versions}))) } else { + debug!("epk: no version pattern matched"); Ok(None) } } @@ -58,6 +61,7 @@ fn match_with_pattern(data: &[u8], pattern: &str) -> bool { pub fn extract_epk(app_ctx: &AppContext, ctx: Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; let ctx = ctx.downcast::().map_err(|_| "Invalid context type")?; + debug!("epk: dispatching EPK v{} extraction", ctx.epk_version); let platform_version = common::string_from_bytes(&ctx.versions[4..20]); let sdk_version = common::string_from_bytes(&ctx.versions[20..36]); diff --git a/src/formats/epk1/mod.rs b/src/formats/epk1/mod.rs index 81fb94f..73e6b4b 100644 --- a/src/formats/epk1/mod.rs +++ b/src/formats/epk1/mod.rs @@ -114,4 +114,4 @@ pub fn extract_epk1(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box< } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/epk2/mod.rs b/src/formats/epk2/mod.rs index 5a32617..f3e6105 100644 --- a/src/formats/epk2/mod.rs +++ b/src/formats/epk2/mod.rs @@ -150,4 +150,4 @@ pub fn extract_epk2(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box< } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/epk2b/mod.rs b/src/formats/epk2b/mod.rs index a42e0af..757c715 100644 --- a/src/formats/epk2b/mod.rs +++ b/src/formats/epk2b/mod.rs @@ -86,4 +86,4 @@ pub fn extract_epk2b(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/epk3/mod.rs b/src/formats/epk3/mod.rs index e908b0f..6d42f92 100644 --- a/src/formats/epk3/mod.rs +++ b/src/formats/epk3/mod.rs @@ -118,4 +118,4 @@ pub fn extract_epk3(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box< } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/funai_bdp/mod.rs b/src/formats/funai_bdp/mod.rs index a773f75..3f0ee7f 100644 --- a/src/formats/funai_bdp/mod.rs +++ b/src/formats/funai_bdp/mod.rs @@ -141,4 +141,4 @@ pub fn uncomp_image_rom(data: &[u8]) -> Result, Box) -> Result<() } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/funai_upg/mod.rs b/src/formats/funai_upg/mod.rs index 00ca134..3df9881 100644 --- a/src/formats/funai_upg/mod.rs +++ b/src/formats/funai_upg/mod.rs @@ -77,4 +77,4 @@ pub fn extract_funai_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/funai_upg_phl/mod.rs b/src/formats/funai_upg_phl/mod.rs index 4a06e21..9055fd2 100644 --- a/src/formats/funai_upg_phl/mod.rs +++ b/src/formats/funai_upg_phl/mod.rs @@ -76,4 +76,4 @@ pub fn extract_funai_upg_phl(app_ctx: &AppContext, _ctx: Box) -> Result } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/gx_dvb/mod.rs b/src/formats/gx_dvb/mod.rs index f133a5d..26621af 100644 --- a/src/formats/gx_dvb/mod.rs +++ b/src/formats/gx_dvb/mod.rs @@ -8,7 +8,7 @@ use crate::AppContext; use crate::utils::common; use binrw::BinReaderExt; use include::*; -use log::info; +use log::{debug, info}; pub fn is_gx_dvb_file(app_ctx: &AppContext) -> Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; @@ -26,6 +26,7 @@ pub fn extract_gx_dvb(app_ctx: &AppContext, _ctx: Box) -> Result<(), Bo file.seek(SeekFrom::Start(TABLE_OFFSET))?; let table: PartTable = file.read_be()?; + debug!("Table raw: part_count={}", table.part_count); info!("Part count: {}", table.part_count); diff --git a/src/formats/invincible_image/mod.rs b/src/formats/invincible_image/mod.rs index 381dce4..9c1e57e 100644 --- a/src/formats/invincible_image/mod.rs +++ b/src/formats/invincible_image/mod.rs @@ -87,4 +87,4 @@ pub fn extract_invincible_image(app_ctx: &AppContext, _ctx: Box) -> Res } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/msd10/include.rs b/src/formats/msd10/include.rs index 4a0f0a9..48dd02e 100644 --- a/src/formats/msd10/include.rs +++ b/src/formats/msd10/include.rs @@ -1,7 +1,7 @@ use crate::utils::common; use binrw::BinRead; -#[derive(PartialEq)] +#[derive(PartialEq, Debug)] pub enum FirmwareType{ Old, Tizen, diff --git a/src/formats/msd10/mod.rs b/src/formats/msd10/mod.rs index 3a08529..522460c 100644 --- a/src/formats/msd10/mod.rs +++ b/src/formats/msd10/mod.rs @@ -14,7 +14,7 @@ use crate::formats::msd::{decrypt_aes_salted_old, decrypt_aes_salted_tizen, decr use crate::formats::msd::msd_ouith_parser_old::{parse_ouith_blob}; use crate::formats::msd::msd_ouith_parser_tizen_1_8::{parse_blob_1_8}; use include::*; -use log::info; +use log::{debug, info}; pub fn is_msd10_file(app_ctx: &AppContext) -> Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; @@ -48,6 +48,7 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box for i in 0..header_count { let header: HeaderEntry = file.read_le()?; info!("Header {}: {}, offset: {}, size: {}", i + 1, header.name(), header.offset, header.size); + debug!("msd10: header[{}] name={} offset={} size={}", i + 1, header.name(), header.offset, header.size); headers.push(header); } @@ -65,9 +66,12 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box let mut firmware_type: Option = None; for (key_hex, name) in keys::MSD10 { let key_bytes = hex::decode(key_hex)?; + debug!("msd10: trying key '{}' ({} bytes, {})", name, key_bytes.len(), + if key_bytes.len() == 20 { "OLD" } else { "TIZEN" }); if key_bytes.len() == 20 { match decrypt_aes_salted_old(&toc_data, &key_bytes) { Ok(_) => { + debug!("msd10: key '{}' matched (OLD firmware)", name); passphrase_bytes = Some(key_bytes); passphrase_name = name; firmware_type = Some(FirmwareType::Old); @@ -79,6 +83,7 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box else if key_bytes.len() == 16 { match decrypt_aes_salted_tizen(&toc_data, &key_bytes) { Ok(_) => { + debug!("msd10: key '{}' matched (Tizen firmware)", name); passphrase_bytes = Some(key_bytes); passphrase_name = name; firmware_type = Some(FirmwareType::Tizen); @@ -90,18 +95,22 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box } let (passphrase_bytes, firmware_type) = if let (Some(p), Some(t)) = (passphrase_bytes, firmware_type) { + debug!("msd10: matched key '{}' -> firmware_type={:?}", passphrase_name, t); info!("Using passphrase: {}", passphrase_name); (p, t) } else { + debug!("msd10: no key matched out of {} keys tried", keys::MSD10.len()); return Err("No matching key found!".into()); }; //parse TOC if firmware_type == FirmwareType::Tizen { let toc = decrypt_aes_salted_tizen(&toc_data, &passphrase_bytes)?; + debug!("msd10: TOC decrypted (Tizen), {} bytes", toc.len()); opt_dump_dec_hdr(app_ctx, &toc, "toc")?; let (items, info) = parse_blob_1_8(&toc, app_ctx.has_option("msd:print_ouith"))?; + debug!("msd10: parsed {} TOC items", items.len()); if let Some(info) = info { info!("\nImage info:\n{} {}.{} {}/{}/{}", @@ -111,6 +120,7 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box for (i, item) in items.iter().enumerate() { let size = sections[i as usize].size; let offset = sections[i as usize].offset; + debug!("msd10: item[{}] id={} offset={} size={} aes={}", i+1, item.item_id, offset, size, item.aes_encryption); info!("\n({}/{}) - {}, Size: {}", i + 1, items.len(), item.name, size); @@ -141,9 +151,11 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box } else if firmware_type == FirmwareType::Old { let toc = decrypt_aes_salted_old(&toc_data, &passphrase_bytes)?; + debug!("msd10: TOC decrypted (Old), {} bytes", toc.len()); opt_dump_dec_hdr(app_ctx, &toc, "toc")?; let (items, info) = parse_ouith_blob(&toc, app_ctx.has_option("msd:print_ouith"))?; + debug!("msd10: parsed {} OUITH items", items.len()); if let Some(info) = info { info!("\nImage info:\n{} {}.{} {}/{}/20{}", @@ -159,6 +171,8 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box if sections[i as usize].index != item.item_id { return Err("Item ID in TOC does not match ID from header!".into()); } + debug!("msd10: processing item[{}] type={} offset={} heading={} data={} aes={}", + i+1, type_str, offset, item.heading_size, item.data_size, item.aes_encryption); let mut out_filename = format!("{}", item.name); if item.item_type == 0x11 { //CMAC DATA @@ -194,4 +208,4 @@ pub fn extract_msd10(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/msd11/mod.rs b/src/formats/msd11/mod.rs index d39ba57..79fa8d1 100644 --- a/src/formats/msd11/mod.rs +++ b/src/formats/msd11/mod.rs @@ -120,4 +120,4 @@ pub fn extract_msd11(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/mstar/mod.rs b/src/formats/mstar/mod.rs index 52ea1cb..764d387 100644 --- a/src/formats/mstar/mod.rs +++ b/src/formats/mstar/mod.rs @@ -12,7 +12,7 @@ use crate::utils::compression::{decompress_lzma, decompress_lz4}; use crate::utils::lzop::{unlzop_to_file}; use crate::utils::sparse::{unsparse_to_file}; use include::*; -use log::info; +use log::{debug, info}; pub fn is_mstar_file(app_ctx: &AppContext) -> Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; @@ -28,11 +28,13 @@ pub fn is_mstar_file(app_ctx: &AppContext) -> Result>, Box) -> Result<(), Box> { let file = app_ctx.file().ok_or("Extractor expected file")?; + debug!("mstar: starting extraction, script at 0x0 and fallback at 0x1000"); let mut script = common::read_file(&file, 0, 32768)?; if let Some(pos) = script.iter().position(|x| [0x00, 0xFF].contains(x)) { script.truncate(pos); + debug!("mstar: script truncated at offset {}", pos); } let mut script_string = String::from_utf8_lossy(&script); @@ -40,23 +42,28 @@ pub fn extract_mstar(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box //try for hisense info!("Failed to get script at 0x0, trying 0x1000..."); script = common::read_file(&file, 4096, 32768)?; + debug!("mstar: fallback script read {} bytes at 0x1000", script.len()); if let Some(pos) = script.iter().position(|x| [0x00, 0xFF].contains(x)) { script.truncate(pos); + debug!("mstar: fallback script truncated at offset {}", pos); } script_string = String::from_utf8_lossy(&script); if script_string.is_empty() { + debug!("mstar: both script reads empty, failing"); return Err("Failed to get script".into()); } } opt_dump_dec_hdr(app_ctx, &script, "script")?; let lines: Vec<&str> = script_string.lines().map(|l| l.trim()).collect(); + debug!("mstar: script has {} non-empty lines", lines.len()); for (i, line) in lines.iter().enumerate() { if line.starts_with("filepartload") { + debug!("mstar: line[{}] = filepartload: {}", i, line); let parts: Vec<&str> = line.split_whitespace().collect(); let offset = parse_number(parts[3]).unwrap_or(0); let size = parse_number(parts[4]).unwrap_or(0); @@ -172,4 +179,4 @@ pub fn extract_mstar(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/mstar_secure_old/mod.rs b/src/formats/mstar_secure_old/mod.rs index cdd925d..cba8207 100644 --- a/src/formats/mstar_secure_old/mod.rs +++ b/src/formats/mstar_secure_old/mod.rs @@ -74,4 +74,4 @@ pub fn extract_mstar_secure_old(app_ctx: &AppContext, ctx: Box) -> Resu } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/mtk_bdp/mod.rs b/src/formats/mtk_bdp/mod.rs index 1e11a04..90b014f 100644 --- a/src/formats/mtk_bdp/mod.rs +++ b/src/formats/mtk_bdp/mod.rs @@ -128,4 +128,4 @@ pub fn extract_mtk_bdp(app_ctx: &AppContext, ctx: Box) -> Result<(), Bo } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/mtk_pkg/mod.rs b/src/formats/mtk_pkg/mod.rs index 0ef32cb..13c6534 100644 --- a/src/formats/mtk_pkg/mod.rs +++ b/src/formats/mtk_pkg/mod.rs @@ -15,7 +15,7 @@ use crate::utils::aes::{decrypt_aes128_cbc_nopad}; use crate::keys; use lzhs::{decompress_mtk_to_file}; use include::*; -use log::{info, warn}; +use log::{debug, info, warn}; pub struct MtkPkgContext { is_philips_variant: bool, @@ -27,17 +27,21 @@ pub fn is_mtk_pkg_file(app_ctx: &AppContext) -> Result>, Box let mut encrypted_header = common::read_file(&file, 0, HEADER_SIZE)?; let mut header = decrypt_aes128_cbc_nopad(&encrypted_header, &HEADER_KEY, &HEADER_IV)?; + debug!("mtk_pkg detection: default magic={:02X?}", &header[4..12]); if &header[4..12] == MTK_HEADER_MAGIC { - Ok(Some(Box::new(MtkPkgContext { is_philips_variant: false, decrypted_header: header}))) + debug!("mtk_pkg: matched standard variant"); + return Ok(Some(Box::new(MtkPkgContext { is_philips_variant: false, decrypted_header: header}))); } else { // try for philips which has additional 128 bytes at beginning encrypted_header = common::read_file(&file, PHILIPS_EXTRA_HEADER_SIZE as u64, HEADER_SIZE)?; header = decrypt_aes128_cbc_nopad(&encrypted_header, &HEADER_KEY, &HEADER_IV)?; + debug!("mtk_pkg detection: philips magic={:02X?}", &header[4..12]); if &header[4..12] == MTK_HEADER_MAGIC { - Ok(Some(Box::new(MtkPkgContext { is_philips_variant: true, decrypted_header: header }))) + debug!("mtk_pkg: matched philips variant"); + return Ok(Some(Box::new(MtkPkgContext { is_philips_variant: true, decrypted_header: header }))); } else { + debug!("mtk_pkg: no magic match, skipping"); Ok(None) - } } } diff --git a/src/formats/novatek/mod.rs b/src/formats/novatek/mod.rs index d4bd3ba..9424a2c 100644 --- a/src/formats/novatek/mod.rs +++ b/src/formats/novatek/mod.rs @@ -52,4 +52,4 @@ pub fn extract_novatek(app_ctx: &AppContext, _ctx: Box) -> Result<(), B } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/novatek_raw/mod.rs b/src/formats/novatek_raw/mod.rs index 9b1ab7e..3d56fa4 100644 --- a/src/formats/novatek_raw/mod.rs +++ b/src/formats/novatek_raw/mod.rs @@ -7,7 +7,7 @@ use crate::AppContext; use crate::utils::aes::decrypt_aes_ecb_auto; use crate::utils::common; use crate::keys; -use log::{info, warn}; +use log::{debug, info, warn}; // shredder format detectordecryptor // Detects files starting with bsl magic and attempts XOR/AES-ECB decryption @@ -37,18 +37,22 @@ pub fn is_novatek_raw_file(app_ctx: &AppContext) -> Result>, let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; let file_size = file.metadata()?.len(); + debug!("novatek_raw detection: file_size={}", file_size); if file_size < SHREDDER_MAGIC.len() as u64 { + debug!("novatek_raw: file too small, skipping"); return Ok(None); } let magic = common::read_file(&file, 0, SHREDDER_MAGIC.len())?; + debug!("novatek_raw: magic bytes={:02X?}", magic); if magic == SHREDDER_MAGIC { info!("- Detected shredder format"); return Ok(Some(Box::new(()))); } if app_ctx.has_option("nvt_raw:key") { + debug!("novatek_raw: forced via nvt_raw:key option"); return Ok(Some(Box::new(()))); } @@ -57,32 +61,42 @@ pub fn is_novatek_raw_file(app_ctx: &AppContext) -> Result>, pub fn extract_novatek_raw(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box> { let file = app_ctx.file().ok_or("Extractor expected file")?; + debug!("Starting novatek_raw extraction"); let key_hex = app_ctx.options.iter() .find(|o| o.starts_with("nvt_raw:key=")) .map(|o| o.strip_prefix("nvt_raw:key=").unwrap()); let key_hex = match key_hex { - Some(k) => k, + Some(k) => { + debug!("Using CLI-provided key"); + k + } None => keys::NOVATEK_RAW.first().map(|(_, k)| *k).ok_or("nvt_raw:key= option required for decryption")?, }; + debug!("Key source: {}", key_hex); let key = hex::decode(key_hex).map_err(|e| format!("Invalid hex key: {}", e))?; + debug!("Decoded key length: {} bytes", key.len()); let file_size = file.metadata()?.len() as usize; let enc_data = common::read_file(&file, 0, file_size)?; + debug!("Read {} encrypted bytes from file", enc_data.len()); info!("- File size: {} bytes", file_size); info!("- Decrypting with AES-{}...", if key.len() == 16 { "128" } else { "256" }); let dec_data = match decrypt_aes_ecb_auto(&key, &enc_data) { Ok(d) => { + debug!("AES-ECB decryption succeeded, output size: {} bytes", d.len()); info!("- Decryption complete"); d } - Err(_) => { - warn!("- AES-ECB failed, trying XOR..."); - xor_decrypt(&key, &enc_data) + Err(e) => { + warn!("- AES-ECB failed ({}), trying XOR...", e); + let xored = xor_decrypt(&key, &enc_data); + debug!("XOR fallback decryption output size: {} bytes", xored.len()); + xored } }; @@ -94,6 +108,7 @@ pub fn extract_novatek_raw(app_ctx: &AppContext, _ctx: Box) -> Result<( info!("- Saved decrypted image to {}", output_path.display()); info!("\nExtracting partitions:"); + let mut extracted_count = 0; for (name, offset, size) in NVT_PARTITIONS { if (offset + size) as usize <= dec_data.len() && size > 0 { let part_data = &dec_data[offset as usize..(offset + size) as usize]; @@ -101,8 +116,13 @@ pub fn extract_novatek_raw(app_ctx: &AppContext, _ctx: Box) -> Result<( let mut part_file = OpenOptions::new().write(true).create(true).open(&part_path)?; part_file.write_all(part_data)?; info!(" {}: offset=0x{:x}, size={}", name, offset, size); + debug!("Wrote {}: {} bytes to {}", name, part_data.len(), part_path.display()); + extracted_count += 1; + } else if size > 0 { + debug!("Skipping {} (out of range: offset=0x{:x}, size={}, total={})", name, offset, size, dec_data.len()); } } + debug!("Total partitions extracted: {}", extracted_count); Ok(()) } diff --git a/src/formats/nvt_timg/mod.rs b/src/formats/nvt_timg/mod.rs index a60794d..ac9f072 100644 --- a/src/formats/nvt_timg/mod.rs +++ b/src/formats/nvt_timg/mod.rs @@ -103,4 +103,4 @@ pub fn extract_nvt_timg(app_ctx: &AppContext, ctx: Box) -> Result<(), B } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/onkyo/mod.rs b/src/formats/onkyo/mod.rs index 071c414..84f0bc1 100644 --- a/src/formats/onkyo/mod.rs +++ b/src/formats/onkyo/mod.rs @@ -132,4 +132,4 @@ pub fn extract_onkyo(app_ctx: &AppContext, ctx: Box) -> Result<(), Box< } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/pana_dvd/mod.rs b/src/formats/pana_dvd/mod.rs index 270f2dd..9e74dc7 100644 --- a/src/formats/pana_dvd/mod.rs +++ b/src/formats/pana_dvd/mod.rs @@ -1,4 +1,4 @@ -use log::info; +use log::{debug, info}; mod include; mod pana_dvd_crypto; @@ -65,6 +65,7 @@ pub fn is_pana_dvd_file(app_ctx: &AppContext) -> Result>, Bo pub fn extract_pana_dvd(app_ctx: &AppContext, ctx: Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; let context = ctx.downcast::().map_err(|_| "Invalid context type")?; + debug!("pana_dvd extraction: is_aes={}, base_hdr_size={}", context.is_aes, context.base_hdr_size); let matching_key = context.matching_key; let mut file_entries: Vec = Vec::new(); @@ -73,6 +74,7 @@ pub fn extract_pana_dvd(app_ctx: &AppContext, ctx: Box) -> Result<(), B if context.is_aes { let (aes_key, aes_iv) = (context.aes_key.unwrap(), context.aes_iv.unwrap()); info!("Using key: {} + AES key: {}, IV: {}", hex::encode_upper(matching_key), hex::encode_upper(aes_key), hex::encode_upper(aes_iv)); + debug!("pana_dvd: AES mode, reading 48-byte file table"); //read inner file table let file_table = common::read_exact(&mut file, 48)?; @@ -82,17 +84,21 @@ pub fn extract_pana_dvd(app_ctx: &AppContext, ctx: Box) -> Result<(), B for _i in 0..4 { let file_entry: AesHeaderFileEntry = file_table_reader.read_le()?; if file_entry.size == 0 && file_entry.offset == 0 { + debug!("pana_dvd: AES file table entry {} is zero, stopping", _i); break } //ignore duplicate entries if !file_entries.iter().any(|f| f.offset == file_entry.offset ){ + debug!("pana_dvd: AES file table entry {}: offset={}, size={}", _i, file_entry.offset, file_entry.size); file_entries.push(FileEntry { offset: file_entry.offset, size: file_entry.size, header_size: context.base_hdr_size }); } } } else { info!("Using key: {}", hex::encode_upper(matching_key)); - file_entries.push(FileEntry { offset: 0, size: file.metadata()?.len() as u32, header_size: context.base_hdr_size }); + let file_size = file.metadata()?.len() as u32; + debug!("pana_dvd: non-AES mode, treating entire file as single entry, size={}", file_size); + file_entries.push(FileEntry { offset: 0, size: file_size, header_size: context.base_hdr_size }); } info!("File contains {} sub-files...", file_entries.len()); @@ -305,4 +311,4 @@ fn extract_drv(mut data: Vec, key: &[u8; 8]) -> Result, Box Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; @@ -26,12 +26,15 @@ pub fn is_pfl_upg_file(app_ctx: &AppContext) -> Result>, Box pub fn extract_pfl_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; - let header: Header = file.read_le()?; + let header: Header = file.read_le()?; + debug!("pfl_upg header: header_size={}, data_size={}, mask=0x{:08X}", + header.header_size, header.data_size, header.mask); let signature = common::read_exact(&mut file, 128)?; let _ = common::read_exact(&mut file, 32)?; //unknown let version_bytes = common::read_exact(&mut file, 28)?; let version = common::string_from_bytes(&version_bytes); + debug!("pfl_upg version: {}", version); info!("\nVersion: {}", version); if header.description() != "" { //look ugly when empty @@ -39,6 +42,7 @@ pub fn extract_pfl_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), B info!("-------------------"); } info!("Data size: {}", header.data_size); + debug!("pfl_upg: is_encrypted={}", header.is_encrypted()); file.seek(SeekFrom::Start(header.header_size as u64))?; @@ -48,8 +52,10 @@ pub fn extract_pfl_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), B //get some data as test ciphertext for key finding let ciphertext = common::read_file(&mut file, header.header_size as u64, 64)?; + debug!("pfl_upg: ciphertext for key search is {} bytes", ciphertext.len()); let aes_key; if let Some((key_name, key)) = try_find_key(&signature, &ciphertext)? { + debug!("pfl_upg: matched RSA pubkey '{}'", key_name); info!("Matched pubkey: {}, AES key: {}", key_name, hex::encode(key)); aes_key = key; } else { @@ -58,6 +64,7 @@ pub fn extract_pfl_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), B //need to align to 16 bytes for AES blocksize let encrypted_data = common::read_exact(&mut file, (header.data_size as usize + 0xf) & !0xf)?; + debug!("pfl_upg: encrypted data read {} bytes", encrypted_data.len()); info!("Decrypting data..."); data = decrypt_aes256_ecb(&aes_key, &encrypted_data)?; @@ -65,16 +72,22 @@ pub fn extract_pfl_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), B } else { data = common::read_exact(&mut file, header.data_size as usize)?; + debug!("pfl_upg: unencrypted data read {} bytes", data.len()); } let mut data_reader = Cursor::new(data); + debug!("pfl_upg: data_reader length={}", data_reader.get_ref().len()); while (data_reader.position() as usize) < data_reader.get_ref().len() { let file_header: FileHeader = data_reader.read_le()?; + debug!("pfl_upg: file_header: name_len={}, stored={}, real={}, is_folder={}, is_pkg={}", + file_header.file_name().len(), file_header.stored_size, file_header.real_size, + file_header.is_folder(), file_header.is_package()); //sometimes has extra header data let ex_header_size = file_header.header_size - 76; //76 is base file header size let ex_header_bytes = common::read_exact(&mut data_reader, ex_header_size as usize)?; + debug!("pfl_upg: ex_header_size={}", ex_header_size); if file_header.is_folder() { info!("\nFolder - {}", file_header.file_name()); @@ -138,4 +151,4 @@ pub fn extract_pfl_upg(app_ctx: &AppContext, _ctx: Box) -> Result<(), B } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/philips_bdp/mod.rs b/src/formats/philips_bdp/mod.rs index 854aa26..8a973c2 100644 --- a/src/formats/philips_bdp/mod.rs +++ b/src/formats/philips_bdp/mod.rs @@ -91,4 +91,4 @@ pub fn extract_philips_bdp(app_ctx: &AppContext, ctx: Box) -> Result<() } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/pup/mod.rs b/src/formats/pup/mod.rs index 13dc398..5609f3c 100644 --- a/src/formats/pup/mod.rs +++ b/src/formats/pup/mod.rs @@ -10,12 +10,13 @@ use std::io::{Write, Seek, SeekFrom}; use crate::utils::common; use crate::utils::compression::{decompress_zlib}; use include::*; -use log::info; +use log::{debug, info}; pub fn is_pup_file(app_ctx: &AppContext) -> Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; let header = common::read_file(&file, 0, 4)?; + debug!("pup: magic check {:02X?} -> ps4={} ps5={}", header, header==b"\x4F\x15\x3D\x1D", header==b"\x54\x14\xF5\xEE"); if header == b"\x4F\x15\x3D\x1D" || header == b"\x54\x14\xF5\xEE" { //ps4, ps5 Ok(Some(Box::new(()))) } else { @@ -25,10 +26,12 @@ pub fn is_pup_file(app_ctx: &AppContext) -> Result>, Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; + debug!("pup: starting extraction"); let header: Header = file.read_le()?; info!("File info:\nFile size: {}\nEntry count: {}", header.file_size, header.entry_count); + debug!("pup: header file_size={}, entry_count={}", header.file_size, header.entry_count); let mut entries: Vec = Vec::new(); let mut block_tables: Vec = Vec::new(); @@ -36,13 +39,17 @@ pub fn extract_pup(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box) -> Result<(), Box Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; @@ -28,19 +28,25 @@ pub fn is_roku_file(app_ctx: &AppContext) -> Result>, Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; + debug!("roku: starting extraction"); let mut encrypted_data = Vec::new(); - file.read_to_end(&mut encrypted_data)?; + let read_size = file.read_to_end(&mut encrypted_data)?; + debug!("roku: read {} bytes from file", read_size); info!("\nDecrypting...\n"); let tar_data = decrypt_aes128_cbc_pcks7(&encrypted_data, &FILE_KEY, &FILE_IV)?; + debug!("roku: decrypted to {} bytes of tar data", tar_data.len()); let tar_reader = Cursor::new(tar_data); let mut tar_archive = Archive::new(tar_reader); + let mut entry_count = 0; for entry_result in tar_archive.entries_with_seek()? { let mut entry = entry_result?; + entry_count += 1; let path = entry.path()?.to_path_buf(); + debug!("roku: tar entry[{}] = {:?}, size={}", entry_count, path, entry.header().size()?); if path == std::path::Path::new("manifest") { let size = entry.header().size()? as usize; @@ -100,4 +106,4 @@ pub fn extract_roku(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box< } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/ruf/mod.rs b/src/formats/ruf/mod.rs index a0169fa..980ec77 100644 --- a/src/formats/ruf/mod.rs +++ b/src/formats/ruf/mod.rs @@ -115,4 +115,4 @@ fn actually_extract_ruf(mut file: &File, output_folder: &PathBuf, start_offset: } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/rvp/mod.rs b/src/formats/rvp/mod.rs index 4fb0d57..1d83299 100644 --- a/src/formats/rvp/mod.rs +++ b/src/formats/rvp/mod.rs @@ -143,4 +143,4 @@ pub fn extract_rvp(app_ctx: &AppContext, ctx: Box) -> Result<(), Box Result>, Box> { let dir = match app_ctx.dir() {Some(d) => d, None => return Ok(None)}; @@ -28,9 +28,11 @@ pub fn is_samsung_old_dir(app_ctx: &AppContext) -> Result>, pub fn extract_samsung_old(app_ctx: &AppContext, _ctx: Box) -> Result<(), Box> { let path = app_ctx.dir().ok_or("Extractor expected directory")?; + debug!("samsung_old: scanning directory {}", path.display()); let fw_info = fs::read_to_string(Path::new(&path).join("image/info.txt"))?; info!("Firmware info: {}", fw_info); + debug!("samsung_old: fw_info raw: {}", fw_info); let image_path = Path::new(&path).join("image"); @@ -44,6 +46,7 @@ pub fn extract_samsung_old(app_ctx: &AppContext, _ctx: Box) -> Result<( } } if let Some(p) = secret { + debug!("samsung_old: matched secret for prefix '{}'", fw_info.split_whitespace().next().unwrap_or("?")); info!("Secret: {}", p); } else { return Err("This firmware is not supported!".into()); @@ -59,6 +62,7 @@ pub fn extract_samsung_old(app_ctx: &AppContext, _ctx: Box) -> Result<( let file = File::open(&path)?; let filename = path.file_name().unwrap().to_str().unwrap(); let file_size = file.metadata()?.len(); + debug!("samsung_old: processing .sec file '{}' ({} bytes)", filename, file_size); info!("\nFile - {}", filename); let data = common::read_file(&file, 0, file_size.try_into().unwrap())?; @@ -128,4 +132,4 @@ pub fn extract_samsung_old(app_ctx: &AppContext, _ctx: Box) -> Result<( } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/sdboot/mod.rs b/src/formats/sdboot/mod.rs index b537238..594b39f 100644 --- a/src/formats/sdboot/mod.rs +++ b/src/formats/sdboot/mod.rs @@ -134,4 +134,4 @@ pub fn extract_sdboot(app_ctx: &AppContext, _ctx: Box) -> Result<(), Bo } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/sddl_sec/mod.rs b/src/formats/sddl_sec/mod.rs index d793d49..677b035 100644 --- a/src/formats/sddl_sec/mod.rs +++ b/src/formats/sddl_sec/mod.rs @@ -247,4 +247,4 @@ pub fn extract_sddl_sec(app_ctx: &AppContext, _ctx: Box) -> Result<(), } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/sdimage/mod.rs b/src/formats/sdimage/mod.rs index 7f47d5f..139d798 100644 --- a/src/formats/sdimage/mod.rs +++ b/src/formats/sdimage/mod.rs @@ -55,4 +55,4 @@ pub fn extract_sdimage(app_ctx: &AppContext, _ctx: Box) -> Result<(), B } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/slp/mod.rs b/src/formats/slp/mod.rs index 3bad574..0ed3d47 100644 --- a/src/formats/slp/mod.rs +++ b/src/formats/slp/mod.rs @@ -111,4 +111,4 @@ pub fn extract_slp(app_ctx: &AppContext, ctx: Box) -> Result<(), Box Result>, Box> { let file = match app_ctx.file() {Some(f) => f, None => return Ok(None)}; let header_magic = common::read_file(&file, 0, 16)?; + debug!("sony_bdp: header_magic={:02X?}", header_magic); //try old encryption (hex subst) if is_valid_header_magic(&hex_substitute(&header_magic)) { + debug!("sony_bdp: matched HexSubst encryption"); return Ok(Some(Box::new( SonyBdpCtx {encryption_type: EncryptionType::HexSubst @@ -38,6 +40,7 @@ pub fn is_sony_bdp_file(app_ctx: &AppContext) -> Result>, Bo let try_decrypt = ver_up_decrypt_aes128ofb(&key_array, &iv_array, &header_magic); if is_valid_header_magic(&try_decrypt) { + debug!("sony_bdp: matched AES-OFB key '{}'", name); return Ok(Some(Box::new( SonyBdpCtx {encryption_type: EncryptionType::AesOfb((key_array, iv_array, name.to_string())) @@ -45,17 +48,19 @@ pub fn is_sony_bdp_file(app_ctx: &AppContext) -> Result>, Bo ))); } } - + debug!("sony_bdp: no encryption match, skipping"); Ok(None) } pub fn extract_sony_bdp(app_ctx: &AppContext, ctx: Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; let ctx = ctx.downcast::().map_err(|_| "Invalid context type")?; + debug!("sony_bdp: encryption_type={:?}", ctx.encryption_type); //need to decrypt entire file of new aes enc let mut enc_data = Vec::new(); - file.read_to_end(&mut enc_data)?; + let enc_size = file.read_to_end(&mut enc_data)?; + debug!("sony_bdp: read {} encrypted bytes", enc_size); let dec_data = match ctx.encryption_type { EncryptionType::HexSubst => { @@ -67,11 +72,13 @@ pub fn extract_sony_bdp(app_ctx: &AppContext, ctx: Box) -> Result<(), B ver_up_decrypt_aes128ofb(&key, &iv, &enc_data) } }; + debug!("sony_bdp: decrypted to {} bytes", dec_data.len()); let mut data_reader = Cursor::new(dec_data); let header = common::read_exact(&mut data_reader, 300)?; let mut hdr_reader = Cursor::new(header); let hdr: Header = hdr_reader.read_le()?; + debug!("sony_bdp: firmware={}, version={}, date={}, file_size={}", hdr.firmware_name(), hdr.firmware_version(), hdr.date(), hdr.file_size); info!("File info:\nFirmware: {}\nVersion: {}\nDate: {}\nFile size: {}", hdr.firmware_name(), hdr.firmware_version(), hdr.date(), hdr.file_size); @@ -86,6 +93,7 @@ pub fn extract_sony_bdp(app_ctx: &AppContext, ctx: Box) -> Result<(), B } let entry: Entry = hdr_reader.read_le()?; + debug!("sony_bdp: entry[{}] offset={} size={}", i, entry.offset, entry.size); if entry.size == 0 { continue } @@ -132,4 +140,4 @@ pub fn extract_sony_bdp(app_ctx: &AppContext, ctx: Box) -> Result<(), B } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/tsb_bin/mod.rs b/src/formats/tsb_bin/mod.rs index d18f7c9..dc5a7e2 100644 --- a/src/formats/tsb_bin/mod.rs +++ b/src/formats/tsb_bin/mod.rs @@ -13,7 +13,7 @@ use binrw::BinReaderExt; use crate::utils::common; use include::*; use tsb_des::decrypt; -use log::info; +use log::{debug, info}; struct TsbBinCtx { key: Option<[u8; 8]> @@ -24,12 +24,14 @@ pub fn is_tsb_bin_file(app_ctx: &AppContext) -> Result>, Box let header = common::read_file(&file, 0, 256)?; if is_valid_header_checksum(&header) { + debug!("tsb_bin: valid header checksum, no decryption needed"); return Ok(Some(Box::new(TsbBinCtx {key: None}))); } // -- failed, try with decrypt //derive key from FILE SIZE (yes) let file_size = file.metadata()?.len() as u32; + debug!("tsb_bin: header checksum failed, trying size-derived key (file_size={})", file_size); let mut key = [0u8; 8]; key[..4].copy_from_slice(&file_size.to_le_bytes()); let inv = !file_size; @@ -46,6 +48,7 @@ pub fn is_tsb_bin_file(app_ctx: &AppContext) -> Result>, Box pub fn extract_tsb_bin(app_ctx: &AppContext, ctx: Box) -> Result<(), Box> { let mut file = app_ctx.file().ok_or("Extractor expected file")?; let ctx = ctx.downcast::().map_err(|_| "Invalid context type")?; + debug!("tsb_bin: extracted {} key", if ctx.key.is_some() {"size-derived"} else {"none (plain)"}); let mut header = common::read_file(&mut file, 0, 0x400)?; if let Some(key) = ctx.key { //decrypt header @@ -61,6 +64,8 @@ pub fn extract_tsb_bin(app_ctx: &AppContext, ctx: Box) -> Result<(), Bo ,hdr.length, hdr.entry_count, hdr.build_no(), hdr.entry_addr); for (i, entry) in hdr.entries.iter().enumerate() { + debug!("tsb_bin: entry[{}] name={} offset={} size={} load_addr=0x{:02x} comp={}", + i+1, entry.name(), entry.offset, entry.size, entry.load_addr, entry.is_compressed()); info!("\n({}/{}) - {}, Size: {}, Offset: {}, Load address: 0x{:02x}", i+1, hdr.entry_count, entry.name(), entry.size, entry.offset, entry.load_addr); @@ -90,4 +95,4 @@ pub fn extract_tsb_bin(app_ctx: &AppContext, ctx: Box) -> Result<(), Bo } Ok(()) -} \ No newline at end of file +} diff --git a/src/formats/vestel/mod.rs b/src/formats/vestel/mod.rs index 2fba9e8..44c840d 100644 --- a/src/formats/vestel/mod.rs +++ b/src/formats/vestel/mod.rs @@ -216,4 +216,4 @@ fn extract_mb230( } Ok(()) -} \ No newline at end of file +} diff --git a/src/main.rs b/src/main.rs index 2b6a49b..1e7c0c6 100644 --- a/src/main.rs +++ b/src/main.rs @@ -99,16 +99,15 @@ fn main() -> Result<(), Box> { // Initialize logger based on verbosity level // Default (no flags): show info-level output (normal progress) // -q: errors only - // -v: info (same as default, explicit) - // -vv: debug level (more details) + // -v: debug level (more details) + // -vv: trace level (everything) // -vvv: trace level (everything) let log_level = if args.quiet { "error" } else { match args.verbose { 0 => "info", - 1 => "info", - 2 => "debug", + 1 => "debug", _ => "trace", } }; @@ -118,14 +117,12 @@ fn main() -> Result<(), Box> { .format_target(false) .format_module_path(false) .format(|buf, record| { - // Clean format: just the message for info/debug/trace - // Add level prefix for warn/error so they stand out match record.level() { - log::Level::Error => writeln!(buf, "[ERROR] {}", record.args()), - log::Level::Warn => writeln!(buf, "[WARN] {}", record.args()), - log::Level::Info => writeln!(buf, "{}", record.args()), - log::Level::Debug => writeln!(buf, "[DBG] {}", record.args()), - log::Level::Trace => writeln!(buf, "[TRC] {}", record.args()), + log::Level::Error => writeln!(buf, "\x1b[31m[ERROR]\x1b[0m {}", record.args()), + log::Level::Warn => writeln!(buf, "\x1b[33m[WARN]\x1b[0m {}", record.args()), + log::Level::Info => writeln!(buf, "\x1b[36m{}\x1b[0m", record.args()), + log::Level::Debug => writeln!(buf, "\x1b[32m[DBG]\x1b[0m {}", record.args()), + log::Level::Trace => writeln!(buf, "\x1b[90m[TRC]\x1b[0m {}", record.args()), } }) .init(); diff --git a/src/utils.rs b/src/utils.rs index 5a8d9ab..855d169 100644 --- a/src/utils.rs +++ b/src/utils.rs @@ -1,3 +1,4 @@ +pub mod sevenz; pub mod common; pub mod aes; pub mod lzop; diff --git a/src/utils/sevenz.rs b/src/utils/sevenz.rs new file mode 100644 index 0000000..e952583 --- /dev/null +++ b/src/utils/sevenz.rs @@ -0,0 +1,16 @@ +use std::path::PathBuf; +use log::info; + +#[allow(dead_code)] +pub fn decompress_7z(data: &[u8], output_dir: PathBuf) -> Result<(), Box> { + info!("- Decompressing 7z archive..."); + sevenz_rust2::decompress(std::io::Cursor::new(data.to_vec()), &output_dir)?; + Ok(()) +} + +#[allow(dead_code)] +pub fn decompress_7z_file(file_path: &std::path::Path, output_dir: PathBuf) -> Result<(), Box> { + info!("- Decompressing 7z file..."); + sevenz_rust2::decompress_file(file_path, &output_dir)?; + Ok(()) +} diff --git a/src/utils/sparse.rs b/src/utils/sparse.rs index 9a58613..40c846e 100644 --- a/src/utils/sparse.rs +++ b/src/utils/sparse.rs @@ -68,4 +68,4 @@ pub fn unsparse_to_file(data: &[u8], file_path: PathBuf) -> Result<(), Box