search

simonrob / email-oauth2-proxy

An IMAP/POP/SMTP proxy that transparently adds OAuth 2.0 authentication for email clients that don't support this method.
Apache License 2.0
785 stars 84 forks source link

No AUTH option advertised on HELO, only on EHLO #232

Closed niklasfink closed 5 months ago

niklasfink commented 6 months ago

Hello, I'm experiencing an issue with some clients which use HELO instead of EHLO messages.

When testing the email proxy with telnet and using EHLO messages, everything works and I can send an email:

Connected to emailproxy.
Escape character is '^]'.
220 xx.outlook.office365.com Microsoft ESMTP MAIL Service ready at Fri, 1 Mar 2024 09:55:13 +0000
EHLO itsme
500 5.3.3 Unrecognized command 'unknown' [xx.PROD.OUTLOOK.COM 2024-03-01T09:55:18.157Z xx]
500 5.3.3 Unrecognized command 'unknown' [xx.PROD.OUTLOOK.COM 2024-03-01T09:55:23.173Z xx]
EHLO itsme
250-xx.outlook.office365.com Hello [publicip]
250-SIZE 157286400
250-PIPELINING
250-DSN
250-ENHANCEDSTATUSCODES
250-AUTH PLAIN LOGIN
250-8BITMIME
250-BINARYMIME
250-CHUNKING
250 SMTPUTF8

However, when using for example swaks (Swiss Army Knife for SMTP) or some clients (such as printers) which seem to say HELO instead of EHLO, then it's not working since the AUTH option is not advertised:

Connected to emailproxy.
Escape character is '^]'.
220 xx.outlook.office365.com Microsoft ESMTP MAIL Service ready at Fri, 1 Mar 2024 10:00:59 +0000
HELO itsme
500 5.3.3 Unrecognized command 'unknown' [xx.PROD.OUTLOOK.COM 2024-03-01T10:01:05.276Z xx]
500 5.3.3 Unrecognized command 'unknown' [xx.PROD.OUTLOOK.COM 2024-03-01T10:01:10.276Z xx]
HELO itsme
250 FR5P281CA0030.outlook.office365.com Hello [publicip]

As we can see, it's giving us much less and the 250-AUTH PLAIN LOGIN is missing.

When using swaks, it goes like this:

swaks --to TOMAIL --from FROMMAIL --server emailproxy --auth-user user --auth-password pass --ehlo itsme
=== Trying emailproxy...
=== Connected to emailproxy.
<-  220 xx.outlook.office365.com Microsoft ESMTP MAIL Service ready at Fri, 1 Mar 2024 09:38:14 +0000
 -> EHLO itsme
<** 500 5.3.3 Unrecognized command 'unknown' [xx.PROD.OUTLOOK.COM 2024-03-01T09:38:20.645Z xx]
 -> HELO itsme
<-  250 xx.outlook.office365.com Hello [publicip]
*** Host did not advertise authentication
 -> QUIT
<-  221 2.0.0 Service closing transmission channel

Do you have an idea for this?

Config:

[SMTP-25]
server_address = outlook.office365.com
server_port = 587
starttls = True

[mailaddress]
permission_url = https://login.microsoftonline.com/tenantid/oauth2/v2.0/authorize
token_url = https://login.microsoftonline.com/tenantid/oauth2/v2.0/token
oauth2_scope = https://outlook.office365.com/SMTP.Send offline_access
redirect_uri = https://emailproxy.local
redirect_listen_address = http://emailproxy:80
client_id = ...
client_secret = ...
simonrob commented 5 months ago

The correct response to HELO is just the server identification (see RFC 821), so this is as expected.

If your client is expecting to receive information about SMTP extensions (which is the case for commands relating to authentication), it needs to send EHLO. Some servers (including O365) tend to be more flexible about this, and still respond to extension commands even if they haven't received an EHLO. Because of this, the proxy still monitors HELO, even if perhaps it technically shouldn't.

I'm more interested in the 500 5.3.3 Unrecognized command 'unknown' that occurs in every log you've posted. For example, in the first extract you send EHLO twice, and recieve this response. Is it just that you made a typo and have edited out part (but not all) of this, or is something else going on?

Out of curiosity, I also tried swaks, and it worked without issue. Please could you post the log from the proxy's side in --debug mode.

niklasfink commented 5 months ago

Ok, so I initially thought that the 500 error codes and my EHLO/HELO topic are separated, but maybe the issue is intertwined. I have posted the log output of my printer connecting to the proxy in #234.

When using swaks, it looks like this:

2024-03-03 19:48:19: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) --> [ Client connected ]
2024-03-03 19:48:19: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b'220 xx.outlook.office365.com Microsoft ESMTP MAIL Service ready at Sun, 3 Mar 2024 19:48:18 +0000\r\n'
2024-03-03 19:48:19: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-- b'220 xx.outlook.office365.com Microsoft ESMTP MAIL Service ready at Sun, 3 Mar 2024 19:48:18 +0000\r\n'
2024-03-03 19:48:19: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) --> b'QUIT\n!\x11\x00\x0c\xac\x12\x00\x01\xac\x12\x00\x08\xdb\xf6\x00\x19EHLO itsme\r\n'
2024-03-03 19:48:19: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     --> b'QUIT\n!\x11\x00\x0c\xac\x12\x00\x01\xac\x12\x00\x08\xdb\xf6\x00\x19EHLO itsme\r\n'
2024-03-03 19:48:24: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b"500 5.3.3 Unrecognized command 'unknown' [xx.xx.PROD.OUTLOOK.COM 2024-03-03T19:48:24.046Z xx]\r\n"
2024-03-03 19:48:24: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-- b"500 5.3.3 Unrecognized command 'unknown' [xx.xx.PROD.OUTLOOK.COM 2024-03-03T19:48:24.046Z xx]\r\n"
2024-03-03 19:48:24: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) --> b'HELO itsme\r\n'
2024-03-03 19:48:24: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     --> b'HELO itsme\r\n'
2024-03-03 19:48:29: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b"500 5.3.3 Unrecognized command 'unknown' [xx.xx.PROD.OUTLOOK.COM 2024-03-03T19:48:29.062Z xx]\r\n"
2024-03-03 19:48:34: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b"500 5.3.3 Unrecognized command '<redacted>' [xx.xx.PROD.OUTLOOK.COM 2024-03-03T19:48:34.077Z xx]\r\n"
2024-03-03 19:48:39: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b"500 5.3.3 Unrecognized command '<redacted>' [xx.xx.PROD.OUTLOOK.COM 2024-03-03T19:48:39.093Z xx]\r\n"
2024-03-03 19:48:39: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b'250 xx.outlook.office365.com Hello [publicip]\r\n'
2024-03-03 19:48:39: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     --> b'STARTTLS\r\n'
2024-03-03 19:48:39: 2024-03-03 19:48:39,102: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b"500 5.3.3 Unrecognized command '<redacted>' [xx.xx.PROD.OUTLOOK.COM 2024-03-03T19:48:39.093Z xx]\r\n"
2024-03-03 19:48:39,120: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b'250 xx.outlook.office365.com Hello [publicip]\r\n'
2024-03-03 19:48:39,120: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     --> b'STARTTLS\r\n'
2024-03-03 19:48:39,143: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b'220 2.0.0 SMTP server ready\r\n'
2024-03-03 19:48:39,162: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-> [ Starting TLS handshake ]
2024-03-03 19:48:39,162: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) [ Successfully negotiated SMTP STARTTLS connection - re-sending greeting ]
2024-03-03 19:48:39,162: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     --> b'HELO itsme\r\n'
2024-03-03 19:48:39,208: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-> [ TLSv1.3 handshake complete ]
2024-03-03 19:48:39,245: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b'250 xx.outlook.office365.com Hello [publicip]\r\n'
2024-03-03 19:48:39,245: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-- b'250 xx.outlook.office365.com Hello [publicip]\r\n'
2024-03-03 19:48:39,250: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) --> b'QUIT\r\n'
2024-03-03 19:48:39,250: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     --> b'QUIT\r\n'
2024-03-03 19:48:39,269: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587)     <-- b'221 2.0.0 Service closing transmission channel\r\n'
2024-03-03 19:48:39,269: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-- b'221 2.0.0 Service closing transmission channel\r\n'
2024-03-03 19:48:39,271: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) <-- [ Server disconnected ]
2024-03-03 19:48:39,271: SMTP ([internal]:38533-{[internal]:25}-outlook.office365.com:587) --> [ Client disconnected ]

I would leave it up to you which issue to continue with. Sorry for the confusion.

simonrob commented 5 months ago

The proxy supports the <initial-response> argument to AUTH LOGIN, though you'll still need to send HELO/EHLO first.

Re: printer, I'd need to see a log from the proxy's side to see what commands are being sent.

simonrob commented 5 months ago

Re: your second update, it's easy to get O365 to reply with that 'unknown' message when you send the string you're providing: QUIT\n!\x11\x00\x0c\xac\x12\x00\x01\xac\x12\x00\x08\xdb\xf6\x00\x19EHLO itsme\r\n (line 4 of the log).

This is the real issue: your client is connecting, then immediately sending QUIT, followed by an unknown binary string, and only then the EHLO message. You need to configure the client to stop this (swaks didn't do this when I tried it myself). One potential cause is if your client is expecting a secure connection from the outset (rather than using STARTTLS). But the fact that it sends plaintext commands after this suggests that isn't the case here.

simonrob commented 5 months ago

After a quick search, I may have found the cause – the QUIT\n! was the key here. You need to stop this service (HAProxy?) interfering with your SMTP requests.

Edit: just to follow up, I believe the complete command that is being injected is probably:

\r\n\r\n\x00\r\nQUIT\n!\x11\x00\x0c\xac\x12\x00\x01\xac\x12\x00\x08\xdb\xf6\x00\x19EHLO itsme\r\n

Using proxy-protoxol, this decodes to a PROXY prococol header of:

ProxyResultIPv4((IPv4Address('172.18.0.1'), 56310), (IPv4Address('172.18.0.8'), 25), protocol=socket.SOCK_STREAM, tlv=ProxyProtocolTLV(b'E\x00\tO itsme\r\n'))

There's still some corruption of the actual data, so this may not be wholly correct, but I think it's pretty clear that this is the cause here.

~The command isn't shown completely in the proxy log because it reads line by line, separated by \r\n, so the first blank lines are skipped. It should potentially send the \x00 for completeness, but that's not the issue here.~ Edit 2: for completeness, I tried this, and the proxy does send the first part of the command, but that isn't shown in this log. I'm assuming you didn't edit this out, so perhaps you're using a different version of this protocol that omits the initial part of the header. Either way, it's pretty clear this is the cause, and that the proxy isn't at fault here, so I'll close this issue. Feel free to reopen if you find that something on the proxy's side is involved.

niklasfink commented 5 months ago

Thanks a lot, this has solved the issue. I was using the email-oauth2-proxy in a dockerized environment with traefik in front of it. Unfortunately, I had set the "traefik.tcp.services.emailproxy-service.loadbalancer.proxyProtocol.version=2", which needed to be removed. It is working now as a tcp router and http for authentication replies.