Why fields are visited more than once when deserialization?

Question

I am running serde_test, testing against the example from official documentation: https://serde.rs/deserialize-struct.html. All the code is identical except that the fn main() is mine.

My goal is to check that visit_map is being called in a manner that I've expected it to be, that is, there is exactly 1 call for each struct, but due to my tests, each field is being called twice, why?

There is no documentation indicating that visit_map would be called twice. Thus as a user, it's reasonable to assume that there is only one. If someonce want to do a non-trivial task inside visit_map, it might be a huge cost to implement Deserialize by hand.

The code:

use std::fmt;

use serde::de::{self, Deserialize, Deserializer, MapAccess, SeqAccess, Visitor};

#[derive(Debug, PartialEq)]
struct Duration {
    secs: u64,
    nanos: u32,
}

impl<'de> Deserialize<'de> for Duration {
    fn deserialize<D>(deserializer: D) -> Result<Self, D::Error>
    where
        D: Deserializer<'de>,
    {
        #[derive(Debug)]
        enum Field {
            Secs,
            Nanos,
        }

        // This part could also be generated independently by:
        //
        //    #[derive(Deserialize)]
        //    #[serde(field_identifier, rename_all = "lowercase")]
        //    enum Field { Secs, Nanos }
        impl<'de> Deserialize<'de> for Field {
            fn deserialize<D>(deserializer: D) -> Result<Field, D::Error>
            where
                D: Deserializer<'de>,
            {
                struct FieldVisitor;

                impl<'de> Visitor<'de> for FieldVisitor {
                    type Value = Field;

                    fn expecting(&self, formatter: &mut fmt::Formatter) -> fmt::Result {
                        formatter.write_str("`secs` or `nanos`")
                    }

                    fn visit_str<E>(self, value: &str) -> Result<Field, E>
                    where
                        E: de::Error,
                    {
                        match value {
                            "secs" => Ok(Field::Secs),
                            "nanos" => Ok(Field::Nanos),
                            _ => Err(de::Error::unknown_field(value, FIELDS)),
                        }
                    }
                }

                deserializer.deserialize_identifier(FieldVisitor)
            }
        }

        struct DurationVisitor;

        impl<'de> Visitor<'de> for DurationVisitor {
            type Value = Duration;

            fn expecting(&self, formatter: &mut fmt::Formatter) -> fmt::Result {
                formatter.write_str("struct Duration")
            }

            fn visit_seq<V>(self, mut seq: V) -> Result<Duration, V::Error>
            where
                V: SeqAccess<'de>,
            {
                let secs = seq
                    .next_element()?
                    .ok_or_else(|| de::Error::invalid_length(0, &self))?;
                let nanos = seq
                    .next_element()?
                    .ok_or_else(|| de::Error::invalid_length(1, &self))?;
                Ok(Duration { secs, nanos })
            }

            fn visit_map<V>(self, mut map: V) -> Result<Duration, V::Error>
            where
                V: MapAccess<'de>,
            {
                let mut secs = None;
                let mut nanos = None;
                while let Some(key) = map.next_key()? {
                    println!(" Found Key {:?}", key);
                    match key {
                        Field::Secs => {
                            if secs.is_some() {
                                return Err(de::Error::duplicate_field("secs"));
                            }
                            secs = Some(map.next_value()?);
                        }
                        Field::Nanos => {
                            if nanos.is_some() {
                                return Err(de::Error::duplicate_field("nanos"));
                            }
                            nanos = Some(map.next_value()?);
                        }
                    }
                }
                let secs = secs.ok_or_else(|| de::Error::missing_field("secs"))?;
                let nanos = nanos.ok_or_else(|| de::Error::missing_field("nanos"))?;
                Ok(Duration { secs, nanos })
            }
        }

        const FIELDS: &'static [&'static str] = &["secs", "nanos"];
        deserializer.deserialize_struct("Duration", FIELDS, DurationVisitor)
    }
}

fn main() {
    use serde_test::Token;
    let obj = Duration {
        secs: 10,
        nanos: 12,
    };
    serde_test::assert_de_tokens(
        &obj,
        &[
            Token::Struct {
                name: "Duration",
                len: 3,
            },
            Token::Str("secs"),
            Token::U64(10),
            Token::Str("nanos"),
            Token::U64(12),
            // the following fields can be omitted, possibly because of visit_str is a
            // function that would be called on demand, that is, as long as some Token
            // is being met. That leads to a unusual result: incomplete group of
            // matched tokens is acceptable!
            Token::StructEnd,
        ],
    );
}

Output:

$ cargo run
 Found Key Secs
 Found Key Nanos
 Found Key Secs
 Found Key Nanos

Answer 1

Your deserializer is correct, it's just that assert_de_tokens is performing the deserialize twice.

A Deserialize implementation actually includes two methods: deserialize and deserialize_in_place. deserialize_in_place is hidden (incorrectly, in my opinion) but is still considered part of the public API, so assert_de_tokens actually performs two tests: one on deserialize and one on deserialize_in_place.