Merge pull request #9 from xandkar/sk/move-from-eprint-to-tracing

mindeng · Jul 18, 2024 · a03defb · a03defb
2 parents afbee48 + 4b0dcfa
commit a03defb
Show file tree

Hide file tree

Showing 15 changed files with 142 additions and 61 deletions.
diff --git a/.github/workflows/rust.yml b/.github/workflows/rust.yml
@@ -19,4 +19,4 @@ jobs:
     - name: Build
       run: cargo build --verbose
     - name: Run tests
-      run: cargo test --verbose
+      run: cargo test --verbose -- --nocapture
diff --git a/Cargo.toml b/Cargo.toml
@@ -1,6 +1,6 @@
 [package]
 name = "nom-exif"
-version = "1.2.6"
+version = "1.3.0"
 edition = "2021"
 license-file = "LICENSE"
 description = "Exif/metadata parsing library written in pure Rust, both JPEG/HEIF/HEIC images and MOV/MP4 videos are supported."
@@ -18,6 +18,7 @@ thiserror = "1.0"
 serde = { version = "1.0", features = ["derive"], optional = true }
 regex = { version = "1.10" }
 chrono = "0.4"
+tracing = { version = "0.1.40" }
 
 [features]
 json_dump = ["serde"]
@@ -29,6 +30,7 @@ chrono = "0.4"
 serde_json = "1.0"
 regex = { version = "1.10" }
 clap = { version = "4.4", features = ["derive"] }
+tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
 
 [[example]]
 name = "rexiftool"

diff --git a/src/bbox.rs b/src/bbox.rs
@@ -49,15 +49,16 @@ pub struct BoxHeader {
 }
 
 impl BoxHeader {
+    #[tracing::instrument(skip_all)]
     pub fn parse<'a>(input: &'a [u8]) -> IResult<&'a [u8], BoxHeader> {
         let (remain, size) = number::streaming::be_u32(input)?;
 
         let (remain, box_type) = map_res(streaming::take(4_usize), |res: &'a [u8]| {
             // String::from_utf8 will fail on "©xyz"
             Ok::<String, ()>(res.iter().map(|b| b.as_char()).collect::<String>())
-            // String::from_utf8(res.to_vec()).map_err(|e| {
-            //     eprintln!("{e:?}");
-            //     e
+            // String::from_utf8(res.to_vec()).map_err(|error| {
+            //     tracing::error!(?error, ?res, "Failed to construct string");
+            //     error
             // })
         })(remain)?;
 
@@ -77,20 +78,17 @@ impl BoxHeader {
         }
 
         if box_size > (MAX_BODY_LEN + header_size) as u64 {
-            eprintln!(
-                "box size of box '{}' is too big: {}",
-                box_type
-                    .chars()
-                    .map(|c| {
-                        if c.is_ascii_graphic() {
-                            c.as_char()
-                        } else {
-                            '*'
-                        }
-                    })
-                    .collect::<String>(),
-                box_size
-            );
+            let box_type = box_type
+                .chars()
+                .map(|c| {
+                    if c.is_ascii_graphic() {
+                        c.as_char()
+                    } else {
+                        '*'
+                    }
+                })
+                .collect::<String>();
+            tracing::error!(?box_type, ?box_size, "Box is too big");
             return fail(remain);
         }
 
@@ -156,10 +154,11 @@ pub struct BoxHolder<'a> {
 }
 
 impl<'a> BoxHolder<'a> {
+    #[tracing::instrument(skip_all)]
     pub fn parse(input: &'a [u8]) -> IResult<&'a [u8], BoxHolder<'a>> {
         let (_, header) = BoxHeader::parse(input)?;
         let (remain, data) = streaming::take(header.box_size)(input)?;
-        // println!("got {} {}", header.box_type, data.len());
+        tracing::debug!(?header.box_type, data_len = ?data.len(), "Got");
 
         Ok((remain, BoxHolder { header, data }))
     }
@@ -339,11 +338,13 @@ mod tests {
 
     #[test_case("exif.heic")]
     fn travel_heic(path: &str) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let mut boxes = Vec::new();
 
         let (remain, bbox) = travel_while(&buf, |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push((bbox.header.box_type.to_owned(), bbox.to_owned()));
             bbox.box_type() != "mdat"
         })
@@ -365,7 +366,7 @@ mod tests {
         let (remain, bbox) = travel_while(
             &meta.body_data()[4..], // Safe-slice in test_case
             |bbox| {
-                // println!("got {}", bbox.header.box_type);
+                tracing::info!(bbox.header.box_type, "Got");
                 boxes.push(bbox.header.box_type.to_owned());
                 bbox.box_type() != "iloc"
             },
@@ -384,11 +385,13 @@ mod tests {
 
     #[test_case("meta.mov")]
     fn travel_mov(path: &str) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let mut boxes = Vec::new();
 
         let (remain, bbox) = travel_while(&buf, |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push((bbox.header.box_type.to_owned(), bbox.to_owned()));
             bbox.box_type() != "moov"
         })
@@ -408,7 +411,7 @@ mod tests {
 
         let mut boxes = Vec::new();
         let (remain, bbox) = travel_while(moov.body_data(), |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push(bbox.header.box_type.to_owned());
             bbox.box_type() != "meta"
         })
@@ -424,7 +427,7 @@ mod tests {
         let meta = bbox;
         let mut boxes = Vec::new();
         let (remain, _) = travel_while(meta.body_data(), |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push(bbox.header.box_type.to_owned());
             bbox.box_type() != "ilst"
         })
@@ -437,11 +440,13 @@ mod tests {
 
     #[test_case("meta.mp4")]
     fn travel_mp4(path: &str) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let mut boxes = Vec::new();
 
         let (remain, bbox) = travel_while(&buf, |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push((bbox.header.box_type.to_owned(), bbox.to_owned()));
             bbox.box_type() != "moov"
         })
@@ -461,7 +466,7 @@ mod tests {
 
         let mut boxes = Vec::new();
         let (remain, bbox) = travel_while(moov.body_data(), |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push((bbox.header.box_type.to_owned(), bbox.to_owned()));
             bbox.box_type() != "udta"
         })
@@ -482,7 +487,7 @@ mod tests {
         let meta = bbox;
         let mut boxes = Vec::new();
         let (remain, _) = travel_while(meta.body_data(), |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push(bbox.header.box_type.to_owned());
             bbox.box_type() != "©xyz"
         })
@@ -494,7 +499,7 @@ mod tests {
 
         let mut boxes = Vec::new();
         let (remain, bbox) = travel_while(trak.body_data(), |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push(bbox.header.box_type.to_owned());
             bbox.box_type() != "mdia"
         })
@@ -507,7 +512,7 @@ mod tests {
         let mdia = bbox.unwrap();
         let mut boxes = Vec::new();
         let (remain, _) = travel_while(mdia.body_data(), |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             boxes.push(bbox.header.box_type.to_owned());
             bbox.box_type() != "minf"
         })
@@ -522,10 +527,12 @@ mod tests {
     // atom.
     #[test_case("meta.mp4")]
     fn find_android_gps_box(path: &str) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let (_, bbox) = find_box(&buf, "moov/udta/©xyz").unwrap();
         let bbox = bbox.unwrap();
-        // println!("bbox: {:?}", bbox.header);
+        tracing::info!(?bbox.header, "bbox");
 
         // gps info
         assert_eq!(
@@ -536,6 +543,8 @@ mod tests {
 
     #[test]
     fn box_header() {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let data = [
             0x00, 0x00, 0x01, 0xdd, 0x6d, 0x65, 0x74, 0x61, 0x02, 0x04, 0x04, 0x00,
         ];

diff --git a/src/bbox/iinf.rs b/src/bbox/iinf.rs
@@ -61,6 +61,7 @@ pub(crate) struct InfeBox {
 }
 
 impl ParseBody<InfeBox> for InfeBox {
+    #[tracing::instrument(skip_all)]
     fn parse_body<'a>(remain: &'a [u8], header: FullBoxHeader) -> IResult<&'a [u8], InfeBox> {
         let version = header.version;
 
@@ -79,10 +80,7 @@ impl ParseBody<InfeBox> for InfeBox {
             }),
         )(remain)?;
 
-        // println!(
-        //     "got {} type: {:?} ver: {version}",
-        //     header.box_type, item_type,
-        // );
+        tracing::debug!(?header.box_type, ?item_type, ?version, "Got");
 
         let (remain, item_name) = parse_cstr(remain).map_err(|e| {
             if e.is_incomplete() {

diff --git a/src/bbox/iloc.rs b/src/bbox/iloc.rs
@@ -25,6 +25,7 @@ pub struct IlocBox {
 const MAX_ILOC_EXTENTS_PER_ITEM: u16 = 32;
 
 impl ParseBody<IlocBox> for IlocBox {
+    #[tracing::instrument(skip_all)]
     fn parse_body(remain: &[u8], header: FullBoxHeader) -> IResult<&[u8], IlocBox> {
         let version = header.version;
 
@@ -59,7 +60,7 @@ impl ParseBody<IlocBox> for IlocBox {
 
             let (remain, extent_count) = be_u16(remain)?;
             if extent_count > MAX_ILOC_EXTENTS_PER_ITEM {
-                // eprintln!("extent_count: {extent_count}");
+                tracing::debug!(?extent_count, "extent_count");
                 context("extent_count > 32", fail::<_, (), _>)(remain)?;
             }
 

diff --git a/src/bbox/ilst.rs b/src/bbox/ilst.rs
@@ -83,6 +83,7 @@ impl IlstItem {
 
 /// Parse ilst item data to value, see [Well-known
 /// types](https://developer.apple.com/documentation/quicktime-file-format/well-known_types)
+#[tracing::instrument(skip(data))]
 fn parse_value(type_code: u32, data: &[u8]) -> crate::Result<EntryValue> {
     use EntryValue::*;
     let v = match type_code {
@@ -96,9 +97,13 @@ fn parse_value(type_code: u32, data: &[u8]) -> crate::Result<EntryValue> {
             3 => be_i24(data)?.1.into(),
             4 => be_i32(data)?.1.into(),
             8 => be_i64(data)?.1.into(),
-            x => {
-                let msg = format!("Invalid ilst item data; data type is BE Signed Integer while data len is : {x}");
-                // eprintln!("{msg}");
+            data_len => {
+                let data_type = "BE Signed Integer";
+                tracing::error!(data_type, data_len, "Invalid ilst item data.");
+                let msg = format!(
+                    "Invalid ilst item data; \
+                    data type is {data_type} while data len is : {data_len}",
+                );
                 return Err(msg.into());
             }
         },
@@ -108,18 +113,22 @@ fn parse_value(type_code: u32, data: &[u8]) -> crate::Result<EntryValue> {
             3 => be_u24(data)?.1.into(),
             4 => be_u32(data)?.1.into(),
             8 => be_u64(data)?.1.into(),
-            x => {
-                let msg = format!("Invalid ilst item data; data type is BE Unsigned Integer while data len is : {x}");
-                // eprintln!("{msg}");
+            data_len => {
+                let data_type = "BE Unsigned Integer";
+                tracing::error!(data_type, data_len, "Invalid ilst item data.");
+                let msg = format!(
+                    "Invalid ilst item data; \
+                    data type is {data_type} while data len is : {data_len}",
+                );
                 return Err(msg.into());
             }
         },
         23 => be_f32(data)?.1.into(),
         24 => be_f64(data)?.1.into(),
-        o => {
-            let msg = format!("Unsupported ilst item data type: {o}");
-            // eprintln!("{msg}");
-            return Err(msg.into());
+        data_type => {
+            let msg = format!("Unsupported ilst item data type");
+            tracing::error!(data_type, "{}.", msg);
+            return Err(format!("{}: {data_type}", msg).into());
         }
     };
     Ok(v)
@@ -134,6 +143,8 @@ mod tests {
 
     #[test_case("meta.mov")]
     fn ilst_box(path: &str) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let (_, bbox) = travel_while(&buf, |b| b.box_type() != "moov").unwrap();
         let bbox = bbox.unwrap();
@@ -143,7 +154,7 @@ mod tests {
         let bbox = bbox.unwrap();
 
         let (rem, ilst) = IlstBox::parse_box(bbox.data).unwrap();
-        println!("ilst: {ilst:?}");
+        tracing::info!(?ilst, "ilst");
         assert_eq!(rem, b"");
 
         assert_eq!(
@@ -163,6 +174,8 @@ mod tests {
 
     #[test_case("embedded-in-heic.mov")]
     fn heic_mov_ilst(path: &str) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let (_, moov) = travel_while(&buf, |b| b.box_type() != "moov").unwrap();
         let moov = moov.unwrap();

diff --git a/src/bbox/keys.rs b/src/bbox/keys.rs
@@ -78,6 +78,8 @@ mod tests {
 
     #[test_case("meta.mov", 4133, 0x01b9, 0xc9)]
     fn keys_box(path: &str, moov_size: u64, meta_size: u64, keys_size: u64) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let (_, moov) = travel_while(&buf, |b| b.box_type() != "moov").unwrap();
         let moov = moov.unwrap();
@@ -127,6 +129,8 @@ mod tests {
 
     #[test_case("embedded-in-heic.mov", 0x1790, 0x0372, 0x1ce)]
     fn heic_mov_keys(path: &str, moov_size: u64, meta_size: u64, keys_size: u64) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let (_, moov) = travel_while(&buf, |b| b.box_type() != "moov").unwrap();
         let moov = moov.unwrap();

diff --git a/src/bbox/meta.rs b/src/bbox/meta.rs
@@ -65,6 +65,7 @@ impl ParseBody<MetaBox> for MetaBox {
 }
 
 impl MetaBox {
+    #[tracing::instrument(skip_all)]
     pub fn exif_data<'a>(&self, input: &'a [u8]) -> IResult<&'a [u8], Option<&'a [u8]>> {
         self.iinf
             .as_ref()
@@ -86,10 +87,10 @@ impl MetaBox {
                     }
                 } else if construction_method == 1 {
                     // idat offset
-                    eprintln!("idat offset construction method is not supported yet");
+                    tracing::debug!("idat offset construction method is not supported yet");
                     fail(input)
                 } else {
-                    eprintln!("item offset construction method is not supported yet");
+                    tracing::debug!("item offset construction method is not supported yet");
                     fail(input)
                 }
             })
@@ -123,9 +124,11 @@ mod tests {
 
     #[test_case("exif.heic", 2618)]
     fn meta(path: &str, meta_size: usize) {
+        let _ = tracing_subscriber::fmt().with_test_writer().try_init();
+
         let buf = read_sample(path).unwrap();
         let (_, bbox) = travel_while(&buf, |bbox| {
-            // println!("got {}", bbox.header.box_type);
+            tracing::info!(bbox.header.box_type, "Got");
             bbox.box_type() != "meta"
         })
         .unwrap();