(gen_smtp 0.15.0 and 1.1.1) Issues parsing EHLO response with Erlang 23.2.7 - works at with 23.2.6

[kleinernik]

With Erlang 23.2.7 we get the following error. It works with 23.2.6 and older. We use TLS and it is probably an issue with Erlang not with gen_smtp, but I wanted to document it here too.

** (ArgumentError) argument error :erlang.split_binary('250-smtp-out-n03.prod.us-west-2.postgun.com\r\n', 3) (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/binstr.erl:114: :binstr.substr/3 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:697: :gen_smtp_client.read_possible_multiline_reply/1 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:562: :gen_smtp_client.try_EHLO/2 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:623: :gen_smtp_client.do_STARTTLS/2 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:594: :gen_smtp_client.try_STARTTLS/3 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:333: :gen_smtp_client.open_smtp_session/2 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:271: :gen_smtp_client.try_smtp_sessions/3 (gen_smtp 0.15.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:258: :gen_smtp_client.send_it/2 (swoosh 0.24.4) lib/swoosh/adapters/smtp.ex:47: Swoosh.Adapters.SMTP.deliver/2

Same with gen_smtp 1.1.1

** (ArgumentError) argument error :erlang.split_binary('250-smtp-out-n04.prod.us-west-2.postgun.com\r\n', 3) (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/binstr.erl:114: :binstr.substr/3 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:738: :gen_smtp_client.read_possible_multiline_reply/1 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:603: :gen_smtp_client.try_EHLO/2 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:664: :gen_smtp_client.do_STARTTLS/2 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:635: :gen_smtp_client.try_STARTTLS/3 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:353: :gen_smtp_client.open_smtp_session/2 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:292: :gen_smtp_client.try_smtp_sessions/3 (gen_smtp 1.1.0) /home/nik/projects/platform-base/platform/deps/gen_smtp/src/gen_smtp_client.erl:267: :gen_smtp_client.send_it/2 (swoosh 1.3.3) lib/swoosh/adapters/smtp.ex:48: Swoosh.Adapters.SMTP.deliver/2

[maennchen]

I'm seeing the same error on our infrastructure at the moment:

 12:23:43.445 [error] Uncaught Error while sending email:
 ** (ArgumentError) argument error
     :erlang.split_binary('250-mx.google.com at your service, [185.79.235.176]\r\n', 3)
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/binstr.erl:114: :binstr.substr/3
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/gen_smtp_client.erl:738: :gen_smtp_client.read_possible_multiline_reply/1
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/gen_smtp_client.erl:603: :gen_smtp_client.try_EHLO/2
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/gen_smtp_client.erl:664: :gen_smtp_client.do_STARTTLS/2
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/gen_smtp_client.erl:635: :gen_smtp_client.try_STARTTLS/3
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/gen_smtp_client.erl:353: :gen_smtp_client.open_smtp_session/2
     (gen_smtp 1.1.0) /builds/hygeia/backend/deps/gen_smtp/src/gen_smtp_client.erl:292: :gen_smtp_client.try_smtp_sessions/3

[maennchen]

The problems seems to be caused by the contents of Packet in https://github.com/gen-smtp/gen_smtp/blob/master/src/gen_smtp_client.erl#L737

contents of Packet via erlang:display/1

• Erlang 23.2.5

<<50,50,48,32,109,120,46,103,111,111,103,108,101,46,99,111,109,32,69,83,77,84,80,32,107,50,115,105,50,55,51,55,53,53,55,119,109,106,46,49,56,50,32,45,32,103,115,109,116,112,13,10>>
<<50,53,48,45,109,120,46,103,111,111,103,108,101,46,99,111,109,32,97,116,32,121,111,117,114,32,115,101,114,118,105,99,101,44,32,91,56,57,46,50,52,48,46,55,52,46,49,56,52,93,13,10>>
<<50,50,48,32,50,46,48,46,48,32,82,101,97,100,121,32,116,111,32,115,116,97,114,116,32,84,76,83,13,10>>
<<50,53,48,45,109,120,46,103,111,111,103,108,101,46,99,111,109,32,97,116,32,121,111,117,114,32,115,101,114,118,105,99,101,44,32,91,56,57,46,50,52,48,46,55,52,46,49,56,52,93,13,10>>
<<50,53,48,32,50,46,49,46,48,32,79,75,32,107,50,115,105,50,55,51,55,53,53,55,119,109,106,46,49,56,50,32,45,32,103,115,109,116,112,13,10>>
<<50,53,48,32,50,46,49,46,53,32,79,75,32,107,50,115,105,50,55,51,55,53,53,55,119,109,106,46,49,56,50,32,45,32,103,115,109,116,112,13,10>>
<<51,53,52,32,32,71,111,32,97,104,101,97,100,32,107,50,115,105,50,55,51,55,53,53,55,119,109,106,46,49,56,50,32,45,32,103,115,109,116,112,13,10>>
<<50,53,48,32,50,46,48,46,48,32,79,75,32,32,49,54,49,52,57,52,56,52,57,53,32,107,50,115,105,50,55,51,55,53,53,55,119,109,106,46,49,56,50,32,45,32,103,115,109,116,112,13,10>>

• Erlang 23.2.7

<<50,50,48,32,109,120,46,103,111,111,103,108,101,46,99,111,109,32,69,83,77,84,80,32,117,49,51,115,105,50,57,48,56,49,55,48,119,114,113,46,50,55,57,32,45,32,103,115,109,116,112,13,10>>
<<50,53,48,45,109,120,46,103,111,111,103,108,101,46,99,111,109,32,97,116,32,121,111,117,114,32,115,101,114,118,105,99,101,44,32,91,56,57,46,50,52,48,46,55,52,46,49,56,52,93,13,10>>
<<50,50,48,32,50,46,48,46,48,32,82,101,97,100,121,32,116,111,32,115,116,97,114,116,32,84,76,83,13,10>>
\n"0-mx.google.com at your service, [89.240.74.184]

[arjan]

From the looks of it it tries to binary split an Erlang list, which will not work of course. (note the single ' quote in the ArgumentError). So it seems the client receives the packets as lists instead of binaries?

[maennchen]

@arjan Yes that seems to be the issue. I'm currently trying to figure out what change caused this behavior so that it can be reported to Erlang / OTP as a bug.

Edit: Those two commits are the changes in 3.2.7:

• https://github.com/erlang/otp/commit/d97c1673a6a0d8fc8c18817c2a551e1d28bc4ea4
• https://github.com/erlang/otp/commit/961bde86e39392ae3e3efa3eb1239528c71adf23

[arjan]

Those changes seem very unrelated :thinking:

[maennchen]

@arjan I agree. I used asdf to install both versions that were tested.

[arjan]

It looks like suddenly smtp_socket:recv returns {ok, string()} instead of {ok, binary()}. Maybe the default socket mode changed? For such a minor release I would not expect that..

[arjan]

Could you try changing this line to read {mode, binary} instead of just binary? (as you have a way of reproducing this)

[maennchen]

@arjan No, that doesn't solve it, unfortunately.

[maennchen]

@arjan It seems like smtp_socket:tcp_connect_options / smtp_socket:ssl_connect_options is doing something with the format though...

[arjan]

wow that is some weird code. Maybe debug what ssl_connect_options(Opts) actually returns on smtp_socket line 97..

[maennchen]

Still doesn't work like this.

diff --git a/src/gen_smtp_client.erl b/src/gen_smtp_client.erl
index 0c1c175..95c5f0e 100644
--- a/src/gen_smtp_client.erl
+++ b/src/gen_smtp_client.erl
@@ -695,7 +695,7 @@ connect(Host, Options) ->
        undefined -> [];
        Other -> Other
    end,
-   SockOpts = [binary, {packet, line}, {keepalive, true}, {active, false} | AddSockOpts],
+   SockOpts = [{mode, binary}, {packet, line}, {keepalive, true}, {active, false} | AddSockOpts],
    Proto = case proplists:get_value(ssl, Options) of
        true ->
            ssl;
diff --git a/src/smtp_socket.erl b/src/smtp_socket.erl
index 312e7ec..162721c 100644
--- a/src/smtp_socket.erl
+++ b/src/smtp_socket.erl
@@ -299,19 +299,11 @@ ssl_listen_options(Options) ->
 ssl_listen_options(Options, Format) ->
    parse_address([Format|proplist_merge(Options, ?SSL_LISTEN_OPTIONS)]).

-tcp_connect_options([Format|Options]) when Format =:= list; Format =:= binary ->
-   tcp_connect_options(Options, Format);
 tcp_connect_options(Options) ->
-   tcp_connect_options(Options, list).
-tcp_connect_options(Options, Format) ->
-   parse_address([Format|proplist_merge(Options, ?TCP_CONNECT_OPTIONS)]).
+   parse_address(proplist_merge(Options, ?TCP_CONNECT_OPTIONS)).

-ssl_connect_options([Format|Options]) when Format =:= list; Format =:= binary ->
-   ssl_connect_options(Options, Format);
 ssl_connect_options(Options) ->
-   ssl_connect_options(Options, list).
-ssl_connect_options(Options, Format) ->
-   parse_address([Format|proplist_merge(Options, ?SSL_CONNECT_OPTIONS)]).
+   parse_address(proplist_merge(Options, ?SSL_CONNECT_OPTIONS)).

 proplist_merge(PrimaryList, DefaultList) ->
    {PrimaryTuples, PrimaryOther} = lists:partition(fun(X) -> is_tuple(X) end, PrimaryList),

[arjan]

Do you have a test script that you use? Maybe I can help debugging..

[maennchen]

@arjan It seems the mode is somehow removed: [{active,false},{ip,{0,0,0,0}},{packet,line},{port,0}]

[maennchen]

@arjan No sorry, I'm starting a proprietary software and tell it to send the email spool.

[maennchen]

@arjan

diff --git a/src/smtp_socket.erl b/src/smtp_socket.erl
index 312e7ec..512c43a 100644
--- a/src/smtp_socket.erl
+++ b/src/smtp_socket.erl
@@ -92,8 +92,10 @@ connect(Protocol, Address, Port, Opts) ->

 -spec connect(Protocol :: protocol(), Address :: address(), Port :: pos_integer(), Options :: list(), Time :: non_neg_integer() | 'infinity') -> {ok, socket()} | {error, any()}.
 connect(tcp, Address, Port, Opts, Time) ->
+   erlang:display(tcp_connect_options(Opts)),
    gen_tcp:connect(Address, Port, tcp_connect_options(Opts), Time);
 connect(ssl, Address, Port, Opts, Time) ->
+   erlang:display(ssl_connect_options(Opts)),
    ssl:connect(Address, Port, ssl_connect_options(Opts), Time).

@@ -304,14 +306,14 @@ tcp_connect_options([Format|Options]) when Format =:= list; Format =:= binary ->
 tcp_connect_options(Options) ->
    tcp_connect_options(Options, list).
 tcp_connect_options(Options, Format) ->
-   parse_address([Format|proplist_merge(Options, ?TCP_CONNECT_OPTIONS)]).
+   parse_address([{mode, Format}|proplist_merge(Options, ?TCP_CONNECT_OPTIONS)]).

 ssl_connect_options([Format|Options]) when Format =:= list; Format =:= binary ->
    ssl_connect_options(Options, Format);
 ssl_connect_options(Options) ->
    ssl_connect_options(Options, list).
 ssl_connect_options(Options, Format) ->
-   parse_address([Format|proplist_merge(Options, ?SSL_CONNECT_OPTIONS)]).
+   parse_address([{mode, Format}|proplist_merge(Options, ?SSL_CONNECT_OPTIONS)]).

 proplist_merge(PrimaryList, DefaultList) ->
    {PrimaryTuples, PrimaryOther} = lists:partition(fun(X) -> is_tuple(X) end, PrimaryList),

=>

[{mode,binary},{active,false},{ip,{0,0,0,0}},{packet,line},{port,0}]

I'll create you a simple (elixir) call that reproduces the bug.

[kleinernik]

I think the changes to handle_option_format here https://github.com/erlang/otp/commit/961bde86e39392ae3e3efa3eb1239528c71adf23#diff-c6e4e01fbddfaa6057fc43144940a337eb3db17891c62cce9ad2123e0107f776R2713 may have to do something with our issue, even though I can't figure out what could be wrong with this code

[maennchen]

@arjan If you run this in a project with gen_smtp installed, this will trigger the bug:

:gen_smtp_client.send_blocking(
  {"Info.ContactTracing@sg.ch", ["maennchen@joshmartin.ch"],
   "Subject: hgdfj\r\nFrom: Kanton Appenzell Ausserrhoden <Info.ContactTracing@sg.ch>\r\nTo: =?UTF-8?Q?Jonatan=20M=C3=A4nnchen?= <maennchen@joshmartin.ch>\r\nAuto-submitted: yes\r\nX-Auto-Response-Suppress: All\r\nPrecedence: auto_reply\r\nDate: Fri, 5 Mar 2021 13:43:32 +0000\r\nMessage-ID: 9e1e3dab-fa26-4329-afcf-8808adf15b31\r\nContent-Type: text/plain\r\nContent-Transfer-Encoding: 7bit\r\nMIME-Version: 1.0\r\n\r\nSehr geehrte Damen und Herren\r\n\r\nWie soeben telefonisch besprochen, erhalten Sie unter folgendem Link die Informationen zur Isolation:\r\nhttp://localhost:4000/pdf/isolation/2bf2efc8-bfa7-4d2d-b72d-b44179d9c5ba/c496bb7d-940b-4e2d-8a34-bd1ca05f4b2f\r\nBitte lesen Sie das Dokument vollständig durch und beachten Sie die angegebenen Links für weitere Informationen. \r\n\r\nDamit das Contact Tracing sichergestellt werden kann, benötigen wir alle Angaben Ihrer Kontaktpersonen.\r\nSie können Ihre Kontaktpersonen hier selbst erfassen:\r\nhttp://localhost:4000/cases/2bf2efc8-bfa7-4d2d-b72d-b44179d9c5ba/possible-index-submissions\r\n\r\n\r\nBesten Dank und freundliche Grüsse\r\n\r\nContact Tracing St.Gallen, Appenzell Innerrhoden, Appenzell Ausserrhoden Kantonaler Führungsstab: KFS\r\n"},
  relay: "joshmartin.ch",
  port: 25,
  hostname: "smtp.covid19-tracing.ch",
  retries: 10
)

[arjan]

Thanks, I'll try to reproduce it here

[arjan]

I think this is the fix:

diff --git a/src/gen_smtp_client.erl b/src/gen_smtp_client.erl
index a46bc65..6600346 100644
--- a/src/gen_smtp_client.erl
+++ b/src/gen_smtp_client.erl
@@ -658,7 +658,7 @@ do_STARTTLS(Socket, Options) ->
        smtp_socket:send(Socket, "STARTTLS\r\n"),
        case read_possible_multiline_reply(Socket) of
                {ok, <<"220", _Rest/binary>>} ->
-                       case catch smtp_socket:to_ssl_client(Socket, proplists:get_value(tls_options, Options, []), 5000) of
+                       case catch smtp_socket:to_ssl_client(Socket, [binary | proplists:get_value(tls_options, Options, [])], 5000) of
                                {ok, NewSocket} ->
                                        %NewSocket;
                                        {ok, Extensions} = try_EHLO(NewSocket, Options),

The connection started as a normal TCP connection and then got upgraded; which omitted the binary option that the other code path (direct TLS conn) added.

[maennchen]

@arjan Should we still report this to OTP since this seems to be an unintended breaking change?

[arjan]

Yes I guess, if we can reproduce a minimal example of where it goes wrong...

[kleinernik]

I guess I know the root cause. In https://github.com/erlang/otp/blob/961bde86e39392ae3e3efa3eb1239528c71adf23/lib/ssl/src/ssl.erl#L581 the sockets options of the underlying tcp sockets get appended to the ssl_connect options. So if the underlying socket has a different mode than in ssl_connect options, it comes later in the list. It seems to me like the last is used. Now the new implementation https://github.com/erlang/otp/commit/961bde86e39392ae3e3efa3eb1239528c71adf23#diff-c6e4e01fbddfaa6057fc43144940a337eb3db17891c62cce9ad2123e0107f776R2713 happens to reverse the list, now the mode set in the ssl_connect options comes last and is used

[kleinernik]

here is a mininal test script in elixir

tcp_opts = [mode: :binary, active: false, packet: :line, ip: {0,0,0,0}, port: 0]

ssl_opts = [mode: :list, active: false, depth: 0, packet: :line, ip: {0,0,0,0}, port: 0]

Application.ensure_all_started :ssl
{:ok, ip} = '172.217.18.99' |> :inet.parse_address
{:ok, port} = :gen_tcp.connect ip, 443, tcp_opts
:inet.getopts(port, [:mode]) |> IO.inspect
:tls_socket.getopts(:gen_tcp, port, :tls_socket.emulated_options) |> IO.inspect
{:ok, sslsocket} = :ssl.connect port, ssl_opts
:inet.getopts(port, [:mode]) |> IO.inspect
:ssl.getopts(sslsocket, [:mode]) |> IO.inspect

With erlang 23.2.6 the last line prints {:ok, [mode: :binary]}and with erlang 23.2.7 it prints {:ok, [mode: :list]}

[maennchen]

@arjan I've managed to produce a small reproduction script and posted it to the erlang issue system: https://github.com/erlang/otp/issues/4586