qbittorrent / qBittorrent

qBittorrent BitTorrent client
https://www.qbittorrent.org
Other
28.28k stars 3.98k forks source link

SMTP: EHLO success is ignored and HELO is sent. #1845

Closed Taomyn closed 10 years ago

Taomyn commented 10 years ago

It seems when qb sends an email it's not following protocols for the HELO command and so fails with my mailserver (MDaemon):

Sat 2014-07-26 12:58:47: 05: [514116] Session 514116; child 0001 Sat 2014-07-26 12:58:47: 05: [514116] Accepting SMTP connection from [192.168.1.20:63750] to [192.168.1.10:25] Sat 2014-07-26 12:58:47: 03: [514116] --> 220-mydomain.com ESMTP Sat, 26 Jul 2014 12:58:47 +0200 Sat 2014-07-26 12:58:47: 03: [514116] --> 220- Sat 2014-07-26 12:58:47: 03: [514116] --> 220-* This site does not authorise the use of its proprietary computers Sat 2014-07-26 12:58:47: 03: [514116] --> 220-* and computer network to accept, transmit or distribute unsolicited Sat 2014-07-26 12:58:47: 03: [514116] --> 220-* bulk email, phishing or malware from the Internet. Sat 2014-07-26 12:58:47: 03: [514116] --> 220- Sat 2014-07-26 12:58:47: 03: [514116] --> 220-* Failure to abide by the above statement will result in your server Sat 2014-07-26 12:58:47: 03: [514116] --> 220-* being permanently banned from connecting in the future. Sat 2014-07-26 12:58:47: 03: [514116] --> 220- Sat 2014-07-26 12:58:47: 03: [514116] --> 220-* Please report any other problems to postmaster@mydomain.com Sat 2014-07-26 12:58:47: 03: [514116] --> 220 Sat 2014-07-26 12:58:47: 02: [514116] <-- ehlo FE80::XXX Sat 2014-07-26 12:58:47: 03: [514116] --> 250-mydomain.com Hello FE80::XXX, pleased to meet you Sat 2014-07-26 12:58:47: 03: [514116] --> 250-ETRN Sat 2014-07-26 12:58:47: 03: [514116] --> 250-AUTH CRAM-MD5 Sat 2014-07-26 12:58:47: 03: [514116] --> 250-8BITMIME Sat 2014-07-26 12:58:47: 03: [514116] --> 250-STARTTLS Sat 2014-07-26 12:58:47: 03: [514116] --> 250 SIZE Sat 2014-07-26 12:58:47: 02: [514116] <-- helo Sat 2014-07-26 12:58:47: 03: [514116] --> 550 Invalid or missing command argument(s) Sat 2014-07-26 12:58:47: 04: [514116] * Winsock Error 10054 Sat 2014-07-26 12:58:47: 04: [514116] SMTP session terminated (Bytes in/out: 41/685) Sat 2014-07-26 12:58:47: 01: ----------

I'm pretty sure RFCs state that the EHLO/HELO must be followed by an FQDN or IP.

It also would not go amiss to be able to specify the "from" address that qb uses to prevent other issues, especially relay checks.

chrishirst commented 10 years ago

The error message is actually because your mail server requires authentication and the SMTP client trying to connect is not providing a user name and password.

Taomyn commented 10 years ago

No, my server only requires authentication from external connections and non-authorised internal machines, or if the from address is not a local domain. I have plenty of other services performing email notifications on the same machine and none of them authenticate.

The list of 250 commands are just informing the client of the capabilities of the server, not the requirements.

sledgehammer999 commented 10 years ago

FYI, this is low prio for me. Unless someone else comes up with a fix. As you can see the bugtracker is full of issues and I have made a decision to stay focused on the core program and it's core functions for a bt client. Thanks for the report though.

sledgehammer999 commented 10 years ago

Fixed with #1895.

sledgehammer999 commented 10 years ago

@Taomyn do you use Windows, so I can provide you a test build containing the fix? If you use linux, I am pretty sure that you know how to compile it yourself :D

Taomyn commented 10 years ago

@sledgehammer999 I'm using Windows Server 2012 R2, but happy to test a build for you, just point me to it

sledgehammer999 commented 10 years ago

New alpha build: http://qbforums.shiki.hu/index.php/topic,2344.msg12428.html#msg12428

Taomyn commented 10 years ago

Sorry, still doesn't work:

30/08/2014 18:55:46 - Email Notification Error: Both EHLO and HELO failed, msg: * This site does not authorise the use of its proprietary computers

On my mail server:

Sat 2014-08-30 18:55:46.268: 05: [554101] Session 554101; child 0001 Sat 2014-08-30 18:55:46.268: 05: [554101] Accepting SMTP connection from [192.168.1.20:60266] to [192.168.1.10:25] Sat 2014-08-30 18:55:46.270: 03: [554101] --> 220-domain.com ESMTP Sat, 30 Aug 2014 18:55:46 +0200 Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* This site does not authorise the use of its proprietary computers Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* and computer network to accept, transmit or distribute unsolicited Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* bulk email, phishing or malware from the Internet. Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* Failure to abide by the above statement will result in your server Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* being permanently banned from connecting in the future. Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* Please report any other problems to postmaster@domain.com Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220 Sat 2014-08-30 18:55:46.300: 02: [554101] <-- ehlo FE80::B03C:151F:DD73:9C26%14 Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-domain.com Hello FE80::B03C:151F:DD73:9C26%14, pleased to meet you Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-ETRN Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-AUTH CRAM-MD5 Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-8BITMIME Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-ENHANCEDSTATUSCODES Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-STARTTLS Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250 SIZE Sat 2014-08-30 18:55:46.313: 02: [554101] <-- helo FE80::B03C:151F:DD73:9C26%14 Sat 2014-08-30 18:55:46.313: 03: [554101] --> 250 domain.com Hello FE80::B03C:151F:DD73:9C26%14, pleased to meet you Sat 2014-08-30 18:55:46.343: 04: [554101] * Winsock Error 10054 Sat 2014-08-30 18:55:46.343: 04: [554101] SMTP session terminated (Bytes in/out: 70/742) Sat 2014-08-30 18:55:46.343: 01: ----------

Would also be nice if we could specify the HELO/EHLO name, not sure why it's chosen the IP6 address - which I'm not using.

sledgehammer999 commented 10 years ago

Would also be nice if we could specify the HELO/EHLO name, not sure why it's chosen the IP6 address - which I'm not using.

Can see what addresses your network interface reports? My hunch is that reports both ipv4 and ipv6 addresses but qbt chooses ipv6 since it is first in the list. If you have both ipv6 and ipv4 can you try disabling ipv6 in your OS and see if that helps?

sledgehammer999 commented 10 years ago

At least now it seems to respond to the HELo command. But it doesn't say why it closes the connection.

sledgehammer999 commented 10 years ago

Also if the EHLO is understood by the server the client shouldn't send a HELO. Am I wrong? (I don't know much about smtp). Also tagging @YuriIvanov here.

Taomyn commented 10 years ago

I disabled IP6, same name used after I restarted.

You are correct, you only send HELO if EHLO is not understood by the server: http://cr.yp.to/smtp/ehlo.html

I'm also seeing this error about a random port when QB starts:

30/08/2014 19:10:51 - Peer ID: -qB3200- 30/08/2014 19:10:51 - The Web UI is listening on port 12237 30/08/2014 19:10:51 - qBittorrent is successfully listening on interface 192.168.1.20 port: TCP/12236 30/08/2014 19:10:51 - qBittorrent failed listening on interface 0.0.0.0 port: TCP/60590. Reason: Only one usage of each socket address (protocol/network address/port) is normally permitted 30/08/2014 19:10:51 - Options were saved successfully. 30/08/2014 19:10:51 - Embedded Tracker [OFF] 30/08/2014 19:10:51 - Encryption support [FORCED] 30/08/2014 19:10:51 - Local Peer Discovery support [OFF] 30/08/2014 19:10:51 - PeX support [ON] 30/08/2014 19:10:51 - Anonymous mode [OFF] 30/08/2014 19:10:51 - HTTP user agent is qBittorrent v3.2.0alpha 30/08/2014 19:10:51 - UPnP / NAT-PMP support [OFF] 30/08/2014 19:10:51 - qBittorrent is trying to listen on interface 192.168.1.20 port: 12236

I usually specify the ports, no random ones, so I can't tell where this is coming from.

sledgehammer999 commented 10 years ago

Looking through the code it seems that the problem is that qbt doesn't parse correctly "250". Because it does indeed check if the EHLO was successful before sending HELO by checking if there was a 250. However, as I said this is low prio for me. If @YuriIvanov can find the bug in the smtp code that would be great. I am reopening this and changing the title.

As for the port number: please go again at the same forum thread and look for my previous build posted in the same thread and try again. That build uses libtorrent 1.0.x. Also if possible let's discuss that on the forum instead of here.

YuriIvanov commented 10 years ago

sledgehammer999 "At least now it seems to respond to the HELo command. But it doesn't say why it closes the connection."

It is qB closes connection.

WSAECONNRESET 10054 Connection reset by peer. An existing connection was forcibly closed by the remote host. This normally results if the peer application on the remote host is suddenly stopped, the host is rebooted, the host or remote network interface is disabled, or the remote host uses a hard close (see setsockopt for more information on the SO_LINGER option on the remote socket). This error may also result if a connection was broken due to keep-alive activity detecting a failure while one or more operations are in progress. Operations that were in progress fail with WSAENETRESET. Subsequent operations fail with WSAECONNRESET.

sledgehammer999 commented 10 years ago

It is qB closes connection.

Then that means that qbt doesn't recognize the return code to the HELO either. wtf is happening here?

YuriIvanov commented 10 years ago

Problem with the parsing of the responses in my opinion. And we do not need to use HELO if we get the answer to EHLO.

sledgehammer999 commented 10 years ago

Are you willing to look into this or do you have other things to do?

YuriIvanov commented 10 years ago

Already working on it. And i do not see any parsing errors. I would like to know whether qB has a logging system? It would be very useful to look at the actual data returned by the server.

sledgehammer999 commented 10 years ago

You can sprinkle the code with qDebug(), qCritical() or just plain std::cout, while running from terminal.

eg on smtp.cpp after line 163 you could put qCritical() << buffer.constData();.

YuriIvanov commented 10 years ago

I have one guess about this bug.

First, we establish a connection Sat 2014-08-30 18:55:46.268: 05: [554101] Accepting SMTP connection from [192.168.1.20:60266] to [192.168.1.10:25]

But server response contains not only standard response with result of establishing connection and information about itself: ------standard------- Sat 2014-07-26 12:58:47: 03: [514116] --> 220-mydomain.com ESMTP Sat, 26 Jul 2014 12:58:47 +0200

------additional------- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* This site does not authorise the use of its proprietary computers Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* and computer network to accept, transmit or distribute unsolicited Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* bulk email, phishing or malware from the Internet. Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* Failure to abide by the above statement will result in your server Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* being permanently banned from connecting in the future. Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-* Please report any other problems to postmaster@domain.com Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220

After that, qB read the response and parse its first line: ------standard------- Sat 2014-07-26 12:58:47: 03: [514116] --> 220-mydomain.com ESMTP Sat, 26 Jul 2014 12:58:47 +0200

This response indicates that we have successfully established a connection to the SMTP-server. Then qB send EHLO command and waiting for response. Sat 2014-07-26 12:58:47: 02: [514116] <-- ehlo FE80::XXX

And that's our bug. qB state machine expects that buffer contains

Sat 2014-08-30 18:55:46.300: 03: [554101] --> 250-domain.com Hello FE80::B03C:151F:DD73:9C26%14, pleased to meet you

at this moment. But we have not yet dealt with the additional data from the first response. So parsing continuing from wrong position: ------additional------- Sat 2014-08-30 18:55:46.271: 03: [554101] --> 220-*

YuriIvanov commented 10 years ago

http://en.citizendium.org/wiki/SMTP_example_sessions

YuriIvanov commented 10 years ago

I do not know why MDaemon sends these additional responses. I have not found anything like this in the standard.

YuriIvanov commented 10 years ago

http://tools.ietf.org/html/rfc5321

sledgehammer999 commented 10 years ago

Hmm, that makes sense actually. And IIRC if a status code is followed by "-" (hyphen) then it indicates that more responses are following. A status code followed by a space indicates the end of responses.

sledgehammer999 commented 10 years ago

I am currently building a hack for @Taomyn to test. I changed line 176 to if (code[0] == '2' && line[3] != ' ') { But IMO something better should be the real solution. We should test for space/hyphen on every possible server response maybe.

YuriIvanov commented 10 years ago

qB EHLO command support multi-line response

YuriIvanov commented 10 years ago

parseEhloResponse(code, line[3] != ' ', line.mid(4));

sledgehammer999 commented 10 years ago

Yes. But it doesn't support multiline in the init state as you found out. That's why I made that hack for @Taomyn to test.

YuriIvanov commented 10 years ago

if (code[0] == '2' && line[3] != ' ') Maby if (code[0] == '2' && line[3] == ' ') ?

YuriIvanov commented 10 years ago

We must send EHLO command only if first response is not multi-line (because we does not support multi-line INIT response yet).

sledgehammer999 commented 10 years ago

Oops you are correct. (thankfully my machine is too slow to compile so I didn't post a wrong binary yet.)

sledgehammer999 commented 10 years ago

We must send EHLO command only if first response is not multi-line (because we does not support multi-line INIT response yet).

But the proposed fix isn't enough in your opinion? What more parsing should we do?

YuriIvanov commented 10 years ago

As temporary workaround @Taomyn can disable "additional information". I think MDaemon has such option.

YuriIvanov commented 10 years ago

But the proposed fix isn't enough in your opinion? What more parsing should we do?

If first response (establishing connection) is multi-line we should skip additional lines. We need something like parseInitResponse function. That's our solution.

sledgehammer999 commented 10 years ago

If first response (establishing connection) is multi-line we should skip additional lines. We need something like parseInitResponse function. That's our solution.

I think that's what my hack does now. Am I wrong?

YuriIvanov commented 10 years ago

Your hack is just close connection if we receive multi-line Init response.

sledgehammer999 commented 10 years ago

Your hack is just close connection if we receive multi-line Init response.

I forgot that we are in a switch statement. Yeah now the new diff is:

diff --git a/src/smtp.cpp b/src/smtp.cpp
index 0443897..67f7e78 100644
--- a/src/smtp.cpp
+++ b/src/smtp.cpp
@@ -174,6 +174,8 @@ void Smtp::readyRead()
     switch(state) {
     case Init: {
       if (code[0] == '2') {
+        if (line[3] != ' ')
+          break;
         // Connection was successful
         ehlo();
       } else {

Is this enough in your opinion?

sledgehammer999 commented 10 years ago

@Taomyn can you test this new build: http://builds.shiki.hu/temp/qbittorrent_3.2.0alpha_20140831_f22f7cf_smpt_fix_setup.7z

YuriIvanov commented 10 years ago

Is this enough in your opinion?

Yes, i think.

YuriIvanov commented 10 years ago

And if it works add a comment in the code explaining all this magic.

Taomyn commented 10 years ago

Tried it and still not working. Nothing logged in qb that I could see but on my mail server:

Sun 2014-08-31 13:08:39.777: 05: [554935] Session 554935; child 0001 Sun 2014-08-31 13:08:39.777: 05: [554935] Accepting SMTP connection from [192.168.1.20:52312] to [192.168.1.10:25] Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-domain.com ESMTP Sun, 31 Aug 2014 13:08:39 +0200 Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220- Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-* This site does not authorise the use of its proprietary computers Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-* and computer network to accept, transmit or distribute unsolicited Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-* bulk email, phishing or malware from the Internet. Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220- Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-* Failure to abide by the above statement will result in your server Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-* being permanently banned from connecting in the future. Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220- Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220-* Please report any other problems to postmaster@domain.com Sun 2014-08-31 13:08:39.779: 03: [554935] --> 220 Sun 2014-08-31 13:08:39.808: 02: [554935] <-- ehlo FE80::B03C:151F:DD73:9C26%14 Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250-domain.com Hello FE80::B03C:151F:DD73:9C26%14, pleased to meet you Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250-ETRN Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250-AUTH CRAM-MD5 Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250-8BITMIME Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250-ENHANCEDSTATUSCODES Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250-STARTTLS Sun 2014-08-31 13:08:39.808: 03: [554935] --> 250 SIZE Sun 2014-08-31 13:10:39.085: 04: [554935] Connection timed out! Sun 2014-08-31 13:10:39.086: 04: [554935] SMTP session terminated (Bytes in/out: 35/666) Sun 2014-08-31 13:10:39.086: 01: ----------

YuriIvanov commented 10 years ago

At least now we correctly parse an initial response.

YuriIvanov commented 10 years ago

Sun 2014-08-31 13:10:39.085: 04: [554935] Connection timed out! Something with MDaemon settings.

Taomyn commented 10 years ago

Yes, it waited 2 minutes, but it can't wait forever for qb to respond, so it's qb that has the problem not MD.

FYI, my PRTG server monitors MD just fine:

Sun 2014-08-31 13:16:21.004: 05: [554939] Session 554939; child 0001 Sun 2014-08-31 13:16:21.005: 05: [554939] Accepting SMTP connection from [192.168.1.10:51447] to [192.168.1.10:25] Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-domain.com ESMTP Sun, 31 Aug 2014 13:16:21 +0200 Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220- Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-* This site does not authorise the use of its proprietary computers Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-* and computer network to accept, transmit or distribute unsolicited Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-* bulk email, phishing or malware from the Internet. Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220- Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-* Failure to abide by the above statement will result in your server Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-* being permanently banned from connecting in the future. Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220- Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220-* Please report any other problems to postmaster@domain.com Sun 2014-08-31 13:16:21.009: 03: [554939] --> 220 Sun 2014-08-31 13:16:21.010: 02: [554939] <-- EHLO homer Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250-domain.com Hello homer, pleased to meet you Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250-ETRN Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250-AUTH CRAM-MD5 Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250-8BITMIME Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250-ENHANCEDSTATUSCODES Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250-STARTTLS Sun 2014-08-31 13:16:21.012: 03: [554939] --> 250 SIZE Sun 2014-08-31 13:16:21.012: 02: [554939] <-- QUIT Sun 2014-08-31 13:16:21.012: 03: [554939] --> 221 2.0.0 See ya in cyberspace Sun 2014-08-31 13:16:21.012: 04: [554939] SMTP session terminated (Bytes in/out: 18/675) Sun 2014-08-31 13:16:21.012: 01: ----------

YuriIvanov commented 10 years ago

@Taomyn can you increase time to 10 minutes and test it again? So we can find out where the problem in the code or a slow connection.

sledgehammer999 commented 10 years ago

At least now it seems to recognize the EHLO response and not send a HELO. So maybe another bug in the parseEHLO function?

Taomyn commented 10 years ago

Can do,but slow connection between to machines on gigabit ethernet. Give me a sec.....

If you want I can give you my mailserver name and you can test direct, but I'm not posting it here. Can I PM you through github or some other way?

YuriIvanov commented 10 years ago

At the moment, this is not necessary.

YuriIvanov commented 10 years ago

I'll will research this issue tomorrow. Today I don't have time anymore.

sledgehammer999 commented 10 years ago

/joking @Taomyn wow your ONE bug has uncover at least 3 bugs in the smtp code till now. Great job. I wonder how many more we are going to discover until your issue will be fixed.

@YuriIvanov Thanks for the effort. I leave it up to you for the rest.