Giter VIP home page Giter VIP logo

Comments (5)

LeoniePhiline avatar LeoniePhiline commented on May 24, 2024

Update:
As was indicated by the MailHog logs, the error occurs in connect(). I have now mapped the result error to two variants:

smtp_client
    .connect()
    .await
    .map_err(MailError::ConnectSmtp)?
    .send(message)
    .await
    .map_err(MailError::SendMail)

The test thus fails now with:

Error: ConnectSmtp(UnparseableReply)
test mail::tests::mailer_sends_smtp_tls_mail ... FAILED

Edit:

Digging further, in read_ehlo(), EhloResponse::parse() returns an err SyntaxError { syntax: "unexpected token" }

This is weird:

Here's the error's origin (the same on each test failure) in smtp-proto:
image

XXX 4 location (see output below):
image

What I get is:

ch: 0
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply

Why is ch being 0 not covered by the ch @ b'0'..=b'9' match arm in `EhloResponse::parse()?

Is one binary and the other ascii?

image

ch: 0
ch does not match b'0'.
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply
Error: ConnectSmtp(UnparseableReply)

Let's print bits:

image

Good run:

running 1 test
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
test mail::tests::mailer_sends_smtp_tls_mail ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 1 filtered out; finished in 0.07s

Failed run:

running 1 test
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
non-matched ch: 00000000
ch does not match b'0'.
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply
Error: ConnectSmtp(UnparseableReply)
thread 'mail::tests::mailer_sends_smtp_tls_mail' panicked at 'assertion failed: `(left == right)`

Another failed run - different output:

running 1 test
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
non-matched ch: 00000000
ch does not match b'0'.
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply
Error: ConnectSmtp(UnparseableReply)
thread 'mail::tests::mailer_sends_smtp_tls_mail' panicked at 'assertion failed: `(left == right)`

So at minimum, 00110000 (ascii 0, decimal 48) is expected, but 00000000 (binary 0) is received.

Is this a MailHog bug? Or is the iter fed into EhloResponse::parse() not received correctly in read_ehlo()?

Checking iter construction in more detail:
image

(https://github.com/stalwartlabs/mail-send/blob/main/src/smtp/ehlo.rs#L56-L60)

Observation:

Every successful run reads from the initial buf with buf_concat being empty. It looks like this (identical on each successful run):

running 1 test
buf_concat is empty. Reading start of buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
test mail::tests::mailer_sends_smtp_tls_mail ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 1 filtered out; finished in 0.06s

So none of the successful runs extend buf_concat from slice.
On the other hand, every single failed run extends buf_concat from slice:

Example 1: Long output

running 1 test
buf_concat is empty. Reading start of buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
buf_concat is not empty, Extending from buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
non-matched ch: 00000000
ch does not match b'0'.
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply
Error: ConnectSmtp(UnparseableReply)
thread 'mail::tests::mailer_sends_smtp_tls_mail' panicked at 'assertion failed: `(left == right)`

Example 2: Short output

running 1 test
buf_concat is empty. Reading start of buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
buf_concat is not empty, Extending from buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
non-matched ch: 00000000
ch does not match b'0'.
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply
Error: ConnectSmtp(UnparseableReply)
thread 'mail::tests::mailer_sends_smtp_tls_mail' panicked at 'assertion failed: `(left == right)`

Is this some kind of an off by one error, reading into the initial 0u8 which buf is initialized with?
I am thinking of this line:

buf_concat.extend_from_slice(&buf[..br]);

(https://github.com/stalwartlabs/mail-send/blob/main/src/smtp/ehlo.rs#L59)

Alright, this is interesting:

Running code:

            let mut iter = if buf_concat.is_empty() {
                eprintln!("buf_concat is empty. Reading start of buf.");
                buf[..br].iter()
            } else if br + buf_concat.len() < MAX_REPONSE_LENGTH {
                eprintln!("buf_concat is not empty, Extending from buf.");
                eprintln!("extending from slice: {:?}", &buf[..br]);
                buf_concat.extend_from_slice(&buf[..br]);
                eprintln!("extended: {:?}", buf_concat);
                buf_concat.iter()

Shows buf_concat's many b0, as it is extended at the end:


running 1 test
buf_concat is empty. Reading start of buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
buf_concat is not empty, Extending from buf.
extending from slice: [50, 53, 48, 45, 80, 73, 80, 69, 76, 73, 78, 73, 78, 71, 13, 10, 50, 53, 48, 32, 65, 85, 84, 72, 32, 80, 76, 65, 73, 78, 13, 10]
extended: [50, 53, 48, 45, 72, 101, 108, 108, 111, 32, 56, 56, 55, 100, 48, 52, 53, 57, 100, 51, 98, 97, 13, 10, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 50, 53, 48, 45, 80, 73, 80, 69, 76, 73, 78, 73, 78, 71, 13, 10, 50, 53, 48, 32, 65, 85, 84, 72, 32, 80, 76, 65, 73, 78, 13, 10]
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
non-matched ch: 00000000
ch does not match b'0'.
XXX 4
SyntaxError { syntax: "unexpected token" }
Unparseable SMTP reply
Error: ConnectSmtp(UnparseableReply)
thread 'mail::tests::mailer_sends_smtp_tls_mail' panicked at 'assertion failed: `(left == right)`

I guess the bug is the initialization let mut buf = vec![0u8; 1024]; instad of Vec::with_capacity(1024)? No, not exactly. But close.

This is the problem - here the full buf (all almost 1024 b0s) are dumped into buf_concat:

                        if buf_concat.is_empty() {
                            buf_concat = buf.to_vec();
                        }

(https://github.com/stalwartlabs/mail-send/blob/main/src/smtp/ehlo.rs#L69-L71)

Confirmed:

image

Extending from slice no longer dumps the entire buf into the buf_concat vector:

running 1 test
Bytes read: 24
buf_concat is empty. Reading start of buf.
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
Dump into vec 1
Bytes read: 32
buf_concat is not empty, Extending from buf.
extending from slice: [50, 53, 48, 45, 80, 73, 80, 69, 76, 73, 78, 73, 78, 71, 13, 10, 50, 53, 48, 32, 65, 85, 84, 72, 32, 80, 76, 65, 73, 78, 13, 10]
extended: [50, 53, 48, 45, 72, 101, 108, 108, 111, 32, 56, 56, 55, 100, 48, 52, 53, 57, 100, 51, 98, 97, 13, 10, 50, 53, 48, 45, 80, 73, 80, 69, 76, 73, 78, 73, 78, 71, 13, 10, 50, 53, 48, 32, 65, 85, 84, 72, 32, 80, 76, 65, 73, 78, 13, 10]
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
matched ch: 00110010
matched ch: 00110101
matched ch: 00110000
test mail::tests::mailer_sends_smtp_tls_mail ... ok

from mail-send.

mdecimus avatar mdecimus commented on May 24, 2024

Just out of curiosity, could you share the EHLO response that triggered this bug?

from mail-send.

LeoniePhiline avatar LeoniePhiline commented on May 24, 2024

As far as I can see, the responses are normal; maybe it's about timing?
When does let br = self.stream.read(&mut buf).await?; decide to stop reading and yield with some br?

You can see the bytes received as binary above. The bytes themselves don't appear to be special - only the fact that they are being read in two steps caused the bug to surface.

from mail-send.

mdecimus avatar mdecimus commented on May 24, 2024

When does let br = self.stream.read(&mut buf).await?; decide to stop reading and yield with some br?

The OS decides when to stop writing the incoming bytes into the buffer. This usually occurs when the entire packet is received or when the buffer gets full. What probably happened here is that for some reason the EHLO response was sent in two separate frames and triggered this bug.

from mail-send.

LeoniePhiline avatar LeoniePhiline commented on May 24, 2024

Yes, this perfectly matches my observations.

from mail-send.

Related Issues (16)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.