Logger.Formatter crash on :ssl alert in mix archive.install

[ruslandoga]

Elixir and Erlang/OTP versions

Erlang/OTP 27 [erts-15.0] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit]
Elixir 1.17.3 (compiled with Erlang/OTP 27)

Operating system

Darwin 24.1.0 Darwin Kernel Version 24.1.0: Thu Oct 10 21:02:45 PDT 2024; root:xnu-11215.41.3~2/RELEASE_ARM64_T8112 arm64

Current behavior

Sorry for the screenshot, I'll update this message once I manage to reproduce it (I'm trying it now):

Expected behavior

Logger.Formatter can format :ssl alerts.

[josevalim]

It looks like an Erlang bug to me. We are simply invoking a callback in the metadata:

https://github.com/elixir-lang/elixir/blob/v1.17.3/lib/logger/lib/logger/formatter.ex#L243

[josevalim]

Ok, there is something weirder going on. What does Code.ensure_loaded?(:ssl_alert) returns for you? I can confirm the function exists in Erlang (and it has been for quite some time), so the only possible reason is that the module failed to load some misterious reason.

[ruslandoga]

Right, I checked and Logger.Formatter renders the "raw" event just fine in IEx. Might be some "application ensure loaded" issue with Mix and :ssl

iex> Code.ensure_loaded?(:ssl_alert)
true

iex> {mod, config} = Logger.Formatter.new([])

iex> event = %{
  meta: %{
    line: 491,
    pid: self(), # why not
    time: 1732450320177859,
    file: ~c"tls_gen_connection.erl",
    gl: :erlang.group_leader(),
    mfa: {:tls_gen_connection, :handle_protocol_record, 3},
    depth: 20,
    report_cb: &:ssl_logger.format/1
  },
  msg: {:report,
   %{
     protocol: ~c"TLS",
     alert: {:alert, 2, 40,
      %{
        line: 491,
        file: ~c"tls_gen_connection.erl",
        mfa: {:tls_gen_connection, :handle_protocol_record, 3}
      }, :client, :alert_decode_error},
     alerter: :own,
     statename: :connection,
     role: :client
   }},
  level: :notice
}

iex> IO.puts mod.format(event, config)

19:12:00.177 [notice] TLS :client: In state :connection at tls_gen_connection.erl:491 generated CLIENT ALERT: Fatal - Handshake Failure
 - :alert_decode_error

I'll try to reproduce it with mix archive.install. I think the issue happened when I didn't have or lost internet connection while running mix archive.install hex phx_new.

[ruslandoga]

I tried setting hex repo to a "bad cert" URL and it works as expected (no crash):

$ mix hex.repo add expired https://expired.badssl.com
$ mix archive.install hex phx_new --repo expired

17:05:25.287 [notice] TLS :client: In state :certify at ssl_handshake.erl:2158 generated CLIENT ALERT: Fatal - Certificate Expired

Failed to fetch record for expired/phx_new from registry (using cache instead)
{:failed_connect, [{:to_address, {~c"expired.badssl.com", 443}}, {:inet, [:inet], {:tls_alert, {:certificate_expired, ~c"TLS client: In state certify at ssl_handshake.erl:2158 generated CLIENT ALERT: Fatal - Certificate Expired\n"}}}]}
** (Mix) No package with name phx_new (from: mix.exs) in registry

I'll try a few more things (I am not sure where the notice above comes from, :ssl or Logger.Formatter, and if &:ssl_logger.format/1 is being invoked on "expired" cert error path) but for now I'll close the issue since I'm not able to reproduce it.

Sorry!