thomasarmel / socket-server-mocker

Mock socket server in Rust, for testing various network clients.
https://crates.io/crates/socket-server-mocker
MIT License
0 stars 2 forks source link

Randomly getting 'An existing connection was forcibly closed by the remote host' error #6

Open jmevel opened 1 year ago

jmevel commented 1 year ago

I implemented a code very similar to the SMTP Mock example. Some times my test is passing but most of the times I get

thread 'email_client::tests::test_smtp_mock' panicked at 'Could not send email: lettre::transport::smtp::Error { kind: Network, source: Os { code: 10054, kind: ConnectionReset, message: "An existing connection was forcibly closed by the remote host." } }'

In my CI, on Ubuntu, same issue but with a different message

thread 'email_client::tests::test_smtp_mock' panicked at 'Could not send email: lettre::transport::smtp::Error { kind: Network, source: Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" } }'

Have you ever encountered this problem? The thing is from time to time it actually works...

Thank you

thomasarmel commented 1 year ago

Hi, Yes actually I met some issues with SMTP that I was not able to reproduce all the time. But as I remember it was not an issue of connection closing, but the wrong message was sent. The unique solution I found was to trigger pipeline again. I you find out the reason I would be interested :)

jmevel commented 1 year ago

I deleted my previous comment because I just realized the panic was coming from my code... However there's still an issue with the mock server.

I added some logs. First are the logs from the email before sending it and then what the mock server received using the pop_received_message function.

Success:

running 1 test From: adalberto_itaque milford@example.net Reply-To: velma_at opal@example.com To: bernie_eveniet eliseo@example.org Subject: temporibus. Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit Date: Sat, 01 Apr 2023 09:01:50 +0000

est quaerat consequuntur error aut. Email sent successfully!

Messages received by server: EHLO DESKTOP-2Q06VQ1

MAIL FROM:milford@example.net

RCPT TO:eliseo@example.org

DATA

From: adalberto_itaque milford@example.net Reply-To: velma_at opal@example.com To: bernie_eveniet eliseo@example.org Subject: temporibus. Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit Date: Sat, 01 Apr 2023 09:01:50 +0000

est quaerat consequuntur error aut. test email_client::tests::test_smtp_mock ... ok

Failure:

running 1 test From: retta_eum charles@example.com Reply-To: stephania_enim maurice@example.net To: martin_molestiae elise@example.com Subject: cupiditate. Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit Date: Sat, 01 Apr 2023 09:03:15 +0000

saepe quam libero iste numquam cum necessitatibus animi enim. Could not send email: lettre::transport::smtp::Error { kind: Network, source: Os { code: 10054, kind: ConnectionReset, message: "An existing connection was forcibly closed by the remote host." } }

Messages received by server: EHLO DESKTOP-2Q06VQ1

failures:

failures: email_client::tests::test_smtp_mock

As you can see, the server closed the connection after the very first message EHLO [name of my computer]

thomasarmel commented 1 year ago

Ok quite strange. Can I see your code please?

jmevel commented 1 year ago

Yes sure, I'm not sure I'll have more free time this weekend but Monday I'll try to share you a minimal code to reproduce the problem.

jmevel commented 1 year ago

Hi @thomasarmel !

Here is a repository you can clone it and test it with the test_smtp_mock test function in the email_client.rs file.

So far I could never get this sample code to work. Always getting error 10054 on Windows and 104 on Linux.

I honestly don't know what am I doing wrong. Thanks for having a look at it!

EDIT: I refactored a bit the code and added a binary to the project to be able to manually test sending a real email. Checkout the Initial commit if you want a simpler code without the binary

thomasarmel commented 1 year ago

Just to verify: what happen in case you set 0 as SMTP port (let the OS choose a free port)? And then specify the choosen port in your client config. You can use _ServerMocker::listeningport() method.

Maybe the problem comes from the fact that you have port 2525 opened twice?

I'll have a further look on it

jmevel commented 1 year ago

Hello Thomas,

Yeah I've tried port 0 already but I get the following error

lettre::transport::smtp::Error { kind: Connection, source: Os { code: 10049, kind: AddrNotAvailable, message: "The requested address is not valid in its context." } }

I just launched the project again today, it seemed to work around 10 times and then it stopped working suddenly even though I'm using a new port every time (2526 then 2527 and so on...). I checked open ports on Windows with the command netstat -aon but the ports I'm using don't seem to be open anymore.

The whole thing is really weird

EDIT: I just tried with a new port (2121). It failed the first 3 times and then suddenly worked the 4th time... 🤨

thomasarmel commented 1 year ago

Hmmm port 0 works very well on my side. Could you double check your program doesn't listen on the same port some times ?

jmevel commented 1 year ago

Hi @thomasarmel, I finally had time to go back to this issue and I found the root cause however I really can't explain it, it seems very weird to me !

In your SMTP Mock example try inverting the initialization of email_builder and mailer.

So instead of

// Create a client based on a SmtpTransport
let email_builder = Message::builder()
    .from(
        "Alice Dupont <alice.dupont@localhost.mock>"
            .parse()
            .unwrap(),
    )
    .reply_to(
        "Alice Dupont <alice.dupont@localhost.mock>"
            .parse()
            .unwrap(),
    )
    .to("Bob Dupond <bob.dupond@localhost.mock>".parse().unwrap())
    .subject("Happy new year")
    .body(String::from("Be happy!"))
    .unwrap();

// Mail client opens a remote connection on mocked SMTP server
let mailer = SmtpTransport::relay("127.0.0.1")
    .unwrap()
    .tls(Tls::None)
    .port(2525)
    .timeout(Some(std::time::Duration::from_secs(1)))
    .build();
// Send the email
mailer.send(&email_builder).unwrap();

You have

// Mail client opens a remote connection on mocked SMTP server
let mailer = SmtpTransport::relay("127.0.0.1")
    .unwrap()
    .tls(Tls::None)
    .port(2525)
    .timeout(Some(std::time::Duration::from_secs(1)))
    .build();

// Create a client based on a SmtpTransport
let email_builder = Message::builder()
    .from(
        "Alice Dupont <alice.dupont@localhost.mock>"
            .parse()
            .unwrap(),
    )
    .reply_to(
        "Alice Dupont <alice.dupont@localhost.mock>"
            .parse()
            .unwrap(),
    )
    .to("Bob Dupond <bob.dupond@localhost.mock>".parse().unwrap())
    .subject("Happy new year")
    .body(String::from("Be happy!"))
    .unwrap();

// Send the email
mailer.send(&email_builder).unwrap();

And now you get the same issue as me !

thread 'test_smtp_mock' panicked at 'called Result::unwrap() on an Err value: lettre::transport::smtp::Error { kind: Network, source: Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" } }

And since last time I even completely migrated to Linux so this is not a Windows-only issue.

How could you explain this weird behavior? In my opinion it should not matter at all in which order we are instantiating our variables, it should work in both ways.

thomasarmel commented 1 year ago

I tried on my side and the test passed. However I tried to run the test again a couple of times and it actually happened that the test failed sometimes.

However it is not related to the variable instantation order, as I observed the same behavior in both cases.

It's weird!

Thanks for telling me it's not only a Windows issue. I'll investigate further but it's probably related to lettrecrate.

jmevel commented 1 year ago

You're right, I thought it was failing 100% of the times but it's actually working once in a while on my side.

Thanks for taking the time to investigate this issue. I hope I will be able to use your crate at some point and improve my code coverage 😉

thomasarmel commented 1 year ago

I activated tracing on lettre crate, and got the following output:

running 1 test
2023-08-10T18:58:22.414643Z DEBUG lettre::transport::smtp::pool::sync_impl: creating a new connection
2023-08-10T18:58:22.414822Z TRACE lettre::transport::smtp::pool::sync_impl: running cleanup tasks
2023-08-10T18:58:22.429698Z DEBUG lettre::transport::smtp::client::connection: << 220 smtp.localhost.mock ESMTP Mocker<CRLF>
2023-08-10T18:58:22.429831Z DEBUG lettre::transport::smtp::client::connection: Wrote: EHLO DESKTOP-4DF2HCG<CRLF>
2023-08-10T18:58:22.460013Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>
2023-08-10T18:58:22.460076Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>250-PIPELINING<CRLF>
2023-08-10T18:58:22.460098Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>250-PIPELINING<CRLF>250-SIZE 20971520<CRLF>
2023-08-10T18:58:22.460120Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>250-PIPELINING<CRLF>250-SIZE 20971520<CRLF>250-ETRN<CRLF>
2023-08-10T18:58:22.460145Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>250-PIPELINING<CRLF>250-SIZE 20971520<CRLF>250-ETRN<CRLF>250-STARTTLS<CRLF>
2023-08-10T18:58:22.460177Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>250-PIPELINING<CRLF>250-SIZE 20971520<CRLF>250-ETRN<CRLF>250-STARTTLS<CRLF>250-ENHANCEDSTATUSCODES<CRLF>
2023-08-10T18:58:22.460208Z DEBUG lettre::transport::smtp::client::connection: << 250-smtp.localhost.mock<CRLF>250-PIPELINING<CRLF>250-SIZE 20971520<CRLF>250-ETRN<CRLF>250-STARTTLS<CRLF>250-ENHANCEDSTATUSCODES<CRLF>250 8BITMIME<CRLF>
2023-08-10T18:58:22.460310Z DEBUG lettre::transport::smtp::client::connection: server smtp.localhost.mock with {StartTls, EightBitMime}
2023-08-10T18:58:22.460337Z DEBUG lettre::transport::smtp::pool::sync_impl: created 1 idle connections
thread 'test_smtp_mock' panicked at 'called `Result::unwrap()` on an `Err` value: lettre::transport::smtp::Error { kind: Network, source: Os { code: 10060, kind: TimedOut, message:

So it looks like lettre creates a couple of background connections, which my mocker doesn't support...

thomasarmel commented 1 week ago

@jmevel it looks like now the problem occurs less often, could you please check?

jmevel commented 1 week ago

@jmevel it looks like now the problem occurs less often, could you please check?

Hi thomas, thanks for the new 0.0.5 version and the follow up on this issue.

I upgraded lettre & socket-server-mocker on my sample SMTP project however I still get the same issue as before every single time I execute my test.

lettre::transport::smtp::Error { kind: Network, source: Os { code: 10054, kind: ConnectionReset, message: "Une connexion existante a dû être fermée par l’hôte distant." } }

I'm on my work computer on Windows right now. Havent had time to test on Linux yet.

thomasarmel commented 1 week ago

Hum... ok thanks!