Miscellaneous refactoring (#77)

* Bug: default_opts should be first in Map.merge/2

* Fix deprecated Logger.warn/1 calls

* Align 'context' value with FSM state

* Changes to 'format_error' that work both with OTP 25 and 26

* Fix TLS tests to work across OTP 25 and 26

* Bump cache version

.github/workflows/main.yml

@@ -11,7 +11,7 @@ env:
   MIX_ENV: test
   otp-version: '24'
   elixir-version: '1.14'
-  cache-version: '3'
+  cache-version: '4'
 
 jobs:
   build:

config/test.exs

@@ -1,3 +1,3 @@
 import Config
 
-config :logger, level: :warn
+config :logger, level: :warning

lib/mllp/client.ex

@@ -200,13 +200,18 @@ defmodule MLLP.Client do
     "Unexpected packet received"
   end
 
-  def format_error(posix) when is_atom(posix) do
-    case :inet.format_error(posix) do
-      'unknown POSIX error' ->
-        inspect(posix)
-
-      char_list ->
-        to_string(char_list)
+  def format_error(err) when is_atom(err) do
+    # Check if that's a POSIX error
+    posix_error_str =
+      err
+      |> :inet.format_error()
+      |> to_string()
+
+    if String.starts_with?(posix_error_str, "unknown POSIX error") do
+      # No, it's not...
+      inspect(err)
+    else
+      posix_error_str
     end
   end
 
@@ -410,7 +415,7 @@ defmodule MLLP.Client do
         {:keep_state, new_state, reconnect_action(new_state)}
 
       :ok ->
-        {:next_state, :connected, new_state}
+        next_state(:connected, new_state)
     end
   end
 
@@ -426,7 +431,7 @@ defmodule MLLP.Client do
 
   def disconnected({:call, from}, {:send, _message, _options}, data) do
     actions = [
-      {:reply, from, {:error, new_error(:send, data.tcp_error)}},
+      {:reply, from, {:error, new_error(:sending, data.tcp_error)}},
       {:next_event, :internal, :connect}
     ]
 
@@ -459,23 +464,26 @@ defmodule MLLP.Client do
 
     case data.tcp.send(data.socket, payload) do
       :ok ->
-        {:next_state, :receiving,
-         data
-         |> Map.put(:context, :recv)
-         |> Map.put(:caller, from), send_action(send_type, from, options, data)}
+        next_state(
+          :receiving,
+          data
+          |> Map.put(:context, :recv)
+          |> Map.put(:caller, from),
+          send_action(send_type, from, options, data)
+        )
 
       {:error, reason} ->
         telemetry(
           :status,
           %{
             status: :disconnected,
             error: format_error(reason),
-            context: "send message failure"
+            context: :sending
           },
           data
         )
 
-        error_reply = {:error, new_error(:send, reason)}
+        error_reply = {:error, new_error(:sending, reason)}
         {:keep_state_and_data, [{:reply, from, error_reply}]}
     end
   end
@@ -495,7 +503,7 @@ defmodule MLLP.Client do
 
   def connected(:info, {transport_closed, _socket}, data)
       when transport_closed in [:tcp_closed, :ssl_closed] do
-    {:next_state, :disconnected, handle_closed(data)}
+    next_state(:disconnected, handle_closed(data))
   end
 
   def connected(event, unknown, _data) do
@@ -536,28 +544,28 @@ defmodule MLLP.Client do
   end
 
   def receiving({:call, from}, {:send, _message, _options}, _data) do
-    {:keep_state_and_data, [{:reply, from, format_reply({:error, :busy_with_other_call}, :send)}]}
+    {:keep_state_and_data,
+     [{:reply, from, format_reply({:error, :busy_with_other_call}, :sending)}]}
   end
 
   def receiving(:state_timeout, :receive_timeout, data) do
-    {:next_state, :connected, reply_to_caller({:error, :timeout}, maybe_close(:timeout, data))}
+    next_state(:connected, reply_to_caller({:error, :timeout}, maybe_close(:timeout, data)))
   end
 
   def receiving(:info, {transport, socket, incoming}, %{socket: socket} = data)
       when transport in [:tcp, :ssl] do
     new_data = handle_received(incoming, data)
-    next_state = next_after_receiving(new_data)
-    {:next_state, next_state, new_data}
+    next_state(next_after_receiving(new_data), new_data)
   end
 
   def receiving(:info, {transport_closed, socket}, %{socket: socket} = data)
       when transport_closed in [:tcp_closed, :ssl_closed] do
-    {:next_state, :disconnected, handle_closed(data)}
+    next_state(:disconnected, handle_closed(data))
   end
 
   def receiving(:info, {transport_error, socket, reason}, %{socket: socket} = data)
       when transport_error in [:tcp_error, :ssl_error] do
-    {:next_state, :disconnected, handle_error(reason, maybe_close(reason, data))}
+    next_state(:disconnected, handle_error(reason, maybe_close(reason, data)))
   end
 
   def receiving({:call, _from} = event_kind, request, data)
@@ -586,7 +594,7 @@ defmodule MLLP.Client do
   ########################################
 
   defp unexpected_message(state, event, message) do
-    Logger.warn(
+    Logger.warning(
       "Event: #{inspect(event)} in state #{state}. Unknown message received => #{inspect(message)}"
     )
 
@@ -783,6 +791,10 @@ defmodule MLLP.Client do
     %{data | backoff: new_backoff}
   end
 
+  defp next_state(state, data, actions \\ []) do
+    {:next_state, state, Map.put(data, :context, state), actions}
+  end
+
   defp telemetry(_event_name, _measurements, %State{telemetry_module: nil} = _metadata) do
     :ok
   end
@@ -842,8 +854,7 @@ defmodule MLLP.Client do
 
     socket_opts = Keyword.merge(default_socket_opts(), opts[:socket_opts] || [])
 
-    opts
-    |> Map.merge(default_opts())
+    Map.merge(default_opts(), opts)
     |> Map.put_new(:tcp, socket_module)
     |> Map.put(:pid, self())
     |> Map.put(:tls_opts, opts.tls)

lib/mllp/receiver.ex

@@ -236,7 +236,7 @@ defmodule MLLP.Receiver do
     {transport_module, tls_options1, transport_opts1} =
       case Map.pop(transport_opts, :tls) do
         {nil, options1} ->
-          Logger.warn(
+          Logger.warning(
             "Starting listener on a non secured socket, data will be passed over unencrypted connection!"
           )
 
@@ -335,7 +335,9 @@ defmodule MLLP.Receiver do
         :gen_server.enter_loop(__MODULE__, [], state)
 
       {:error, error} ->
-        Logger.warn("Failed to verify client #{inspect(client_info)}, error: #{inspect(error)}")
+        Logger.warning(
+          "Failed to verify client #{inspect(client_info)}, error: #{inspect(error)}"
+        )
 
         {:stop,
          %{message: "Failed to verify client #{inspect(client_info)}, error: #{inspect(error)}"}}
@@ -365,7 +367,7 @@ defmodule MLLP.Receiver do
   end
 
   def handle_info(msg, state) do
-    Logger.warn("Unexpected handle_info for msg [#{inspect(msg)}].")
+    Logger.warning("Unexpected handle_info for msg [#{inspect(msg)}].")
     {:noreply, state}
   end
 
@@ -434,7 +436,7 @@ defmodule MLLP.Receiver do
         address
 
       error ->
-        Logger.warn(
+        Logger.warning(
           "IP/hostname #{inspect(name)} provided is not a valid IP/hostname #{inspect(error)}. It will be filtered from allowed_clients list"
         )
 

lib/mllp/tls_logging_transport.ex

@@ -88,16 +88,20 @@ defmodule MLLP.TLS.HandshakeLoggingTransport do
         {:ok, new_socket}
 
       {:error, _} = handshake_error ->
-        log_peer(peer_data)
+        log_peer(peer_data, handshake_error)
         handshake_error
     end
   end
 
-  defp log_peer({nil, peername_error}) do
-    Logger.error("Handshake failure; peer is undetected (#{inspect(peername_error)})")
+  defp log_peer({nil, peername_error}, handshake_error) do
+    Logger.error(
+      "Handshake failure #{inspect(handshake_error)}; peer is undetected (#{inspect(peername_error)})"
+    )
   end
 
-  defp log_peer({ip, port}) do
-    Logger.error("Handshake failure on connection attempt from #{inspect(ip)}:#{inspect(port)}")
+  defp log_peer({ip, port}, handshake_error) do
+    Logger.error(
+      "Handshake failure #{inspect(handshake_error)} on connection attempt from #{inspect(ip)}:#{inspect(port)}"
+    )
   end
 end

test/client_and_receiver_integration_test.exs

@@ -2,6 +2,7 @@ defmodule ClientAndReceiverIntegrationTest do
   use ExUnit.Case, async: false
   import ExUnit.CaptureLog
   import Mox
+  import MLLP.TestHelper.Utils
   setup :verify_on_exit!
   setup :set_mox_global
 
@@ -127,7 +128,7 @@ defmodule ClientAndReceiverIntegrationTest do
 
       {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port)
 
-      exp_err = %Error{context: :send, reason: :econnrefused, message: "connection refused"}
+      exp_err = %Error{context: :sending, reason: :econnrefused, message: "connection refused"}
       assert {:error, ^exp_err} = MLLP.Client.send(client_pid, "Eh?")
     end
 
@@ -201,7 +202,7 @@ defmodule ClientAndReceiverIntegrationTest do
 
       payload = "A simple message"
 
-      exp_err = %Error{context: :send, reason: :econnrefused, message: "connection refused"}
+      exp_err = %Error{context: :sending, reason: :econnrefused, message: "connection refused"}
       assert {:error, ^exp_err} = MLLP.Client.send(client_pid, payload)
 
       capture_log(fn -> MLLP.Client.stop(client_pid) end)
@@ -224,7 +225,7 @@ defmodule ClientAndReceiverIntegrationTest do
       {:error, %Error{context: context, message: message}} =
         MLLP.Client.send(client_pid, "Simple message")
 
-      assert context in [:send, :recv]
+      assert context in [:sending, :receiving]
       assert message in [MLLP.Client.format_error(:closed), MLLP.Client.format_error(:einval)]
 
       refute MLLP.Client.is_connected?(client_pid)
@@ -358,7 +359,7 @@ defmodule ClientAndReceiverIntegrationTest do
       {:ok, client_pid} =
         MLLP.Client.start_link({127, 0, 0, 1}, ctx.port, tls: ctx.client_tls_options)
 
-      assert {:error, %Error{reason: {:tls_alert, {:handshake_failure, _}}, context: :send}} =
+      assert {:error, %Error{reason: {:tls_alert, {:handshake_failure, _}}, context: :sending}} =
                MLLP.Client.send(
                  client_pid,
                  HL7.Examples.wikipedia_sample_hl7() |> HL7.Message.new()
@@ -417,7 +418,7 @@ defmodule ClientAndReceiverIntegrationTest do
 
                Process.sleep(10)
                refute MLLP.Client.is_connected?(client_pid)
-             end) =~ "Handshake failure on connection attempt from {127, 0, 0, 1}"
+             end) =~ "hostname_check_failed"
     end
   end
 
@@ -445,7 +446,7 @@ defmodule ClientAndReceiverIntegrationTest do
           HL7.Examples.wikipedia_sample_hl7() |> HL7.Message.new()
         )
 
-      assert error.context in [:send, :recv]
+      assert error.context in [:sending, :receiving]
       assert error.reason in [:closed, :einval]
     end
 
@@ -506,7 +507,7 @@ defmodule ClientAndReceiverIntegrationTest do
         keyfile: keyfile
       ]
 
-      tls_alert = ctx[:reason] || []
+      tls_alert = ctx[:reason] || [{:options, {:certfile, ""}}]
 
       expected_error_reasons = [:einval, :no_socket, :closed] ++ tls_alert
 
@@ -523,15 +524,21 @@ defmodule ClientAndReceiverIntegrationTest do
     @tag verify: :verify_none
     @tag client_cert: ""
     @tag keyfile: ""
+    @tag reason: [{:options, {:certfile, ""}}]
     test "does not verify client cert if verify none option is provided on receiver", ctx do
-      make_call_and_assert_success(ctx, ctx.ack)
+      if otp_release() < 26 do
+        make_call_and_assert_success(ctx, ctx.ack)
+      else
+        make_call_and_assert_failure(ctx, ctx.reason)
+      end
     end
 
     @tag port: 8162
     @tag client_cert: ""
     @tag keyfile: ""
 
-    @tag reason: [:handshake_failure, :certificate_required]
+    @tag reason: [:handshake_failure, :certificate_required, {:options, {:certfile, ""}}]
+
     test "no peer cert", ctx do
       make_call_and_assert_failure(ctx, ctx.expected_error_reasons)
     end
@@ -654,7 +661,7 @@ defmodule ClientAndReceiverIntegrationTest do
   defp open_ports_for_pid(pid) do
     Enum.filter(Port.list(), fn p ->
       info = Port.info(p)
-      Keyword.get(info, :name) == 'tcp_inet' and Keyword.get(info, :connected) == pid
+      Keyword.get(info, :name) == ~c"tcp_inet" and Keyword.get(info, :connected) == pid
     end)
   end