improve logging in deserialize path and tests

* Log the depth of elements as they're fetched
* Log the starting depth of structs/enums and their Rust symbol names
  (not just XML element names, which may differ significantly)
* Log every element in the struct/enum match loop at trace level.
* Log file/line numbers at a few key points in the tests.
  This is helpful in finding failures happen in some of the longer
  tests.

This logging helps me understand the data flow as I play with changes
for #76.

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,6 +338,7 @@ 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;
@@ -389,6 +392,7 @@ pub fn parse(
 
         #visit_unused
 
+        debug!("Struct {} @ {}: success", stringify!(#name), start_depth);
         Ok(#name{#struct_builder})
       }
     }