Bytes left into the decode buffer

I am currently failing #PV1 because of 4 trailing bytes being present in the decode buffer. I cannot reproduce that locally, I double check the size of the bytes, dump the hex, I even checked with strace to see if I was missing anything. Any chance the test runner is doing something weird?

My current codebase:

As you can see from the debug logs I added what is being sent does not include those trailing bytes. And everything I sent seems to be decoded correctly?:

remote: [your_program] accepted new connection
remote: [your_program] [src/apiversions.rs:96:9] bytes.len() = 23
remote: [your_program] 00 00 00 17
remote: [your_program] 1a 7d 43 2c
remote: [your_program] 00 00 02 00
remote: [your_program] 12 00 00 00
remote: [your_program] 04 00 00 00
remote: [your_program] 00 00 00
remote: [tester::#PV1] Hexdump of received "ApiVersions" response: 
remote: [tester::#PV1] Idx  | Hex                                             | ASCII
remote: [tester::#PV1] -----+-------------------------------------------------+-----------------
remote: [tester::#PV1] 0000 | 00 00 00 17 1a 7d 43 2c 00 00 02 00 12 00 00 00 | .....}C,........
remote: [tester::#PV1] 0010 | 04 00 00 00 00 00 00 00 00 00 00                | ...........
remote: [tester::#PV1] 
remote: [tester::#PV1] [Decoder] - .ResponseHeader
remote: [tester::#PV1] [Decoder]   - .correlation_id (444416812)
remote: [tester::#PV1] [Decoder] - .ResponseBody
remote: [tester::#PV1] [Decoder]   - .error_code (0)
remote: [tester::#PV1] [Decoder]   - .num_api_keys (1)
remote: [tester::#PV1] [Decoder]   - .ApiKeys[0]
remote: [tester::#PV1] [Decoder]     - .api_key (18)
remote: [tester::#PV1] [Decoder]     - .min_version (0)
remote: [tester::#PV1] [Decoder]     - .max_version (4)
remote: [tester::#PV1] [Decoder]     - .TAG_BUFFER
remote: [tester::#PV1] [Decoder]   - .throttle_time_ms (0)
remote: [tester::#PV1] [Decoder]   - .TAG_BUFFER
remote: [tester::#PV1] Received:
remote: [tester::#PV1] Hex (bytes 14-22)                               | ASCII
remote: [tester::#PV1] ------------------------------------------------+------------------
remote: [tester::#PV1] 00 00 00 00 00 00 00 00 00                      | .........
remote: [tester::#PV1]                 ^                                      ^
remote: [tester::#PV1] Error: unexpected 4 bytes remaining in decoder after decoding ApiVersionsResponse
remote: [tester::#PV1] Context:
remote: [tester::#PV1] - ApiVersions v3
remote: [tester::#PV1]   - Response Body
remote: [tester::#PV1] 
remote: [tester::#PV1] Test failed
remote: [tester::#PV1] Terminating program
remote: [tester::#PV1] Program terminated successfully

No rogue bytes locally:

kov@jabuticaba ~> echo -n "00000023001200040183eb7d00096b61666b612d636c69000a6b61666b612d636c6904302e3100" | xxd -r -p | nc localhost 9092 | hexdump -C
00000000  00 00 00 17 01 83 eb 7d  00 00 02 00 12 00 00 00  |.......}........|
00000010  04 00 00 00 00 00 00                              |.......|
00000017
kov@jabuticaba ~> 

Hey @kov, could you upload your code to GitHub and share the link? It will be much easier to debug if I can run it directly.

Hey! I shared it above, here’s the link:

Thanks for looking into it!

@kov Looks like the specified message length does not match the actual length:

Specified length: 0x17 (one row plus seven bytes).

Actual length: The second row is four bytes more than seven bytes.


UPDATE: As @EshaanAgg correctly pointed out, the specified message length excludes the length field itself:

So our tester will try to read one row plus seven bytes as the body.

@andy1li that is exactly the problem I am hitting, yes! But I cannot reproduce those 4 additional bytes locally, can you? Any chance the tester may be misbehaving? If you look at my debugging messages that appear on the tester execution, the 4 bytes also do not show up there:

remote: [your_program] [src/apiversions.rs:96:9] bytes.len() = 23
remote: [your_program] 00 00 00 17
remote: [your_program] 1a 7d 43 2c
remote: [your_program] 00 00 02 00
remote: [your_program] 12 00 00 00
remote: [your_program] 04 00 00 00
remote: [your_program] 00 00 00
remote: [tester::#PV1] Hexdump of received "ApiVersions" response:

Here’s the code that produces the debug output:

fn hex_dbg(bytes: &[u8]) {
    println!(
        "{}",
        bytes
            .iter()
            .map(|b| format!("{:0>2x}", b))
            .collect::<Vec<String>>()
            .chunks(4)
            .map(|chunk| chunk.join(" "))
            .collect::<Vec<String>>()
            .join("\n")
    )
}
...
        let mut response = ApiVersionsResponse::for_request(&request);

        let bytes = response.encode();
        hex_dbg(&bytes);

        stream.write_all(bytes)?;

The size calculation is incorrect in your implementation.

The bytes sent by your implementation are:

remote: [your_program] 00 00 00 17
remote: [your_program] 1a 7d 43 2c
remote: [your_program] 00 00 02 00
remote: [your_program] 12 00 00 00
remote: [your_program] 04 00 00 00
remote: [your_program] 00 00 00

The first four bytes are: 00 00 00 17, which corresponds to 23 in hexadecimal. Thus, the tester expects 23 ADDITIONAL bytes to be sent after them, and not 23 - 4 = 19 bytes that your implementation is doing.

You need to exclude the 4 bytes of message length bytes from the message length. The simplest way of doing same would be:

impl ResponseHeader {
    pub fn new() -> Self {
        let mut message = ResponseHeader::default();
        // message.set_message_size(size_of::<ResponseHeader>());
        message.set_message_size(size_of::<ResponseHeader>() - size_of::<i32>()); // Exclude the message size itself;
        message
    }

The error message you see extra bytes is due to the tester allocating the buffer size of 23, then reading only 19 bytes and using 4 bytes (which were 0 by default) during the decoding process.

Unrelated: @andy1li Can we update the tester to actually read exactly the bytes that have been sent by the client, and throw an error if the same doesn’t happen? It would help to prevent flagging of error at the wrong place (decoding instead of message length).

1 Like

@EshaanAgg Thanks for the answer and the suggestion!

Can we update the tester to actually read exactly the bytes that have been sent by the client

It’s a great idea! I’m just not sure if it’s possible. :thinking:

A client (our tester in this case) cannot know for sure how many bytes a server will send back unless a protocol explicitly defines it.

Here’s a quote from Socket Programming HOWTO:

A fundamental truth of sockets: messages must either be fixed length (yuck), or be delimited (shrug), or indicate how long they are (much better), or end by shutting down the connection .

Hmm makes sense. I was under the impression but using methods like conn.ReadFull should take care of the “exact reading” problem I was referring to, but turns out even they can’t guarantee 100% correctness, cause it’s the limitation of the socket spec itself! TIL.

Thanks for your reply :slight_smile:

1 Like

Oohhh ok, that makes sense. I counted those bytes by hand several times :stuck_out_tongue_winking_eye: @andy1li if I could make a suggestion, it would be great if message size was validated on a previous step, as there is already too much going on in this step and it’s not obvious at first (or at least it wasn’t for me) that the message size is not included in its calculation. Thank you both!

2 Likes

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.