Merge pull request #83 from scottlamb/pr-debugging-and-cleanups

debugging and cleanups

.gitignore

@@ -5,6 +5,13 @@
 # will have compiled files and executables
 /target
 
+# YouCompleteMe + its bundled RLS appear to create target directories within
+# the crate paths, contrary to the documentation of how workspaces work.
+# (As of https://github.com/ycm-core/YouCompleteMe.git f9906f8,
+# which pulls in rls from nightly-2020-04-17.)
+/yaserde/target
+/yaserde_derive/target
+
 # Remove Cargo.lock from gitignore if creating an executable, leave it for libraries
 # More information here http://doc.crates.io/guide.html#cargotoml-vs-cargolock
 Cargo.lock

yaserde/Cargo.toml

@@ -17,6 +17,7 @@ xml-rs = "0.8.3"
 log = "0.4"
 
 [dev-dependencies]
+env_logger = "0.7.1"
 yaserde_derive = { version = "0.4", path = "../yaserde_derive" }
 
 [badges]

yaserde/src/de/mod.rs

@@ -85,7 +85,7 @@ impl<'de, R: Read> Deserializer<R> {
       }
       _ => {}
     }
-    debug!("Fetched {:?}", next_event);
+    debug!("Fetched {:?}, new depth {}", next_event, self.depth);
     Ok(next_event)
   }
 

yaserde/src/lib.rs

@@ -213,6 +213,7 @@ mod testing {
   #[macro_export]
   macro_rules! deserialize_and_validate {
     ($content: expr, $model: expr, $struct: tt) => {
+      log::debug!("deserialize_and_validate @ {}:{}", file!(), line!());
       let loaded: Result<$struct, String> = yaserde::de::from_str($content);
       assert_eq!(loaded, Ok($model));
     };
@@ -221,6 +222,7 @@ mod testing {
   #[macro_export]
   macro_rules! serialize_and_validate {
     ($model: expr, $content: expr) => {
+      log::debug!("serialize_and_validate @ {}:{}", file!(), line!());
       let data: Result<String, String> = yaserde::ser::to_string(&$model);
 
       let content = String::from(r#"<?xml version="1.0" encoding="utf-8"?>"#) + &$content;

yaserde/tests/default.rs

@@ -6,8 +6,14 @@ extern crate yaserde_derive;
 use std::io::{Read, Write};
 use yaserde::{YaDeserialize, YaSerialize};
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn default_field_string() {
+  init();
+
   fn default_string() -> String {
     "my_default_value".to_string()
   }
@@ -37,6 +43,8 @@ fn default_field_string() {
 
 #[test]
 fn default_field_boolean() {
+  init();
+
   fn default_boolean() -> bool {
     true
   }
@@ -61,6 +69,8 @@ fn default_field_boolean() {
 
 #[test]
 fn default_field_number() {
+  init();
+
   fn default_number() -> u8 {
     6
   }
@@ -85,6 +95,8 @@ fn default_field_number() {
 
 #[test]
 fn default_attribute_string() {
+  init();
+
   fn default_string() -> String {
     "my_default_value".to_string()
   }
@@ -113,6 +125,8 @@ fn default_attribute_string() {
 
 #[test]
 fn module_inclusion() {
+  init();
+
   mod module {
     use super::*;
 

yaserde/tests/deserializer.rs

@@ -3,12 +3,18 @@ extern crate yaserde;
 #[macro_use]
 extern crate yaserde_derive;
 
+use log::debug;
 use std::io::{Read, Write};
 use yaserde::de::from_str;
 use yaserde::{YaDeserialize, YaSerialize};
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 macro_rules! convert_and_validate {
   ($content: expr, $struct: tt, $model: expr) => {
+    debug!("convert_and_validate @ {}:{}", file!(), line!());
     let loaded: Result<$struct, String> = from_str($content);
     assert_eq!(loaded, Ok($model));
   };
@@ -16,6 +22,8 @@ macro_rules! convert_and_validate {
 
 #[test]
 fn de_basic() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "book")]
   pub struct Book {
@@ -48,6 +56,8 @@ fn de_basic() {
 
 #[test]
 fn de_dash_param() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "book")]
   pub struct Book {
@@ -81,6 +91,8 @@ fn de_dash_param() {
 
 #[test]
 fn de_multiple_segments() {
+  init();
+
   mod other_mod {
     use std::io::Read;
     use yaserde::YaDeserialize;
@@ -127,6 +139,8 @@ fn de_multiple_segments() {
 
 #[test]
 fn de_list_of_items() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "library")]
   pub struct Library {
@@ -167,6 +181,8 @@ fn de_list_of_items() {
 
 #[test]
 fn de_attributes() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "base")]
   pub struct XmlStruct {
@@ -205,6 +221,8 @@ fn de_attributes() {
 
 #[test]
 fn de_attributes_custom_deserializer() {
+  init();
+
   mod other_mod {
     use super::*;
 
@@ -269,6 +287,8 @@ fn de_attributes_custom_deserializer() {
 
 #[test]
 fn de_attributes_complex() {
+  init();
+
   mod other_mod {
     use super::*;
 
@@ -316,6 +336,8 @@ fn de_attributes_complex() {
 
 #[test]
 fn de_rename() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "base")]
   pub struct XmlStruct {
@@ -358,6 +380,8 @@ fn de_rename() {
 
 #[test]
 fn de_text_content_with_attributes() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "base")]
   pub struct XmlStruct {
@@ -402,6 +426,8 @@ fn de_text_content_with_attributes() {
 
 #[test]
 fn de_enum() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "base")]
   pub struct XmlStruct {
@@ -466,6 +492,8 @@ fn de_enum() {
 
 #[test]
 fn de_attribute_enum() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "base")]
   pub struct XmlStruct {
@@ -498,6 +526,8 @@ fn de_attribute_enum() {
 
 #[test]
 fn de_complex_enum() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   pub struct XmlStruct {
     background: Color,
@@ -717,6 +747,8 @@ fn de_complex_enum() {
 
 #[test]
 fn de_name_issue_21() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "book")]
   pub struct Book {
@@ -735,6 +767,8 @@ fn de_name_issue_21() {
 
 #[test]
 fn de_custom() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   struct Date {
     #[yaserde(rename = "Year")]
@@ -792,6 +826,8 @@ fn de_custom() {
 
 #[test]
 fn de_subitem_issue_12() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   pub struct Struct {
     id: i32,
@@ -814,6 +850,8 @@ fn de_subitem_issue_12() {
 
 #[test]
 fn de_subitem_issue_12_with_sub() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   pub struct SubStruct {
     id: i32,
@@ -846,6 +884,8 @@ fn de_subitem_issue_12_with_sub() {
 
 #[test]
 fn de_subitem_issue_12_attributes() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   pub struct Struct {
     #[yaserde(attribute)]
@@ -866,6 +906,8 @@ fn de_subitem_issue_12_attributes() {
 
 #[test]
 fn de_subitem_issue_12_attributes_with_sub() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   pub struct SubStruct {
     #[yaserde(attribute)]
@@ -899,6 +941,8 @@ fn de_subitem_issue_12_attributes_with_sub() {
 
 #[test]
 fn de_same_field_name_sub() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   pub struct SubStruct {
     sub: Option<i32>,
@@ -922,6 +966,8 @@ fn de_same_field_name_sub() {
 
 #[test]
 fn de_same_field_name_sub_sub() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize)]
   pub struct SubSubStruct {
     sub: i32,
@@ -960,6 +1006,8 @@ fn de_same_field_name_sub_sub() {
 
 #[test]
 fn de_same_field_name_but_some_other_fields_or_something() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize, YaSerialize)]
   #[yaserde(rename = "foo")]
   pub struct FooOuter {

yaserde/tests/errors.rs

@@ -5,8 +5,14 @@ use std::io::Read;
 use yaserde::de::from_str;
 use yaserde::YaDeserialize;
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn de_no_content() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "book")]
   pub struct Book {
@@ -26,6 +32,8 @@ fn de_no_content() {
 
 #[test]
 fn de_wrong_end_balise() {
+  init();
+
   #[derive(YaDeserialize, PartialEq, Debug)]
   #[yaserde(root = "book")]
   pub struct Book {

yaserde/tests/flatten.rs

@@ -7,8 +7,14 @@ use std::io::{Read, Write};
 
 use yaserde::{YaDeserialize, YaSerialize};
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn basic_flatten() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize, YaSerialize)]
   struct DateTime {
     #[yaserde(flatten)]
@@ -93,6 +99,8 @@ fn basic_flatten() {
 
 #[test]
 fn root_flatten_struct() {
+  init();
+
   #[derive(YaDeserialize, YaSerialize, PartialEq, Debug)]
   #[yaserde(flatten)]
   pub struct Content {
@@ -113,6 +121,8 @@ fn root_flatten_struct() {
 
 #[test]
 fn root_flatten_enum() {
+  init();
+
   #[derive(YaSerialize, PartialEq, Debug)]
   #[yaserde(flatten)]
   pub enum Content {
@@ -147,6 +157,8 @@ fn root_flatten_enum() {
 
 #[test]
 fn flatten_attribute() {
+  init();
+
   #[derive(Default, PartialEq, Debug, YaDeserialize, YaSerialize)]
   struct HtmlText {
     #[yaserde(flatten)]

yaserde/tests/namespace.rs

@@ -6,8 +6,14 @@ extern crate yaserde_derive;
 use std::io::{Read, Write};
 use yaserde::{YaDeserialize, YaSerialize};
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn struct_simple_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "book",
@@ -39,6 +45,8 @@ fn struct_simple_namespace() {
 
 #[test]
 fn struct_multiple_namespaces() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "book",
@@ -71,6 +79,8 @@ fn struct_multiple_namespaces() {
 
 #[test]
 fn struct_partial_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "book",
@@ -101,6 +111,8 @@ fn struct_partial_namespace() {
 
 #[test]
 fn struct_sub_namespace_definition() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "book",
@@ -134,6 +146,8 @@ fn struct_sub_namespace_definition() {
 
 #[test]
 fn struct_namespace_nested() {
+  init();
+
   #[derive(Debug, Default, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(prefix = "nsa", namespace = "nsa: http://www.sample.com/ns/a")]
   struct A {
@@ -167,6 +181,8 @@ fn struct_namespace_nested() {
 
 #[test]
 fn struct_namespace_nested_defined_at_root() {
+  init();
+
   #[derive(Debug, Default, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(prefix = "nsa", namespace = "nsa: http://www.sample.com/ns/a")]
   struct A {
@@ -204,6 +220,8 @@ fn struct_namespace_nested_defined_at_root() {
 
 #[test]
 fn struct_attribute_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "root",
@@ -234,6 +252,8 @@ fn struct_attribute_namespace() {
 
 #[test]
 fn struct_implicit_default_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "tt",
@@ -256,6 +276,8 @@ fn struct_implicit_default_namespace() {
 
 #[test]
 fn struct_explicit_default_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "tt",
@@ -279,6 +301,8 @@ fn struct_explicit_default_namespace() {
 
 #[test]
 fn struct_default_namespace_via_attribute_with_prefix() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "tt",
@@ -303,6 +327,8 @@ fn struct_default_namespace_via_attribute_with_prefix() {
 
 #[test]
 fn enum_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "root",
@@ -333,6 +359,8 @@ fn enum_namespace() {
 
 #[test]
 fn enum_multi_namespaces() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "root",
@@ -374,6 +402,8 @@ fn enum_multi_namespaces() {
 
 #[test]
 fn enum_attribute_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "rootA",
@@ -412,6 +442,8 @@ fn enum_attribute_namespace() {
 
 #[test]
 fn struct_bad_namespace() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   #[yaserde(
     rename = "book",

yaserde/tests/option.rs

@@ -6,8 +6,14 @@ extern crate yaserde_derive;
 use std::io::{Read, Write};
 use yaserde::{YaDeserialize, YaSerialize};
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn basic_option_types() {
+  init();
+
   test_for_type!(Option::<String>, Some("test".to_string()), Some("test"));
   test_for_type!(Option::<String>, None, None);
   test_for_type!(Option::<bool>, Some(true), Some("true"));
@@ -75,6 +81,8 @@ fn basic_option_types() {
 
 #[test]
 fn option_struct() {
+  init();
+
   #[derive(Debug, PartialEq, YaDeserialize, YaSerialize)]
   struct Test {
     field: SubTest,

yaserde/tests/skip_if.rs

@@ -6,8 +6,14 @@ extern crate yaserde_derive;
 use std::io::Write;
 use yaserde::YaSerialize;
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn skip_serializing_if_for_struct() {
+  init();
+
   fn default_string_function() -> String {
     "mask_default".to_string()
   }

yaserde/tests/types.rs

@@ -6,8 +6,14 @@ extern crate yaserde_derive;
 use std::io::{Read, Write};
 use yaserde::{YaDeserialize, YaSerialize};
 
+fn init() {
+  let _ = env_logger::builder().is_test(true).try_init();
+}
+
 #[test]
 fn ser_type() {
+  init();
+
   test_for_type!(String, "test".to_string(), Some("test"));
   test_for_type!(bool, true, Some("true"));
   test_for_type!(u8, 12 as u8, Some("12"));

yaserde_derive/src/de/expand_enum.rs

@@ -29,7 +29,7 @@ pub fn parse(
     use yaserde::Visitor;
     #[allow(unknown_lints, unused_imports)]
     use std::str::FromStr;
-    use log::debug;
+    use log::{debug, trace};
 
     impl YaDeserialize for #name {
       #[allow(unused_variables)]
@@ -41,7 +41,8 @@ pub fn parse(
             (String::from(#root), None)
           };
 
-        debug!("Enum: start to parse {:?}", named_element);
+        let start_depth = reader.depth();
+        debug!("Enum {} @ {}: start to parse {:?}", stringify!(#name), start_depth, named_element);
 
         #namespaces_matching
 
@@ -49,9 +50,10 @@ pub fn parse(
         let mut enum_value = None;
 
         loop {
-          match reader.peek()?.to_owned() {
+          let event = reader.peek()?.to_owned();
+          trace!("Enum {} @ {}: matching {:?}", stringify!(#name), start_depth, event);
+          match event {
             XmlEvent::StartElement{ref name, ref attributes, ..} => {
-              // trace!("{:?}", name.local_name.as_str());
               match name.local_name.as_str() {
                 #match_to_enum
                 _named_element => {
@@ -88,6 +90,7 @@ pub fn parse(
           }
         }
 
+        debug!("Enum {} @ {}: success", stringify!(#name), start_depth);
         match enum_value {
           Some(value) => Ok(value),
           None => {

yaserde_derive/src/de/expand_struct.rs

@@ -311,7 +311,7 @@ pub fn parse(
     use yaserde::Visitor;
     #[allow(unknown_lints, unused_imports)]
     use std::str::FromStr;
-    use log::debug;
+    use log::{debug, trace};
 
     impl YaDeserialize for #name {
       #[allow(unused_variables)]
@@ -322,7 +322,9 @@ pub fn parse(
           } else {
             (String::from(#root), None)
           };
-        debug!("Struct: start to parse {:?}", named_element);
+        let start_depth = reader.depth();
+        debug!("Struct {} @ {}: start to parse {:?}", stringify!(#name), start_depth,
+               named_element);
 
         if reader.depth() == 0 {
           #namespaces_matching
@@ -336,28 +338,23 @@ pub fn parse(
 
         loop {
           let event = reader.peek()?.to_owned();
+          trace!("Struct {} @ {}: matching {:?}", stringify!(#name), start_depth, event);
           match event {
             XmlEvent::StartElement{ref name, ref attributes, ..} => {
-              let mut skipped = false;
-
               match name.local_name.as_str() {
                 #call_visitors
-                named_element => {
+                _ => {
                   let event = reader.next_event()?;
                   #write_unused
 
                   if depth > 0 { // Don't skip root element
-                    skipped = true;
                     reader.skip_element(|event| {
                       #write_unused
                     })?;
                   }
                 }
-                // name => {
-                //   return Err(format!("unknown key {}", name))
-                // }
               }
-              if depth == 0 && !skipped { // Look for attributes only at element start
+              if depth == 0 { // Look for attributes only at element start
                 #attributes_loading
               }
               depth += 1;
@@ -389,6 +386,7 @@ pub fn parse(
 
         #visit_unused
 
+        debug!("Struct {} @ {}: success", stringify!(#name), start_depth);
         Ok(#name{#struct_builder})
       }
     }