From 5e8b98a2309a4f683a29f623ae41ae551ff57eed Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 27 Jun 2023 11:30:16 -0400 Subject: [PATCH 01/47] Unit test for detection of disconnected receiver --- test/client_and_receiver_integration_test.exs | 42 +++++++++++++------ 1 file changed, 30 insertions(+), 12 deletions(-) diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 4e0c905..66af59d 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -108,10 +108,10 @@ defmodule ClientAndReceiverIntegrationTest do assert MLLP.Client.is_connected?(client_pid) capture_log(fn -> MLLP.Client.stop(client_pid) end) - assert Process.alive?(client_pid) == false + refute Process.alive?(client_pid) MLLP.Receiver.stop(port) - assert Process.alive?(receiver_pid) == false + refute Process.alive?(receiver_pid) end test "without a listener" do @@ -120,10 +120,10 @@ defmodule ClientAndReceiverIntegrationTest do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) assert Process.alive?(client_pid) - assert MLLP.Client.is_connected?(client_pid) == false + refute MLLP.Client.is_connected?(client_pid) capture_log(fn -> MLLP.Client.stop(client_pid) end) - assert Process.alive?(client_pid) == false + refute Process.alive?(client_pid) {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) @@ -137,23 +137,23 @@ defmodule ClientAndReceiverIntegrationTest do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) assert Process.alive?(client_pid) - assert MLLP.Client.is_connected?(client_pid) == false + refute MLLP.Client.is_connected?(client_pid) {:ok, %{pid: receiver_pid}} = MLLP.Receiver.start(port: port, dispatcher: MLLP.EchoDispatcher) assert Process.alive?(receiver_pid) - assert MLLP.Client.is_connected?(client_pid) == false + refute MLLP.Client.is_connected?(client_pid) MLLP.Client.reconnect(client_pid) assert MLLP.Client.is_connected?(client_pid) capture_log(fn -> MLLP.Client.stop(client_pid) end) - assert Process.alive?(client_pid) == false + refute Process.alive?(client_pid) MLLP.Receiver.stop(port) - assert Process.alive?(receiver_pid) == false + refute Process.alive?(receiver_pid) end test "with reconnecting" do @@ -162,18 +162,36 @@ defmodule ClientAndReceiverIntegrationTest do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) assert Process.alive?(client_pid) - assert MLLP.Client.is_connected?(client_pid) == false + refute MLLP.Client.is_connected?(client_pid) {:ok, %{pid: receiver_pid}} = MLLP.Receiver.start(port: port, dispatcher: MLLP.EchoDispatcher) assert Process.alive?(receiver_pid) - assert MLLP.Client.is_connected?(client_pid) == false + refute MLLP.Client.is_connected?(client_pid) MLLP.Client.reconnect(client_pid) assert MLLP.Client.is_connected?(client_pid) end + + test "detection of disconnected receiver" do + port = 8147 + + {:ok, %{pid: receiver_pid}} = + MLLP.Receiver.start(port: port, dispatcher: MLLP.EchoDispatcher) + + {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) + + assert MLLP.Client.is_connected?(client_pid) + + MLLP.Receiver.stop(port) + + refute MLLP.Client.is_connected?(client_pid) + + end + + end describe "Sending and receiving" do @@ -189,7 +207,7 @@ defmodule ClientAndReceiverIntegrationTest do assert {:error, ^exp_err} = MLLP.Client.send(client_pid, payload) capture_log(fn -> MLLP.Client.stop(client_pid) end) - assert Process.alive?(client_pid) == false + refute Process.alive?(client_pid) end test "with a receiver that stops before the send" do @@ -203,7 +221,7 @@ defmodule ClientAndReceiverIntegrationTest do assert MLLP.Client.is_connected?(client_pid) MLLP.Receiver.stop(port) - assert Process.alive?(receiver_pid) == false + refute Process.alive?(receiver_pid) assert match?( {:error, %Error{context: _, message: "connection closed"}}, From 34f9159f160a63ed97c89895f7f7aed4e2cd257b Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 27 Jun 2023 19:10:47 -0400 Subject: [PATCH 02/47] wip --- lib/mllp/client.ex | 120 +++++++++++++----- test/client_and_receiver_integration_test.exs | 3 - 2 files changed, 90 insertions(+), 33 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 0f86102..c0afb90 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -166,7 +166,9 @@ defmodule MLLP.Client do tls_opts: [], socket_opts: [], close_on_recv_error: true, - backoff: nil + backoff: nil, + caller: nil, + receive_buffer: nil alias __MODULE__, as: State @@ -258,7 +260,7 @@ defmodule MLLP.Client do Returns true if the connection is open and established, otherwise false. """ @spec is_connected?(pid :: pid()) :: boolean() - def is_connected?(pid), do: GenServer.call(pid, :is_connected) + def is_connected?(pid) when is_pid(pid), do: GenServer.call(pid, :is_connected) @doc """ Instructs the client to disconnect (if connected) and attempt a reconnect. @@ -366,7 +368,7 @@ defmodule MLLP.Client do end def handle_call(:is_connected, _reply, state) do - {:reply, (state.socket && !state.pending_reconnect) == true, state} + {:reply, connected?(state), state} end def handle_call(:reconnect, _from, state) do @@ -393,38 +395,16 @@ defmodule MLLP.Client do {:reply, {:error, err}, state} end - def handle_call({:send, message, options}, _from, state) do - options1 = Map.merge(state.send_opts, options) + def handle_call({:send, message, options}, from, state) do telemetry(:sending, %{}, state) payload = MLLP.Envelope.wrap_message(message) case state.tcp.send(state.socket, payload) do :ok -> - timeout = maybe_convert_time(options1.reply_timeout, :millisecond, :microsecond) - - case recv_ack(state, timeout) do - {:ok, reply} -> - {:reply, {:ok, reply}, state} - - {:error, reason} -> - telemetry( - :status, - %{ - status: :disconnected, - error: format_error(reason), - context: "receive ACK failure" - }, - state - ) - - new_state = - state - |> maybe_close() - |> maintain_reconnect_timer() - - reply = {:error, new_error(:recv, reason)} - {:reply, reply, new_state} - end + state + |> Map.put(:caller, from) + |> Map.put(:receive_buffer, <<>>) + |> receive_response(options) {:error, reason} -> telemetry( @@ -470,11 +450,58 @@ defmodule MLLP.Client do {:noreply, new_state} end + def handle_info({transport, socket, data}, %{socket: socket} = state) + when transport in [:tcp, :ssl] do + new_state = handle_received(data, state) + {:noreply, new_state} + end + + def handle_info({transport_closed, socket}, %{socket: socket} = state) + when transport_closed in [:tcp_closed, :ssl_closed] do + {:noreply, handle_closed(state)} + end + + def handle_info({transport_error, socket, reason}, %{socket: socket} = state) + when transport_error in [:tcp_error, :ssl_error] do + {:noreply, handle_error(reason, state)} + end + def handle_info(unknown, state) do Logger.warn("Unknown kernel message received => #{inspect(unknown)}") {:noreply, state} end + ## Handle the (fragmented) responses to `send` request from a caller + defp handle_received(reply, %{receive_buffer: buffer, caller: caller} = state) do + new_buf = (buffer && buffer <> reply) || reply + check = byte_size(new_buf) - 3 + + case new_buf do + <<@header, _ack::binary-size(check), @trailer>> -> + ## The response is completed, send back to caller + GenServer.reply(caller, {:ok, new_buf}) + Map.drop(state, [:caller, :receive_buffer]) + + <<@header, _rest::binary>> -> + Map.put(state, :receive_buffer, new_buf) + + _ -> + {:error, :invalid_reply} + end + end + + ## Handle receiver connection closed + defp handle_closed(state) do + :todo + state + end + + ## Handle transport errors + defp handle_error(reason, state) do + :todo + state + end + @doc false def terminate(reason = :normal, state) do Logger.debug("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") @@ -486,6 +513,10 @@ defmodule MLLP.Client do stop_connection(state, reason, "process terminated") end + defp connected?(%{socket: socket, pending_reconnect: pending_reconnect} = _state) do + socket && !pending_reconnect + end + defp maybe_convert_time(:infinity, _, _), do: :infinity defp maybe_convert_time(t, from, to) do @@ -500,6 +531,35 @@ defmodule MLLP.Client do defp maybe_close(state), do: state + defp receive_response(state, options) do + options1 = Map.merge(state.send_opts, options) + timeout = maybe_convert_time(options1.reply_timeout, :millisecond, :microsecond) + + case recv_ack(state, timeout) do + {:ok, reply} -> + {:reply, {:ok, reply}, state} + + {:error, reason} -> + telemetry( + :status, + %{ + status: :disconnected, + error: format_error(reason), + context: "receive ACK failure" + }, + state + ) + + new_state = + state + |> maybe_close() + |> maintain_reconnect_timer() + + reply = {:error, new_error(:recv, reason)} + {:reply, reply, new_state} + end + end + defp recv_ack(state, timeout) do recv_ack(state, {timeout, 0}, <<>>) end diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 66af59d..1e29843 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -188,10 +188,7 @@ defmodule ClientAndReceiverIntegrationTest do MLLP.Receiver.stop(port) refute MLLP.Client.is_connected?(client_pid) - end - - end describe "Sending and receiving" do From 8b6f9ffb57fb8e1919aad8c4f6a6b565f86adf46 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 28 Jun 2023 16:32:09 -0400 Subject: [PATCH 03/47] wip (6 failing tests, disconnection detection test passed) --- lib/mllp/client.ex | 65 +++++++++++++------ lib/mllp/receiver.ex | 5 ++ test/client_and_receiver_integration_test.exs | 4 +- test/client_test.exs | 22 +++---- 4 files changed, 64 insertions(+), 32 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index c0afb90..f764b18 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -55,10 +55,10 @@ defmodule MLLP.Client do Upon successful start up via `start_link/4`, the client will attempt to establish a connection to the given address on the provided port. If a connection can not be immediately established, the client will keep trying to establish a connection per the value of `:auto_reconnect_interval` which defaults to - 1 second. Therefor it is possible that before a connection is fully established, the caller + 1 second. Therefore it is possible that before a connection is fully established, the caller may attempt to send a message which will result in `MLLP.Client.Error.t()` being returned containing the last error encountered in trying to establish a connection. Additionally, said behavour could be encountered - at any point during life span of an MLLP.Client process if the connection becomees severed on either side. + at any point during life span of an MLLP.Client process if the connection becomes severed on either side. All connections, send, and receive failures will be logged as errors. @@ -236,7 +236,7 @@ defmodule MLLP.Client do client and a server. This functions similarly to the `:send_timeout` option provided by [`:gen_tcp`](`:gen_tcp`). Defaults to `true`. - * `:tls` - A list of tls options as supported by [`:ssl`](`:ssl`). When using TLS it is highly recommended you + * `:tls` - A list of tls options as supported by [`:ssl`](`:ssl`). When using TLS it is highly recommendeded you set `:verify` to `:verify_peer`, select a CA trust store using the `:cacertfile` or `:cacerts` options. Additionally, further hardening can be achieved through other ssl options such as enabling certificate revocation via the `:crl_check` and `:crl_cache` options and customization of @@ -363,8 +363,7 @@ defmodule MLLP.Client do @doc false def handle_continue(:init_socket, state) do - state1 = attempt_connection(state) - {:noreply, state1} + {:noreply, attempt_connection(state)} end def handle_call(:is_connected, _reply, state) do @@ -401,10 +400,7 @@ defmodule MLLP.Client do case state.tcp.send(state.socket, payload) do :ok -> - state - |> Map.put(:caller, from) - |> Map.put(:receive_buffer, <<>>) - |> receive_response(options) + {:noreply, Map.put(state, :caller, from)} {:error, reason} -> telemetry( @@ -472,34 +468,52 @@ defmodule MLLP.Client do end ## Handle the (fragmented) responses to `send` request from a caller - defp handle_received(reply, %{receive_buffer: buffer, caller: caller} = state) do + + defp handle_received(_reply, %{caller: nil} = state) do + ## No caller, ignore + state + end + + defp handle_received(reply, %{receive_buffer: buffer} = state) do new_buf = (buffer && buffer <> reply) || reply check = byte_size(new_buf) - 3 case new_buf do <<@header, _ack::binary-size(check), @trailer>> -> ## The response is completed, send back to caller - GenServer.reply(caller, {:ok, new_buf}) - Map.drop(state, [:caller, :receive_buffer]) + reply_to_caller({:ok, new_buf}, state) <<@header, _rest::binary>> -> Map.put(state, :receive_buffer, new_buf) _ -> - {:error, :invalid_reply} + reply_to_caller({:error, :invalid_reply}, state) end end - ## Handle receiver connection closed - defp handle_closed(state) do - :todo + defp reply_to_caller(reply, %{caller: caller} = state) do + caller && GenServer.reply(caller, reply) + state + |> Map.put(:caller, nil) + |> Map.put(:receive_buffer, nil) + end + + defp handle_closed(state) do + handle_error(:closed, state) end ## Handle transport errors defp handle_error(reason, state) do - :todo - state + reply_to_caller({:error, new_error(get_context(state), reason)}, state) + |> stop_connection(reason, "closing connection to cleanup") + |> tap(fn state -> + telemetry( + :status, + %{status: :disconnected, error: format_error(reason), context: "send message failure"}, + state + ) + end) end @doc false @@ -626,7 +640,9 @@ defmodule MLLP.Client do state.tcp.close(state.socket) end - ensure_pending_reconnect_cancelled(state) + state + |> Map.put(:socket, nil) + |> ensure_pending_reconnect_cancelled() end defp ensure_pending_reconnect_cancelled(%State{pending_reconnect: nil} = state), do: state @@ -645,10 +661,11 @@ defmodule MLLP.Client do defp attempt_connection(%State{} = state) do telemetry(:status, %{status: :connecting}, state) - opts = [:binary, {:packet, 0}, {:active, false}] ++ state.socket_opts ++ state.tls_opts + opts = [:binary, {:packet, 0}, {:active, :once}] ++ state.socket_opts ++ state.tls_opts case state.tcp.connect(state.address, state.port, opts, 2000) do {:ok, socket} -> + # :inet.setopts(socket, [{:active, :once}]) state1 = state |> ensure_pending_reconnect_cancelled() @@ -777,6 +794,14 @@ defmodule MLLP.Client do } end + defp get_context(%State{caller: caller}) when not is_nil(caller) do + :recv + end + + defp get_context(_state) do + :unknown + end + defp normalize_address!({_, _, _, _} = addr), do: addr defp normalize_address!({_, _, _, _, _, _, _, _} = addr), do: addr diff --git a/lib/mllp/receiver.ex b/lib/mllp/receiver.ex index 96c73f2..3d2f50e 100644 --- a/lib/mllp/receiver.ex +++ b/lib/mllp/receiver.ex @@ -362,6 +362,11 @@ defmodule MLLP.Receiver do {:noreply, state} end + def terminate(reason, %{transport: transport_mod, socket: socket} = state) do + Logger.error("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") + transport_mod.close(socket) + end + defp implements_behaviour?(mod, behaviour) do behaviours_found = Keyword.get_values(mod.__info__(:attributes), :behaviour) diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 1e29843..65d0509 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -26,7 +26,7 @@ defmodule ClientAndReceiverIntegrationTest do [ack: ack, port: port, transport_opts: transport_opts, allowed_clients: allowed_clients] end - describe "Supervsion" do + describe "Supervision" do test "successfully starts up under a supervisor using a child spec" do port = 8999 transport_opts = %{num_acceptors: 1, max_connections: 1, socket_opts: [delay_send: true]} @@ -185,7 +185,9 @@ defmodule ClientAndReceiverIntegrationTest do assert MLLP.Client.is_connected?(client_pid) + # Process.exit(receiver_pid, :kill) MLLP.Receiver.stop(port) + :timer.sleep(10) refute MLLP.Client.is_connected?(client_pid) end diff --git a/test/client_test.exs b/test/client_test.exs index ff98eb8..177d9ed 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -147,7 +147,7 @@ defmodule ClientTest do [ :binary, {:packet, 0}, - {:active, false}, + {:active, :once}, {:send_timeout, 60_000} ], 2000 -> @@ -170,7 +170,7 @@ defmodule ClientTest do [ :binary, {:packet, 0}, - {:active, false}, + {:active, :once}, {:send_timeout, 60_000} ], 2000 -> @@ -216,7 +216,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -254,7 +254,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -310,7 +310,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -362,7 +362,7 @@ defmodule ClientTest do [ :binary, {:packet, 0}, - {:active, false}, + {:active, :once}, {:send_timeout, 60_000} ], 2000 -> @@ -400,7 +400,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -426,7 +426,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -459,7 +459,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -484,7 +484,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -509,7 +509,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, false}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end From 41d0bb9db40cb406ddb5b0d819af2f3044d7fdd4 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Thu, 29 Jun 2023 22:15:05 -0400 Subject: [PATCH 04/47] wip (recv timeout) --- lib/mllp/client.ex | 199 ++++++------------ test/client_and_receiver_integration_test.exs | 2 +- test/client_test.exs | 24 ++- 3 files changed, 84 insertions(+), 141 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index f764b18..6fa9bcb 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -148,7 +148,10 @@ defmodule MLLP.Client do tls_opts: Keyword.t(), socket_opts: Keyword.t(), close_on_recv_error: boolean(), - backoff: any() + backoff: any(), + caller: pid() | nil, + receive_buffer: binary() | nil, + reply_timer: reference() } defstruct socket: nil, @@ -168,7 +171,8 @@ defmodule MLLP.Client do close_on_recv_error: true, backoff: nil, caller: nil, - receive_buffer: nil + receive_buffer: nil, + reply_timer: nil alias __MODULE__, as: State @@ -379,39 +383,39 @@ defmodule MLLP.Client do {:reply, :ok, new_state} end - def handle_call(_msg, _from, %State{socket: nil} = state) do - telemetry( - :status, - %{ - status: :disconnected, - error: :no_socket, - context: "MLLP.Client disconnected failure" - }, - state - ) - - err = new_error(:connect, state.connect_failure) - {:reply, {:error, err}, state} - end - def handle_call({:send, message, options}, from, state) do telemetry(:sending, %{}, state) - payload = MLLP.Envelope.wrap_message(message) - - case state.tcp.send(state.socket, payload) do - :ok -> - {:noreply, Map.put(state, :caller, from)} - - {:error, reason} -> - telemetry( - :status, - %{status: :disconnected, error: format_error(reason), context: "send message failure"}, - state - ) - - new_state = maintain_reconnect_timer(state) - reply = {:error, new_error(:send, reason)} - {:reply, reply, new_state} + Logger.error("--------------Sending....") + + if connected?(state) do + payload = MLLP.Envelope.wrap_message(message) + + case state.tcp.send(state.socket, payload) do + :ok -> + reply_timeout = Map.get(options, :reply_timeout, state.send_opts.reply_timeout) + + {:noreply, + state + |> Map.put(:caller, from) + |> Map.put(:reply_timer, Process.send_after(self(), :reply_timeout, reply_timeout))} + + {:error, reason} -> + telemetry( + :status, + %{ + status: :disconnected, + error: format_error(reason), + context: "send message failure" + }, + state + ) + + new_state = maintain_reconnect_timer(state) + reply = {:error, new_error(:send, reason)} + {:reply, reply, new_state} + end + else + {:reply, {:error, new_error(:send, :closed)}, state} end end @@ -436,6 +440,21 @@ defmodule MLLP.Client do end end + def handle_call(_msg, _from, %State{socket: nil} = state) do + telemetry( + :status, + %{ + status: :disconnected, + error: :no_socket, + context: "MLLP.Client disconnected failure" + }, + state + ) + + err = new_error(:connect, state.connect_failure) + {:reply, {:error, err}, state} + end + @doc false def handle_info(:timeout, state) do new_state = @@ -446,6 +465,11 @@ defmodule MLLP.Client do {:noreply, new_state} end + def handle_info(:reply_timeout, state) do + {:noreply, + reply_to_caller({:error, :timeout}, state)} + end + def handle_info({transport, socket, data}, %{socket: socket} = state) when transport in [:tcp, :ssl] do new_state = handle_received(data, state) @@ -493,10 +517,7 @@ defmodule MLLP.Client do defp reply_to_caller(reply, %{caller: caller} = state) do caller && GenServer.reply(caller, reply) - - state - |> Map.put(:caller, nil) - |> Map.put(:receive_buffer, nil) + reply_cleanup(state) end defp handle_closed(state) do @@ -505,6 +526,8 @@ defmodule MLLP.Client do ## Handle transport errors defp handle_error(reason, state) do + Logger.error("Error: #{inspect(reason)}, state: #{inspect(state)}") + reply_to_caller({:error, new_error(get_context(state), reason)}, state) |> stop_connection(reason, "closing connection to cleanup") |> tap(fn state -> @@ -516,6 +539,15 @@ defmodule MLLP.Client do end) end + defp reply_cleanup(%State{reply_timer: reply_timer} = state) do + reply_timer && Process.cancel_timer(reply_timer) + + state + |> Map.put(:caller, nil) + |> Map.put(:receive_buffer, nil) + |> Map.put(:reply_timer, nil) + end + @doc false def terminate(reason = :normal, state) do Logger.debug("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") @@ -531,12 +563,6 @@ defmodule MLLP.Client do socket && !pending_reconnect end - defp maybe_convert_time(:infinity, _, _), do: :infinity - - defp maybe_convert_time(t, from, to) do - System.convert_time_unit(t, from, to) - end - defp maybe_close(%{close_on_recv_error: true} = state) do state |> stop_connection(:timeout, "recv error, closing connection to cleanup") @@ -545,90 +571,6 @@ defmodule MLLP.Client do defp maybe_close(state), do: state - defp receive_response(state, options) do - options1 = Map.merge(state.send_opts, options) - timeout = maybe_convert_time(options1.reply_timeout, :millisecond, :microsecond) - - case recv_ack(state, timeout) do - {:ok, reply} -> - {:reply, {:ok, reply}, state} - - {:error, reason} -> - telemetry( - :status, - %{ - status: :disconnected, - error: format_error(reason), - context: "receive ACK failure" - }, - state - ) - - new_state = - state - |> maybe_close() - |> maintain_reconnect_timer() - - reply = {:error, new_error(:recv, reason)} - {:reply, reply, new_state} - end - end - - defp recv_ack(state, timeout) do - recv_ack(state, {timeout, 0}, <<>>) - end - - defp recv_ack(_state, {time_left, time_owed}, _buffer) - when is_integer(time_left) and time_left <= time_owed do - {:error, :timeout} - end - - defp recv_ack(state, {time_left, time_owed}, buffer) do - {res, elapsed} = do_recv(state, 0, time_left) - - case res do - {:ok, reply} -> - new_buf = buffer <> reply - check = byte_size(new_buf) - 3 - - case new_buf do - <<@header, _ack::binary-size(check), @trailer>> -> - {:ok, new_buf} - - <<@header, _rest::binary>> -> - time_credit = update_recv_time_credit(time_left, time_owed + elapsed) - recv_ack(state, time_credit, new_buf) - - _ -> - {:error, :invalid_reply} - end - - {:error, _} = err -> - err - end - end - - defp do_recv(state, length, :infinity) do - res = state.tcp.recv(state.socket, length, :infinity) - {res, 0} - end - - defp do_recv(state, length, timeout) do - timeout_in_ms = System.convert_time_unit(timeout, :microsecond, :millisecond) - t1 = System.monotonic_time(:microsecond) - res = state.tcp.recv(state.socket, length, timeout_in_ms) - t2 = System.monotonic_time(:microsecond) - {res, t2 - t1} - end - - defp update_recv_time_credit(:infinity, _), do: {:infinity, 0} - - defp update_recv_time_credit(time_left, time_spent) do - time_charged = div(time_spent, 1000) * 1000 - time_owed = time_spent - time_charged - {time_left - time_charged, time_owed} - end - defp stop_connection(%State{} = state, error, context) do if state.socket != nil do telemetry( @@ -661,11 +603,10 @@ defmodule MLLP.Client do defp attempt_connection(%State{} = state) do telemetry(:status, %{status: :connecting}, state) - opts = [:binary, {:packet, 0}, {:active, :once}] ++ state.socket_opts ++ state.tls_opts + opts = [:binary, {:packet, 0}, {:active, true}] ++ state.socket_opts ++ state.tls_opts case state.tcp.connect(state.address, state.port, opts, 2000) do {:ok, socket} -> - # :inet.setopts(socket, [{:active, :once}]) state1 = state |> ensure_pending_reconnect_cancelled() diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 65d0509..a7ca8b0 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -127,7 +127,7 @@ defmodule ClientAndReceiverIntegrationTest do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) - exp_err = %Error{context: :connect, reason: :econnrefused, message: "connection refused"} + exp_err = %Error{context: :send, reason: :closed, message: "connection closed"} assert {:error, ^exp_err} = MLLP.Client.send(client_pid, "Eh?") end diff --git a/test/client_test.exs b/test/client_test.exs index 177d9ed..ccc9a8c 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -147,7 +147,7 @@ defmodule ClientTest do [ :binary, {:packet, 0}, - {:active, :once}, + {:active, true}, {:send_timeout, 60_000} ], 2000 -> @@ -170,7 +170,7 @@ defmodule ClientTest do [ :binary, {:packet, 0}, - {:active, :once}, + {:active, true}, {:send_timeout, 60_000} ], 2000 -> @@ -254,7 +254,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -310,7 +310,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -362,7 +362,7 @@ defmodule ClientTest do [ :binary, {:packet, 0}, - {:active, :once}, + {:active, true}, {:send_timeout, 60_000} ], 2000 -> @@ -400,15 +400,17 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end ) |> expect(:send, fn ^socket, ^packet -> :ok end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, MLLP.Envelope.wrap_message("NACK")} end) + + # |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, MLLP.Envelope.wrap_message("NACK")} end) {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock) + assert Client.is_connected?(client) assert {:ok, "NACK"} = Client.send(client, message) end @@ -426,7 +428,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -459,7 +461,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -484,7 +486,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end @@ -509,7 +511,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end From 2552fcf839a7651f5f2dff8bce3b9c2505dc0a33 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Fri, 30 Jun 2023 19:12:38 -0400 Subject: [PATCH 05/47] Minor --- test/client_test.exs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/client_test.exs b/test/client_test.exs index ccc9a8c..198cd64 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -216,7 +216,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, :once}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, active}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end From 613d6659298ddad5fc4648d19330d9763c022a77 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sat, 1 Jul 2023 10:12:11 -0400 Subject: [PATCH 06/47] Changes to test cases --- lib/mllp/client.ex | 5 ++--- lib/mllp/receiver.ex | 5 ----- test/client_and_receiver_integration_test.exs | 9 ++++----- test/client_test.exs | 2 +- 4 files changed, 7 insertions(+), 14 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 6fa9bcb..886c3bc 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -415,7 +415,7 @@ defmodule MLLP.Client do {:reply, reply, new_state} end else - {:reply, {:error, new_error(:send, :closed)}, state} + {:reply, {:error, new_error(:send, state.connect_failure)}, state} end end @@ -466,8 +466,7 @@ defmodule MLLP.Client do end def handle_info(:reply_timeout, state) do - {:noreply, - reply_to_caller({:error, :timeout}, state)} + {:noreply, reply_to_caller({:error, :timeout}, state)} end def handle_info({transport, socket, data}, %{socket: socket} = state) diff --git a/lib/mllp/receiver.ex b/lib/mllp/receiver.ex index 3d2f50e..96c73f2 100644 --- a/lib/mllp/receiver.ex +++ b/lib/mllp/receiver.ex @@ -362,11 +362,6 @@ defmodule MLLP.Receiver do {:noreply, state} end - def terminate(reason, %{transport: transport_mod, socket: socket} = state) do - Logger.error("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") - transport_mod.close(socket) - end - defp implements_behaviour?(mod, behaviour) do behaviours_found = Keyword.get_values(mod.__info__(:attributes), :behaviour) diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index a7ca8b0..02454d3 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -127,7 +127,7 @@ defmodule ClientAndReceiverIntegrationTest do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) - exp_err = %Error{context: :send, reason: :closed, message: "connection closed"} + exp_err = %Error{context: :send, reason: :econnrefused, message: "connection refused"} assert {:error, ^exp_err} = MLLP.Client.send(client_pid, "Eh?") end @@ -178,14 +178,13 @@ defmodule ClientAndReceiverIntegrationTest do test "detection of disconnected receiver" do port = 8147 - {:ok, %{pid: receiver_pid}} = + {:ok, %{pid: _receiver_pid}} = MLLP.Receiver.start(port: port, dispatcher: MLLP.EchoDispatcher) {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) assert MLLP.Client.is_connected?(client_pid) - # Process.exit(receiver_pid, :kill) MLLP.Receiver.stop(port) :timer.sleep(10) @@ -202,7 +201,7 @@ defmodule ClientAndReceiverIntegrationTest do payload = "A simple message" - exp_err = %Error{context: :connect, reason: :econnrefused, message: "connection refused"} + exp_err = %Error{context: :send, reason: :econnrefused, message: "connection refused"} assert {:error, ^exp_err} = MLLP.Client.send(client_pid, payload) capture_log(fn -> MLLP.Client.stop(client_pid) end) @@ -349,7 +348,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: :connect}} = + assert {:error, %Error{reason: {:tls_alert, {:handshake_failure, _}}, context: :send}} = MLLP.Client.send( client_pid, HL7.Examples.wikipedia_sample_hl7() |> HL7.Message.new() diff --git a/test/client_test.exs b/test/client_test.exs index 198cd64..593c81f 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -216,7 +216,7 @@ defmodule ClientTest do :connect, fn ^address, ^port, - [:binary, {:packet, 0}, {:active, active}, {:send_timeout, 60_000}], + [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], 2000 -> {:ok, socket} end From 69a6530a18d13d79ff452976fb3be74a8d206e13 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sun, 2 Jul 2023 18:37:49 -0400 Subject: [PATCH 07/47] Store context in state --- lib/mllp/client.ex | 34 ++++++++++++++++++++++------------ 1 file changed, 22 insertions(+), 12 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 886c3bc..7e36d1c 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -151,7 +151,8 @@ defmodule MLLP.Client do backoff: any(), caller: pid() | nil, receive_buffer: binary() | nil, - reply_timer: reference() + reply_timer: reference(), + context: atom() } defstruct socket: nil, @@ -172,7 +173,8 @@ defmodule MLLP.Client do backoff: nil, caller: nil, receive_buffer: nil, - reply_timer: nil + reply_timer: nil, + context: :connect alias __MODULE__, as: State @@ -385,7 +387,6 @@ defmodule MLLP.Client do def handle_call({:send, message, options}, from, state) do telemetry(:sending, %{}, state) - Logger.error("--------------Sending....") if connected?(state) do payload = MLLP.Envelope.wrap_message(message) @@ -396,6 +397,7 @@ defmodule MLLP.Client do {:noreply, state + |> Map.put(:context, :recv) |> Map.put(:caller, from) |> Map.put(:reply_timer, Process.send_after(self(), :reply_timeout, reply_timeout))} @@ -425,7 +427,7 @@ defmodule MLLP.Client do case state.tcp.send(state.socket, payload) do :ok -> - {:reply, {:ok, :sent}, state} + {:reply, {:ok, :sent}, Map.put(state, :context, :recv)} {:error, reason} -> telemetry( @@ -514,11 +516,19 @@ defmodule MLLP.Client do end end - defp reply_to_caller(reply, %{caller: caller} = state) do - caller && GenServer.reply(caller, reply) + defp reply_to_caller(reply, %{caller: caller, context: context} = state) do + caller && GenServer.reply(caller, format_reply(reply, context)) reply_cleanup(state) end + defp format_reply({:ok, result}, _context) do + {:ok, result} + end + + defp format_reply({:error, error}, context) do + {:error, new_error(context, error)} + end + defp handle_closed(state) do handle_error(:closed, state) end @@ -726,6 +736,10 @@ defmodule MLLP.Client do Ack.verify_ack_against_message(unwrapped_message, ack) end + defp new_error(context, %MLLP.Client.Error{} = error) do + Map.put(error, :context, context) + end + defp new_error(context, error) do %MLLP.Client.Error{ reason: error, @@ -734,12 +748,8 @@ defmodule MLLP.Client do } end - defp get_context(%State{caller: caller}) when not is_nil(caller) do - :recv - end - - defp get_context(_state) do - :unknown + defp get_context(%State{context: context}) do + (context && context) || :unknown end defp normalize_address!({_, _, _, _} = addr), do: addr From 29a5056c4d06dc0e68ffe8c71a69a21c1236a8d0 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sun, 2 Jul 2023 19:02:53 -0400 Subject: [PATCH 08/47] Call maybe_close on tcp_error --- lib/mllp/client.ex | 8 ++++---- test/client_test.exs | 20 -------------------- 2 files changed, 4 insertions(+), 24 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 7e36d1c..883db65 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -484,7 +484,7 @@ defmodule MLLP.Client do def handle_info({transport_error, socket, reason}, %{socket: socket} = state) when transport_error in [:tcp_error, :ssl_error] do - {:noreply, handle_error(reason, state)} + {:noreply, handle_error(reason, maybe_close(reason, state))} end def handle_info(unknown, state) do @@ -572,13 +572,13 @@ defmodule MLLP.Client do socket && !pending_reconnect end - defp maybe_close(%{close_on_recv_error: true} = state) do + defp maybe_close(reason, %{close_on_recv_error: true, context: context} = state) do state - |> stop_connection(:timeout, "recv error, closing connection to cleanup") + |> stop_connection(reason, context) |> attempt_connection() end - defp maybe_close(state), do: state + defp maybe_close(_reason, state), do: state defp stop_connection(%State{} = state, error, context) do if state.socket != nil do diff --git a/test/client_test.exs b/test/client_test.exs index 593c81f..7a6e4d7 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -222,7 +222,6 @@ defmodule ClientTest do end ) |> expect(:send, fn ^socket, ^packet -> :ok end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, tcp_reply} end) {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) @@ -260,8 +259,6 @@ defmodule ClientTest do end ) |> expect(:send, fn ^socket, ^packet -> :ok end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, ack_frag1} end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, ack_frag2} end) {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) @@ -278,9 +275,6 @@ defmodule ClientTest do MLLP.TCPMock |> expect(:send, fn ^socket, ^packet -> :ok end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, ack_frag1} end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, ack_frag2} end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, ack_frag3} end) assert( {:ok, :application_accept, expected_ack} == @@ -316,16 +310,6 @@ defmodule ClientTest do end ) |> expect(:send, fn ^socket, ^packet -> :ok end) - |> expect(:recv, fn ^socket, 0, _ -> - Process.sleep(1) - {:ok, ack_frag1} - end) - |> expect(:recv, fn ^socket, 0, _ -> - Process.sleep(1) - {:ok, ack_frag2} - end) - |> expect(:close, fn ^socket -> :ok end) - |> expect(:connect, fn _, _, _, _ -> {:ok, socket} end) {:ok, client} = Client.start_link(address, port, @@ -370,8 +354,6 @@ defmodule ClientTest do end ) |> expect(:send, fn ^socket, ^packet -> :ok end) - |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, tcp_reply1} end) - |> expect(:close, fn ^socket -> :ok end) {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) @@ -407,8 +389,6 @@ defmodule ClientTest do ) |> expect(:send, fn ^socket, ^packet -> :ok end) - # |> expect(:recv, fn ^socket, 0, 60_000 -> {:ok, MLLP.Envelope.wrap_message("NACK")} end) - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock) assert Client.is_connected?(client) From 0e76b1fd9a28e8725faa08b7c47f1264ece8be0a Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 5 Jul 2023 09:28:25 -0400 Subject: [PATCH 09/47] Replace some mock tests with real ones --- test/client_test.exs | 135 +++++++++++++++---------------------------- 1 file changed, 48 insertions(+), 87 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index 7a6e4d7..908568f 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -10,6 +10,8 @@ defmodule ClientTest do setup :verify_on_exit! setup :set_mox_global + @default_port 4090 + setup do attach_telemetry() on_exit(fn -> detach_telemetry() end) @@ -198,45 +200,29 @@ defmodule ClientTest do end describe "send/2" do - test "with valid HL7 returns an AA" do + setup do address = {127, 0, 0, 1} port = 4090 - socket = make_ref() - raw_hl7 = HL7.Examples.wikipedia_sample_hl7() - message = HL7.Message.new(raw_hl7) - packet = MLLP.Envelope.wrap_message(raw_hl7) - - tcp_reply = - MLLP.Envelope.wrap_message( - "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|01052901|P|2.5\rMSA|AA|01052901|You win!\r" - ) - - MLLP.TCPMock - |> expect( - :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> - {:ok, socket} - end - ) - |> expect(:send, fn ^socket, ^packet -> :ok end) + {:ok, _receiver} = MLLP.Receiver.start(port: port, dispatcher: ClientTest.TestDispatcher) + {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCP) + on_exit(fn -> MLLP.Receiver.stop(port); Process.sleep(100); Process.exit(client, :kill) end) + %{client: client} + end - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) + test "with valid HL7 returns an AA", ctx do - expected_ack = %MLLP.Ack{acknowledgement_code: "AA", text_message: "You win!"} + raw_hl7 = HL7.Examples.wikipedia_sample_hl7() + message = HL7.Message.new(raw_hl7) + expected_ack = %MLLP.Ack{acknowledgement_code: "AA", text_message: ""} assert( {:ok, :application_accept, expected_ack} == - Client.send(client, message) + Client.send(ctx.client, message, %{reply_timeout: 1000}) ) + end - test "when replies are fragmented" do - address = {127, 0, 0, 1} - port = 4090 - socket = make_ref() + test "when replies are fragmented", ctx do raw_hl7 = HL7.Examples.wikipedia_sample_hl7() message = HL7.Message.new(raw_hl7) packet = MLLP.Envelope.wrap_message(raw_hl7) @@ -247,38 +233,21 @@ defmodule ClientTest do ) {ack_frag1, ack_frag2} = String.split_at(tcp_reply1, 50) - - MLLP.TCPMock - |> expect( - :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> - {:ok, socket} - end - ) - |> expect(:send, fn ^socket, ^packet -> :ok end) - - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) - - expected_ack = %MLLP.Ack{acknowledgement_code: "AA", text_message: "You win!"} + expected_ack = %MLLP.Ack{acknowledgement_code: "AA", text_message: ""} assert( {:ok, :application_accept, expected_ack} == - Client.send(client, message) + Client.send(ctx.client, message) ) {ack_frag1, ack_frag2} = String.split_at(tcp_reply1, 50) {ack_frag2, ack_frag3} = String.split_at(ack_frag2, 10) - MLLP.TCPMock - |> expect(:send, fn ^socket, ^packet -> :ok end) assert( {:ok, :application_accept, expected_ack} == - Client.send(client, message) + Client.send(ctx.client, message) ) end @@ -326,10 +295,7 @@ defmodule ClientTest do ) end - test "when reply header is invalid" do - address = {127, 0, 0, 1} - port = 4090 - socket = make_ref() + test "when reply header is invalid", ctx do raw_hl7 = HL7.Examples.wikipedia_sample_hl7() message = HL7.Message.new(raw_hl7) packet = MLLP.Envelope.wrap_message(raw_hl7) @@ -337,25 +303,6 @@ defmodule ClientTest do tcp_reply1 = "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|01052901|P|2.5\rMSA|AA|01052901|You win!\r" - MLLP.TCPMock - |> expect( - :connect, - 2, - fn ^address, - ^port, - [ - :binary, - {:packet, 0}, - {:active, true}, - {:send_timeout, 60_000} - ], - 2000 -> - {:ok, socket} - end - ) - |> expect(:send, fn ^socket, ^packet -> :ok end) - - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) expected_err = %MLLP.Client.Error{ context: :recv, @@ -365,7 +312,7 @@ defmodule ClientTest do assert( {:error, expected_err} == - Client.send(client, message) + Client.send(ctx.client, tcp_reply1) ) end @@ -375,21 +322,8 @@ defmodule ClientTest do socket = make_ref() message = "Hello, it's me" - packet = MLLP.Envelope.wrap_message(message) - - MLLP.TCPMock - |> expect( - :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> - {:ok, socket} - end - ) - |> expect(:send, fn ^socket, ^packet -> :ok end) - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock) + {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCP) assert Client.is_connected?(client) assert {:ok, "NACK"} = Client.send(client, message) @@ -552,4 +486,31 @@ defmodule ClientTest do defp detach_telemetry() do :telemetry.detach("telemetry_events") end + + defmodule TestDispatcher do + require Logger + + @behaviour MLLP.Dispatcher + + def dispatch(:mllp_hl7, <<"MSH|NOREPLY", _rest::binary>>, state) do + {:ok, %{state | reply_buffer: ""}} + end + + def dispatch(:mllp_hl7, message, state) when is_binary(message) do + reply = + MLLP.Ack.get_ack_for_message( + message, + :application_accept + ) + |> to_string() + |> MLLP.Envelope.wrap_message() + + {:ok, %{state | reply_buffer: reply}} + end + + def dispatch(non_hl7_type, message, state) do + {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message("NACK")}} + end + end + end From 093767b98cf0d332a71915ef572afb12d108072b Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 5 Jul 2023 17:42:41 -0400 Subject: [PATCH 10/47] Make sure socket is invalidated on reconnection --- lib/mllp/client.ex | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 883db65..695b5c6 100755 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -646,7 +646,7 @@ defmodule MLLP.Client do defp maintain_reconnect_timer(%{backoff: nil} = state) do ref = Process.send_after(self(), :timeout, state.auto_reconnect_interval) - %State{state | pending_reconnect: ref} + %State{state | socket: nil, pending_reconnect: ref} end defp maintain_reconnect_timer(%{backoff: backoff} = state) do @@ -658,7 +658,7 @@ defmodule MLLP.Client do ref = Process.send_after(self(), :timeout, seconds) {_, new_backoff} = :backoff.fail(backoff) - %State{state | pending_reconnect: ref, backoff: new_backoff} + %State{state | socket: nil, pending_reconnect: ref, backoff: new_backoff} end defp telemetry(_event_name, _measurements, %State{telemetry_module: nil} = _metadata) do From d68353fecf7e8ce35fb74c8368a0a178dfcd6f41 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Thu, 6 Jul 2023 18:54:31 -0400 Subject: [PATCH 11/47] Switching to gen_statem (wip) --- lib/mllp/client/client_fsm.ex | 731 ++++++++++++++++++++++++++++++++++ mix.exs | 5 +- mix.lock | 5 + 3 files changed, 740 insertions(+), 1 deletion(-) create mode 100644 lib/mllp/client/client_fsm.ex diff --git a/lib/mllp/client/client_fsm.ex b/lib/mllp/client/client_fsm.ex new file mode 100644 index 0000000..9995d68 --- /dev/null +++ b/lib/mllp/client/client_fsm.ex @@ -0,0 +1,731 @@ +defmodule MLLP.Client.FSM do + @moduledoc """ + MLLP.Client provides a simple tcp client for sending and receiving data + via [MLLP](https://www.hl7.org/documentcenter/public/wg/inm/mllp_transport_specification.PDF) over TCP. + + While MLLP is primarily used to send [HL7](https://en.wikipedia.org/wiki/Health_Level_7) messages, + MLLP.Client can be used to send non-hl7 messages, such as XML. + + ## Connection Behaviour + + Upon successful start up via `start_link/4`, the client will attempt to establish a connection to the given address + on the provided port. If a connection can not be immediately established, the client will keep + trying to establish a connection per the value of `:auto_reconnect_interval` which defaults to + 1 second. Therefore it is possible that before a connection is fully established, the caller + may attempt to send a message which will result in `MLLP.Client.Error.t()` being returned containing + the last error encountered in trying to establish a connection. Additionally, said behavour could be encountered + at any point during life span of an MLLP.Client process if the connection becomes severed on either side. + + All connections, send, and receive failures will be logged as errors. + + ## Examples + + ### Sending messages as strings + ``` + iex> MLLP.Receiver.start(dispatcher: MLLP.EchoDispatcher, port: 4090) + {:ok, + %{ + pid: #PID<0.2167.0>, + port: 4090, + receiver_id: #Reference<0.3312799297.2467299337.218126> + }} + iex> {:ok, client} = MLLP.Client.start_link("127.0.0.1", 4090) + {:ok, #PID<0.369.0>} + iex> msg = "MSH|^~\\&|MegaReg|XYZHospC|SuperOE|XYZImgCtr|20060529090131-0500|..." + "MSH|^~\\&|MegaReg|XYZHospC|SuperOE|XYZImgCtr|20060529090131-0500|..." + iex> MLLP.Client.send(client, msg) + {:ok, "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^A01^ACK|..."} + iex> + ``` + + ### Sending messages with `HL7.Message.t()` + ``` + iex> MLLP.Receiver.start(dispatcher: MLLP.EchoDispatcher, port: 4090) + {:ok, + %{ + pid: #PID<0.2167.0>, + port: 4090, + receiver_id: #Reference<0.3312799297.2467299337.218126> + }} + iex> {:ok, client} = MLLP.Client.start_link("127.0.0.1", 4090) + {:ok, #PID<0.369.0>} + iex> msg = HL7.Message.new(HL7.Examples.wikipedia_sample_hl7()) + iex> MLLP.Client.send(client, msg) + {:ok, :application_accept, + %MLLP.Ack{ + acknowledgement_code: "AA", + hl7_ack_message: nil, + text_message: "A real MLLP message dispatcher was not provided" + }} + ``` + + ### Using TLS + + ``` + iex> tls_opts = [ + cacertfile: "/path/to/ca_certificate.pem", + verify: :verify_peer, + certfile: "/path/to/server_certificate.pem", + keyfile: "/path/to/private_key.pem" + ] + iex> MLLP.Receiver.start(dispatcher: MLLP.EchoDispatcher, port: 4090, tls: tls_opts) + iex> {:ok, client} = MLLP.Client.start_link("localhost", 8154, tls: [verify: :verify_peer, cacertfile: "path/to/ca_certfile.pem"]) + iex> msg = HL7.Message.new(HL7.Examples.wikipedia_sample_hl7()) + iex> MLLP.Client.send(client, msg) + {:ok, :application_accept, + %MLLP.Ack{ + acknowledgement_code: "AA", + hl7_ack_message: nil, + text_message: "A real MLLP message dispatcher was not provided" + }} + ``` + """ + + require Logger + + alias MLLP.{Envelope, Ack, ClientContract, TCP, TLS} + + @behaviour MLLP.ClientContract + + use GenStateMachine, callback_mode: [:state_functions, :state_enter] + + @type pid_ref :: atom | pid | {atom, any} | {:via, atom, any} + @type ip_address :: :inet.socket_address() | String.t() + + @type t :: %MLLP.Client.FSM{ + socket: any(), + socket_address: String.t(), + address: ip_address(), + port: char(), + auto_reconnect_interval: non_neg_integer(), + pid: pid() | nil, + telemetry_module: module() | nil, + tcp: module() | nil, + tls_opts: Keyword.t(), + socket_opts: Keyword.t(), + close_on_recv_error: boolean(), + backoff: any(), + caller: pid() | nil, + receive_buffer: binary() | nil, + context: atom() + } + + defstruct socket: nil, + socket_address: "127.0.0.1:0", + auto_reconnect_interval: 1000, + address: {127, 0, 0, 1}, + port: 0, + pid: nil, + telemetry_module: nil, + tcp: nil, + connect_failure: nil, + host_string: nil, + send_opts: %{}, + tls_opts: [], + socket_opts: [], + close_on_recv_error: true, + backoff: nil, + caller: nil, + receive_buffer: nil, + context: :connect + + alias __MODULE__, as: State + + ## API + @doc false + @spec format_error(term()) :: String.t() + def format_error({:tls_alert, _} = err) do + to_string(:ssl.format_error({:error, err})) + end + + def format_error(:closed), do: "connection closed" + def format_error(:timeout), do: "timed out" + def format_error(:system_limit), do: "all available erlang emulator ports in use" + + def format_error(:invalid_reply) do + "Invalid header received in server acknowledgment" + 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) + end + end + + def format_error(err) when is_binary(err), do: err + + def format_error(err), do: inspect(err) + + @doc """ + Starts a new MLLP.Client. + + MLLP.Client.start_link/4 will start a new MLLP.Client process. + + This function will raise a `ArgumentError` if an invalid `ip_address()` is provided. + + ## Options + + * `:use_backoff` - Specify if an exponential backoff should be used for connection. When an attempt + to establish a connection fails, either post-init or at some point during the life span of the client, + the backoff value will determine how often to retry a reconnection. Starts at 1 second and increases + exponentially until reaching `backoff_max_seconds` seconds. Defaults to `true`. + + * `:backoff_max_seconds` - Specify the max limit of seconds the backoff reconection attempt should take, + defauls to 180 (3 mins). + + * `:auto_reconnect_interval` - Specify the interval between connection attempts. Specifically, if an attempt + to establish a connection fails, either post-init or at some point during the life span of the client, the value + of this option shall determine how often to retry a reconnection. Defaults to 1000 milliseconds. + This option will only be used if `use_backoff` is set to `false`. + + * `:reply_timeout` - Optionally specify a timeout value for receiving a response. Must be a positive integer or + `:infinity`. Defaults to 60 seconds. + + * `:socket_opts` - A list of socket options as supported by [`:gen_tcp`](`:gen_tcp`). + Note that `:binary`, `:packet`, and `:active` can not be overridden. Default options are enumerated below. + - send_timeout: Defaults to 60 seconds + + * `:close_on_recv_error` - A boolean value which dictates whether the client socket will be + closed when an error in receiving a reply is encountered, this includes timeouts. + Setting this to `true` is usually the safest behaviour to avoid a "dead lock" situation between a + client and a server. This functions similarly to the `:send_timeout` option provided by + [`:gen_tcp`](`:gen_tcp`). Defaults to `true`. + + * `:tls` - A list of tls options as supported by [`:ssl`](`:ssl`). When using TLS it is highly recommendeded you + set `:verify` to `:verify_peer`, select a CA trust store using the `:cacertfile` or `:cacerts` options. + Additionally, further hardening can be achieved through other ssl options such as enabling + certificate revocation via the `:crl_check` and `:crl_cache` options and customization of + enabled protocols and cipher suites for your specific use-case. See [`:ssl`](`:ssl`) for details. + + """ + @spec start_link( + address :: ip_address(), + port :: :inet.port_number(), + options :: ClientContract.options() + ) :: {:ok, pid()} + + def start_link(address, port, options \\ []) do + GenStateMachine.start_link( + __MODULE__, + [address: normalize_address!(address), port: port] ++ options + ) + end + + @doc """ + Returns true if the connection is open and established, otherwise false. + """ + @spec is_connected?(pid :: pid()) :: boolean() + def is_connected?(pid) when is_pid(pid), do: GenStateMachine.call(pid, :is_connected) + + @doc """ + Instructs the client to disconnect (if connected) and attempt a reconnect. + """ + @spec reconnect(pid :: pid()) :: :ok + def reconnect(pid), do: GenStateMachine.call(pid, :reconnect) + + @doc """ + Sends a message and receives a response. + + send/4 supports both `HL7.Message` and String.t(). + + All messages and responses will be wrapped and unwrapped via `MLLP.Envelope.wrap_message/1` and + `MLLP.Envelope.unwrap_message/1` respectively + + In case the payload provided is an `HL7.Message.t()` the acknowledgment returned from the server + will always be verified via `MLLP.Ack.verify_ack_against_message/2`. This is the only case + where an `MLLP.Ack.ack_verification_result()` will be returned. + + ## Options + + * `:reply_timeout` - Optionally specify a timeout value for receiving a response. Must be a positive integer or + `:infinity`. Defaults to 60 seconds. + """ + @impl true + @spec send( + pid :: pid, + payload :: HL7.Message.t() | String.t() | binary(), + options :: ClientContract.send_options(), + timeout :: non_neg_integer() | :infinity + ) :: + {:ok, String.t()} + | MLLP.Ack.ack_verification_result() + | {:error, ClientContract.client_error()} + + def send(pid, payload, options \\ %{}, timeout \\ :infinity) + + def send(pid, %HL7.Message{} = payload, options, timeout) do + raw_message = to_string(payload) + + case GenStateMachine.call(pid, {:send, raw_message, options}, timeout) do + {:ok, reply} -> + verify_ack(reply, raw_message) + + err -> + err + end + end + + def send(pid, payload, options, timeout) do + case GenStateMachine.call(pid, {:send, payload, options}, timeout) do + {:ok, wrapped_message} -> + {:ok, MLLP.Envelope.unwrap_message(wrapped_message)} + + err -> + err + end + end + + @doc """ + Sends a message without awaiting a response. + + Given the synchronous nature of MLLP/HL7 this function is mainly useful for + testing purposes. + """ + @impl true + def send_async(pid, payload, timeout \\ :infinity) + + def send_async(pid, %HL7.Message{} = payload, timeout) do + send_async(pid, to_string(payload), timeout) + end + + def send_async(pid, payload, timeout) when is_binary(payload) do + GenStateMachine.call(pid, {:send_async, payload}, timeout) + end + + @doc """ + Stops an MLLP.Client given a MLLP.Client pid. + + This function will always return `:ok` per `GenStateMachine.stop/1`, thus + you may give it a pid that references a client which is already stopped. + """ + @spec stop(pid :: pid()) :: :ok + def stop(pid), do: GenStateMachine.stop(pid) + + @header MLLP.Envelope.sb() + @trailer MLLP.Envelope.eb_cr() + + ## GenStateMachine callbacks + + @impl true + @spec init(Keyword.t()) :: + {:ok, :disconnected, MLLP.Client.t(), [{:next_event, :internal, :connect}]} + def init(options) do + opts = + options + |> Enum.into(%{tls: []}) + |> validate_options() + |> maybe_set_default_options() + |> put_socket_address() + + {:ok, :disconnected, struct(State, opts), [{:next_event, :internal, :connect}]} + end + + ############################ + #### Disconnected state #### + ############################ + + def disconnected(:enter, :disconnected, state) do + {:keep_state, state, reconnect_action(state)} + end + + def disconnected(:enter, current_state, state) when current_state in [:connected, :receiving] do + Logger.error("Connection closed") + {:keep_state, state, reconnect_action(state)} + end + + def disconnected(:internal, :connect, state) do + {result, new_state} = attempt_connection(state) + + case result do + :error -> + {:keep_state, new_state, reconnect_action(new_state)} + + :ok -> + {:next_state, :connected, new_state} + end + end + + def disconnected(:state_timeout, :reconnect, data) do + actions = [{:next_event, :internal, :connect}] + {:keep_state, data, actions} + end + + def disconnected({:call, from}, :reconnect, _data) do + Logger.debug("Request to reconnect accepted") + {:keep_state_and_data, [{:reply, from, :ok}, {:next_event, :internal, :connect}]} + end + + def disconnected({:call, from}, {:send, _message, _options}, state) do + actions = [{:reply, from, {:error, new_error(:send, state.connect_failure)}}] + {:keep_state_and_data, actions} + end + + def disconnected({:call, from}, :is_connected, _state) do + {:keep_state_and_data, [{:reply, from, false}]} + end + + ######################### + #### Connected state #### + ######################### + def connected(:enter, :disconnected, _state) do + Logger.debug("Connection established") + :keep_state_and_data + end + + def connected(:enter, :receiving, _state) do + Logger.debug("Response received!") + :keep_state_and_data + end + + def connected({:call, from}, {send_type, message, options}, state) + when send_type in [:send, :send_async] do + payload = MLLP.Envelope.wrap_message(message) + + case state.tcp.send(state.socket, payload) do + :ok -> + {:next_state, :receiving, + state + |> Map.put(:context, :recv) + |> Map.put(:caller, from), send_action(send_type, from, options, state)} + + {:error, reason} -> + telemetry( + :status, + %{ + status: :disconnected, + error: format_error(reason), + context: "send message failure" + }, + state + ) + + error_reply = {:error, new_error(:send, reason)} + {:keep_state_and_data, [{:reply, from, error_reply}]} + end + end + + def connected({:call, from}, :is_connected, _state) do + {:keep_state_and_data, [{:reply, from, true}]} + end + + def connected({:call, from}, :reconnect, _state) do + {:keep_state_and_data, [{:reply, from, :ok}]} + end + + def connected(:info, {transport_closed, _socket}, state) + when transport_closed in [:tcp_closed, :ssl_closed] do + {:next_state, :disconnected, handle_closed(state)} + end + + defp reconnect_action( + %State{backoff: backoff, auto_reconnect_interval: auto_reconnect_interval} = _state + ) do + [{:state_timeout, reconnect_timeout(backoff, auto_reconnect_interval), :reconnect}] + end + + defp send_action(:send, _from, options, state) do + reply_timeout = Map.get(options, :reply_timeout, state.send_opts.reply_timeout) + [{:state_timeout, reply_timeout, :receive_timeout}] + end + + defp send_action(:send_async, from, _options, _state) do + [{:reply, from, {:ok, :sent}}] + end + + defp reconnect_timeout(nil, interval) do + interval + end + + defp reconnect_timeout(backoff, _interval) do + backoff + |> :backoff.get() + |> :timer.seconds() + end + + ######################### + #### Receiving state #### + ######################### + def receiving(:enter, :connected, _state) do + Logger.debug("Waiting for response...") + :keep_state_and_data + end + + def receiving({:call, from}, {:send, _message, _options}, _state) do + {:keep_state_and_data, [{:reply, from, {:error, :busy_with_other_call}}]} + end + + def receiving(:state_timeout, :reply_timeout, state) do + {:next_state, :connected, reply_to_caller({:error, :timeout}, state)} + end + + def receiving(:info, {transport, socket, data}, %{socket: socket} = state) + when transport in [:tcp, :ssl] do + {:next_state, :connected, handle_received(data, state)} + end + + def receiving(:info, {transport_closed, socket}, %{socket: socket} = state) + when transport_closed in [:tcp_closed, :ssl_closed] do + {:next_state, :disconnected, handle_closed(state)} + end + + def receiving(:info, {transport_error, socket, reason}, %{socket: socket} = state) + when transport_error in [:tcp_error, :ssl_error] do + {:next_state, :disconnected, handle_error(reason, maybe_close(reason, state))} + end + + def receiving(:info, unknown, _state) do + Logger.warn("Unknown kernel message received => #{inspect(unknown)}") + :keep_state_and_data + end + + ## Handle the (fragmented) responses to `send` request from a caller + + defp handle_received(_reply, %{caller: nil} = state) do + ## No caller, ignore + state + end + + defp handle_received(reply, %{receive_buffer: buffer} = state) do + new_buf = (buffer && buffer <> reply) || reply + check = byte_size(new_buf) - 3 + + case new_buf do + <<@header, _ack::binary-size(check), @trailer>> -> + ## The response is completed, send back to caller + reply_to_caller({:ok, new_buf}, state) + + <<@header, _rest::binary>> -> + Map.put(state, :receive_buffer, new_buf) + + _ -> + reply_to_caller({:error, :invalid_reply}, state) + end + end + + ######################################### + + defp reply_to_caller(reply, %{caller: caller, context: context} = state) do + caller && GenStateMachine.reply(caller, format_reply(reply, context)) + reply_cleanup(state) + end + + defp format_reply({:ok, result}, _context) do + {:ok, result} + end + + defp format_reply({:error, error}, context) do + {:error, new_error(context, error)} + end + + defp handle_closed(state) do + handle_error(:closed, state) + end + + ## Handle transport errors + defp handle_error(reason, state) do + Logger.error("Error: #{inspect(reason)}, state: #{inspect(state)}") + + reply_to_caller({:error, new_error(get_context(state), reason)}, state) + |> stop_connection(reason, "closing connection to cleanup") + |> tap(fn state -> + telemetry( + :status, + %{status: :disconnected, error: format_error(reason), context: "send message failure"}, + state + ) + end) + end + + defp reply_cleanup(%State{} = state) do + state + |> Map.put(:caller, nil) + |> Map.put(:receive_buffer, nil) + end + + @doc false + def terminate(reason = :normal, state) do + Logger.debug("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") + stop_connection(state, reason, "process terminated") + end + + def terminate(reason, state) do + Logger.error("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") + stop_connection(state, reason, "process terminated") + end + + defp maybe_close(reason, %{close_on_recv_error: true, context: context} = state) do + stop_connection(state, reason, context) + end + + defp maybe_close(_reason, state), do: state + + defp stop_connection(%State{} = state, error, context) do + if state.socket != nil do + telemetry( + :status, + %{status: :disconnected, error: format_error(error), context: context}, + state + ) + + state.tcp.close(state.socket) + end + + state + |> Map.put(:socket, nil) + end + + defp backoff_succeed(%State{backoff: nil} = state), do: state + + defp backoff_succeed(%State{backoff: backoff} = state) do + {_, new_backoff} = :backoff.succeed(backoff) + %{state | backoff: new_backoff} + end + + defp attempt_connection(%State{} = state) do + telemetry(:status, %{status: :connecting}, state) + opts = [:binary, {:packet, 0}, {:active, true}] ++ state.socket_opts ++ state.tls_opts + + case state.tcp.connect(state.address, state.port, opts, 2000) do + {:ok, socket} -> + state1 = + state + |> backoff_succeed() + + telemetry(:status, %{status: :connected}, state1) + {:ok, %{state1 | socket: socket, connect_failure: nil}} + + {:error, reason} -> + message = format_error(reason) + Logger.error(fn -> "Error connecting to #{state.socket_address} => #{message}" end) + + telemetry( + :status, + %{status: :disconnected, error: format_error(reason), context: "connect failure"}, + state + ) + + {:error, + state + |> maybe_update_reconnection_timeout() + |> Map.put(:connect_failure, reason)} + end + end + + defp maybe_update_reconnection_timeout(%State{backoff: nil} = state) do + state + end + + defp maybe_update_reconnection_timeout(%State{backoff: backoff} = state) do + {_, new_backoff} = :backoff.fail(backoff) + %{state | backoff: new_backoff} + end + + defp telemetry(_event_name, _measurements, %State{telemetry_module: nil} = _metadata) do + :ok + end + + defp telemetry(event_name, measurements, %State{telemetry_module: telemetry_module} = metadata) do + telemetry_module.execute([:client, event_name], add_timestamps(measurements), metadata) + end + + defp add_timestamps(measurements) do + measurements + |> Map.put(:monotonic, :erlang.monotonic_time()) + |> Map.put(:utc_datetime, DateTime.utc_now()) + end + + defp validate_options(opts) do + Map.get(opts, :address) || raise "No server address provided to connect to!" + Map.get(opts, :port) || raise "No server port provdided to connect to!" + opts + end + + @default_opts %{ + telemetry_module: MLLP.DefaultTelemetry, + tls_opts: [], + socket_opts: [send_timeout: 60_000] + } + + @default_send_opts %{ + reply_timeout: 60_000 + } + + defp maybe_set_default_options(opts) do + socket_module = if opts.tls == [], do: TCP, else: TLS + + backoff = + case opts[:use_backoff] do + false -> + nil + + _ -> + backoff_seconds = opts[:backoff_max_seconds] || 180 + :backoff.init(1, backoff_seconds) + end + + send_opts = Map.take(opts, Map.keys(@default_send_opts)) + + send_opts = Map.merge(@default_send_opts, send_opts) + + socket_opts = Keyword.merge(@default_opts[:socket_opts], opts[:socket_opts] || []) + + opts + |> Map.merge(@default_opts) + |> Map.put_new(:tcp, socket_module) + |> Map.put(:pid, self()) + |> Map.put(:tls_opts, opts.tls) + |> Map.put(:send_opts, send_opts) + |> Map.put(:socket_opts, socket_opts) + |> Map.put(:backoff, backoff) + end + + defp put_socket_address(%{address: address, port: port} = opts) do + Map.put(opts, :socket_address, "#{format_address(address)}:#{port}") + end + + defp format_address(address) when is_list(address) or is_atom(address) or is_binary(address) do + to_string(address) + end + + defp format_address(address), do: :inet.ntoa(address) + + defp verify_ack(raw_ack, raw_message) do + ack = Envelope.unwrap_message(raw_ack) + unwrapped_message = Envelope.unwrap_message(raw_message) + Ack.verify_ack_against_message(unwrapped_message, ack) + end + + defp new_error(context, %MLLP.Client.Error{} = error) do + Map.put(error, :context, context) + end + + defp new_error(context, error) do + %MLLP.Client.Error{ + reason: error, + context: context, + message: format_error(error) + } + end + + defp get_context(%State{context: context}) do + (context && context) || :unknown + end + + defp normalize_address!({_, _, _, _} = addr), do: addr + defp normalize_address!({_, _, _, _, _, _, _, _} = addr), do: addr + + defp normalize_address!(addr) when is_binary(addr) do + String.to_charlist(addr) + end + + defp normalize_address!(addr) when is_list(addr), do: addr + + defp normalize_address!(addr) when is_atom(addr), do: addr + + defp normalize_address!(addr), + do: raise(ArgumentError, "Invalid server ip address : #{inspect(addr)}") +end diff --git a/mix.exs b/mix.exs index a013de1..ec537ed 100644 --- a/mix.exs +++ b/mix.exs @@ -38,11 +38,14 @@ defmodule MLLP.MixProject do {:ranch, "~> 1.8.0"}, {:elixir_hl7, "~> 0.6.0"}, {:backoff, "~> 1.1.6"}, + {:gen_state_machine, "~> 3.0"}, {:ex_doc, "~> 0.24.2", only: :dev, runtime: false}, {:dialyxir, "~> 1.1.0", only: [:dev, :test], runtime: false}, {:mix_test_watch, "~> 1.0.2", only: :dev, runtime: false}, {:mox, "~> 1.0.0", only: :test}, - {:excoveralls, "~> 0.14.4", only: :test, runtime: false} + {:excoveralls, "~> 0.14.4", only: :test, runtime: false}, + ## Debugging + {:replbug, github: "bokner/replbug"} ] end diff --git a/mix.lock b/mix.lock index cbd0c5a..e2b70f6 100644 --- a/mix.lock +++ b/mix.lock @@ -4,10 +4,12 @@ "dialyxir": {:hex, :dialyxir, "1.1.0", "c5aab0d6e71e5522e77beff7ba9e08f8e02bad90dfbeffae60eaf0cb47e29488", [:mix], [{:erlex, ">= 0.2.6", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "07ea8e49c45f15264ebe6d5b93799d4dd56a44036cf42d0ad9c960bc266c0b9a"}, "earmark_parser": {:hex, :earmark_parser, "1.4.17", "6f3c7e94170377ba45241d394389e800fb15adc5de51d0a3cd52ae766aafd63f", [:mix], [], "hexpm", "f93ac89c9feca61c165b264b5837bf82344d13bebc634cd575cb711e2e342023"}, "elixir_hl7": {:hex, :elixir_hl7, "0.6.2", "b066608f2e63258da596d99794745ab42cb4e62ac9b363014d1611b49146da07", [:mix], [], "hexpm", "43db06b2f9333581b02a03ada7a22c3406088cd9b4564a60b2ab63e2191e5ee9"}, + "erlang_term": {:hex, :erlang_term, "2.0.6", "b004de5bc7e83785c7bf69fff1ccff838ac49a75af693f397308306213b41ea8", [:rebar3], [], "hexpm", "b9f227336ea08d4e416824899e2613d50470246d7d28776856cace9d7c9c0f07"}, "erlex": {:hex, :erlex, "0.2.6", "c7987d15e899c7a2f34f5420d2a2ea0d659682c06ac607572df55a43753aa12e", [:mix], [], "hexpm", "2ed2e25711feb44d52b17d2780eabf998452f6efda104877a3881c2f8c0c0c75"}, "ex_doc": {:hex, :ex_doc, "0.24.2", "e4c26603830c1a2286dae45f4412a4d1980e1e89dc779fcd0181ed1d5a05c8d9", [:mix], [{:earmark_parser, "~> 1.4.0", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "e134e1d9e821b8d9e4244687fb2ace58d479b67b282de5158333b0d57c6fb7da"}, "excoveralls": {:hex, :excoveralls, "0.14.6", "610e921e25b180a8538229ef547957f7e04bd3d3e9a55c7c5b7d24354abbba70", [:mix], [{:hackney, "~> 1.16", [hex: :hackney, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm", "0eceddaa9785cfcefbf3cd37812705f9d8ad34a758e513bb975b081dce4eb11e"}, "file_system": {:hex, :file_system, "0.2.10", "fb082005a9cd1711c05b5248710f8826b02d7d1784e7c3451f9c1231d4fc162d", [:mix], [], "hexpm", "41195edbfb562a593726eda3b3e8b103a309b733ad25f3d642ba49696bf715dc"}, + "gen_state_machine": {:hex, :gen_state_machine, "3.0.0", "1e57f86a494e5c6b14137ebef26a7eb342b3b0070c7135f2d6768ed3f6b6cdff", [:mix], [], "hexpm", "0a59652574bebceb7309f6b749d2a41b45fdeda8dbb4da0791e355dd19f0ed15"}, "hackney": {:hex, :hackney, "1.18.1", "f48bf88f521f2a229fc7bae88cf4f85adc9cd9bcf23b5dc8eb6a1788c662c4f6", [:rebar3], [{:certifi, "~>2.9.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "~>6.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "~>1.0.0", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "~>1.1", [hex: :mimerl, repo: "hexpm", optional: false]}, {:parse_trans, "3.3.1", [hex: :parse_trans, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "~>1.1.0", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}, {:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "a4ecdaff44297e9b5894ae499e9a070ea1888c84afdd1fd9b7b2bc384950128e"}, "idna": {:hex, :idna, "6.1.1", "8a63070e9f7d0c62eb9d9fcb360a7de382448200fbbd1b106cc96d3d8099df8d", [:rebar3], [{:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "92376eb7894412ed19ac475e4a86f7b413c1b9fbb5bd16dccd57934157944cea"}, "jason": {:hex, :jason, "1.4.0", "e855647bc964a44e2f67df589ccf49105ae039d4179db7f6271dfd3843dc27e6", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "79a3791085b2a0f743ca04cec0f7be26443738779d09302e01318f97bdb82121"}, @@ -21,6 +23,9 @@ "nimble_parsec": {:hex, :nimble_parsec, "1.2.0", "b44d75e2a6542dcb6acf5d71c32c74ca88960421b6874777f79153bbbbd7dccc", [:mix], [], "hexpm", "52b2871a7515a5ac49b00f214e4165a40724cf99798d8e4a65e4fd64ebd002c1"}, "parse_trans": {:hex, :parse_trans, "3.3.1", "16328ab840cc09919bd10dab29e431da3af9e9e7e7e6f0089dd5a2d2820011d8", [:rebar3], [], "hexpm", "07cd9577885f56362d414e8c4c4e6bdf10d43a8767abb92d24cbe8b24c54888b"}, "ranch": {:hex, :ranch, "1.8.0", "8c7a100a139fd57f17327b6413e4167ac559fbc04ca7448e9be9057311597a1d", [:make, :rebar3], [], "hexpm", "49fbcfd3682fab1f5d109351b61257676da1a2fdbe295904176d5e521a2ddfe5"}, + "redbug": {:git, "git@github.com:massemanet/redbug.git", "a249400ee173e1cb7db37e725df973a7a3b0d9b9", []}, + "replbug": {:git, "https://github.com/bokner/replbug.git", "0670e5d07c909a8635fb2aae79cc220696c26a2a", []}, + "rexbug": {:hex, :rexbug, "1.0.6", "024071c67d970151fbdc06f299faf8db3e1b2ac759a28623a9cc80a517fc74f2", [:mix], [{:mix_test_watch, ">= 0.5.0", [hex: :mix_test_watch, repo: "hexpm", optional: true]}, {:redbug, "~> 1.2", [hex: :redbug, repo: "hexpm", optional: false]}], "hexpm", "148ea724979413e9fd84ca3b4bb5d2d8b840ac481adfd645f5846fda409a642c"}, "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.6", "cf344f5692c82d2cd7554f5ec8fd961548d4fd09e7d22f5b62482e5aeaebd4b0", [:make, :mix, :rebar3], [], "hexpm", "bdb0d2471f453c88ff3908e7686f86f9be327d065cc1ec16fa4540197ea04680"}, "telemetry": {:hex, :telemetry, "1.1.0", "a589817034a27eab11144ad24d5c0f9fab1f58173274b1e9bae7074af9cbee51", [:rebar3], [], "hexpm", "b727b2a1f75614774cff2d7565b64d0dfa5bd52ba517f16543e6fc7efcc0df48"}, "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.0", "bc84380c9ab48177092f43ac89e4dfa2c6d62b40b8bd132b1059ecc7232f9a78", [:rebar3], [], "hexpm", "25eee6d67df61960cf6a794239566599b09e17e668d3700247bc498638152521"}, From 14ab8a9c0e1dcc69c322618dfe5cefedd3c7877e Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Fri, 7 Jul 2023 18:44:03 -0400 Subject: [PATCH 12/47] Tests passed (except ones for frag responses have to be rewritten) --- lib/mllp/client.ex | 343 ++++++++-------- lib/mllp/client/client_fsm.ex | 731 ---------------------------------- test/client_test.exs | 90 ++--- 3 files changed, 202 insertions(+), 962 deletions(-) mode change 100755 => 100644 lib/mllp/client.ex delete mode 100644 lib/mllp/client/client_fsm.ex diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex old mode 100755 new mode 100644 index 695b5c6..1c8cce1 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -1,47 +1,3 @@ -defmodule MLLP.ClientContract do - @moduledoc """ - MLLP.ClientContract provides the behavior implemented by MLLP.Client. It may be useful - for testing in your own application with tools such as [`Mox`](https://hexdocs.pm/mox/) - """ - @type error_type :: :connect_failure | :send_error | :recv_error - @type error_reason :: :closed | :timeout | :no_socket | :inet.posix() - - @type client_error :: MLLP.Client.Error.t() - - @type options :: [ - auto_reconnect_interval: non_neg_integer(), - use_backoff: boolean(), - backoff_max_seconds: integer(), - reply_timeout: non_neg_integer() | :infinity, - socket_opts: [:gen_tcp.option()], - telemetry_module: nil, - close_on_recv_error: boolean(), - tls: [:ssl.tls_client_option()] - ] - - @type send_options :: %{ - optional(:reply_timeout) => non_neg_integer() | :infinity - } - - @callback send( - pid :: pid, - payload :: HL7.Message.t() | String.t(), - options :: send_options(), - timeout :: non_neg_integer() | :infinity - ) :: - {:ok, String.t()} - | MLLP.Ack.ack_verification_result() - | {:error, client_error()} - - @callback send_async( - pid :: pid, - payload :: HL7.Message.t() | String.t(), - timeout :: non_neg_integer | :infinity - ) :: - {:ok, :sent} - | {:error, client_error()} -end - defmodule MLLP.Client do @moduledoc """ MLLP.Client provides a simple tcp client for sending and receiving data @@ -125,12 +81,13 @@ defmodule MLLP.Client do ``` """ - use GenServer require Logger alias MLLP.{Envelope, Ack, ClientContract, TCP, TLS} - @behaviour ClientContract + @behaviour MLLP.ClientContract + + use GenStateMachine, callback_mode: [:state_functions, :state_enter] @type pid_ref :: atom | pid | {atom, any} | {:via, atom, any} @type ip_address :: :inet.socket_address() | String.t() @@ -141,7 +98,6 @@ defmodule MLLP.Client do address: ip_address(), port: char(), auto_reconnect_interval: non_neg_integer(), - pending_reconnect: reference() | nil, pid: pid() | nil, telemetry_module: module() | nil, tcp: module() | nil, @@ -151,7 +107,6 @@ defmodule MLLP.Client do backoff: any(), caller: pid() | nil, receive_buffer: binary() | nil, - reply_timer: reference(), context: atom() } @@ -160,7 +115,6 @@ defmodule MLLP.Client do auto_reconnect_interval: 1000, address: {127, 0, 0, 1}, port: 0, - pending_reconnect: nil, pid: nil, telemetry_module: nil, tcp: nil, @@ -173,7 +127,6 @@ defmodule MLLP.Client do backoff: nil, caller: nil, receive_buffer: nil, - reply_timer: nil, context: :connect alias __MODULE__, as: State @@ -256,7 +209,7 @@ defmodule MLLP.Client do ) :: {:ok, pid()} def start_link(address, port, options \\ []) do - GenServer.start_link( + GenStateMachine.start_link( __MODULE__, [address: normalize_address!(address), port: port] ++ options ) @@ -266,13 +219,13 @@ defmodule MLLP.Client do Returns true if the connection is open and established, otherwise false. """ @spec is_connected?(pid :: pid()) :: boolean() - def is_connected?(pid) when is_pid(pid), do: GenServer.call(pid, :is_connected) + def is_connected?(pid) when is_pid(pid), do: GenStateMachine.call(pid, :is_connected) @doc """ Instructs the client to disconnect (if connected) and attempt a reconnect. """ @spec reconnect(pid :: pid()) :: :ok - def reconnect(pid), do: GenServer.call(pid, :reconnect) + def reconnect(pid), do: GenStateMachine.call(pid, :reconnect) @doc """ Sends a message and receives a response. @@ -291,6 +244,7 @@ defmodule MLLP.Client do * `:reply_timeout` - Optionally specify a timeout value for receiving a response. Must be a positive integer or `:infinity`. Defaults to 60 seconds. """ + @impl true @spec send( pid :: pid, payload :: HL7.Message.t() | String.t() | binary(), @@ -306,7 +260,7 @@ defmodule MLLP.Client do def send(pid, %HL7.Message{} = payload, options, timeout) do raw_message = to_string(payload) - case GenServer.call(pid, {:send, raw_message, options}, timeout) do + case GenStateMachine.call(pid, {:send, raw_message, options}, timeout) do {:ok, reply} -> verify_ack(reply, raw_message) @@ -316,7 +270,7 @@ defmodule MLLP.Client do end def send(pid, payload, options, timeout) do - case GenServer.call(pid, {:send, payload, options}, timeout) do + case GenStateMachine.call(pid, {:send, payload, options}, timeout) do {:ok, wrapped_message} -> {:ok, MLLP.Envelope.unwrap_message(wrapped_message)} @@ -331,31 +285,34 @@ defmodule MLLP.Client do Given the synchronous nature of MLLP/HL7 this function is mainly useful for testing purposes. """ + @impl true def send_async(pid, payload, timeout \\ :infinity) def send_async(pid, %HL7.Message{} = payload, timeout) do - GenServer.call(pid, {:send_async, to_string(payload)}, timeout) + send_async(pid, to_string(payload), timeout) end - def send_async(pid, payload, timeout) do - GenServer.call(pid, {:send_async, payload}, timeout) + def send_async(pid, payload, timeout) when is_binary(payload) do + GenStateMachine.call(pid, {:send_async, payload, []}, timeout) end @doc """ Stops an MLLP.Client given a MLLP.Client pid. - This function will always return `:ok` per `GenServer.stop/1`, thus + This function will always return `:ok` per `GenStateMachine.stop/1`, thus you may give it a pid that references a client which is already stopped. """ @spec stop(pid :: pid()) :: :ok - def stop(pid), do: GenServer.stop(pid) + def stop(pid), do: GenStateMachine.stop(pid) @header MLLP.Envelope.sb() @trailer MLLP.Envelope.eb_cr() - ## GenServer callbacks - @doc false - @spec init(Keyword.t()) :: {:ok, MLLP.Client.t(), {:continue, :init_socket}} + ## GenStateMachine callbacks + + @impl true + @spec init(Keyword.t()) :: + {:ok, :disconnected, MLLP.Client.t(), [{:next_event, :internal, :connect}]} def init(options) do opts = options @@ -364,132 +321,181 @@ defmodule MLLP.Client do |> maybe_set_default_options() |> put_socket_address() - {:ok, struct(State, opts), {:continue, :init_socket}} + {:ok, :disconnected, struct(State, opts), [{:next_event, :internal, :connect}]} end - @doc false - def handle_continue(:init_socket, state) do - {:noreply, attempt_connection(state)} + ############################ + #### Disconnected state #### + ############################ + + def disconnected(:enter, :disconnected, state) do + {:keep_state, state, reconnect_action(state)} end - def handle_call(:is_connected, _reply, state) do - {:reply, connected?(state), state} + def disconnected(:enter, current_state, state) when current_state in [:connected, :receiving] do + Logger.error("Connection closed") + {:keep_state, state, reconnect_action(state)} end - def handle_call(:reconnect, _from, state) do - new_state = - state - |> stop_connection(:timeout, "timeout message") - |> attempt_connection() + def disconnected(:internal, :connect, state) do + {result, new_state} = attempt_connection(state) - {:reply, :ok, new_state} + case result do + :error -> + {:keep_state, new_state, reconnect_action(new_state)} + + :ok -> + {:next_state, :connected, new_state} + end + end + + def disconnected(:state_timeout, :reconnect, data) do + actions = [{:next_event, :internal, :connect}] + {:keep_state, data, actions} end - def handle_call({:send, message, options}, from, state) do - telemetry(:sending, %{}, state) + def disconnected({:call, from}, :reconnect, _data) do + Logger.debug("Request to reconnect accepted") + {:keep_state_and_data, [{:reply, from, :ok}, {:next_event, :internal, :connect}]} + end - if connected?(state) do - payload = MLLP.Envelope.wrap_message(message) + def disconnected({:call, from}, {:send, _message, _options}, state) do + actions = [{:reply, from, {:error, new_error(:send, state.connect_failure)}}] + {:keep_state_and_data, actions} + end - case state.tcp.send(state.socket, payload) do - :ok -> - reply_timeout = Map.get(options, :reply_timeout, state.send_opts.reply_timeout) + def disconnected({:call, from}, :is_connected, _state) do + {:keep_state_and_data, [{:reply, from, false}]} + end - {:noreply, - state - |> Map.put(:context, :recv) - |> Map.put(:caller, from) - |> Map.put(:reply_timer, Process.send_after(self(), :reply_timeout, reply_timeout))} + def disconnected(event, unknown, _state) do + unexpected_message(event, unknown) + end - {:error, reason} -> - telemetry( - :status, - %{ - status: :disconnected, - error: format_error(reason), - context: "send message failure" - }, - state - ) + ######################### + #### Connected state #### + ######################### + def connected(:enter, :disconnected, _state) do + Logger.debug("Connection established") + :keep_state_and_data + end - new_state = maintain_reconnect_timer(state) - reply = {:error, new_error(:send, reason)} - {:reply, reply, new_state} - end - else - {:reply, {:error, new_error(:send, state.connect_failure)}, state} - end + def connected(:enter, :receiving, _state) do + Logger.debug("Response received!") + :keep_state_and_data end - def handle_call({:send_async, message}, _from, state) do - telemetry(:sending, %{}, state) + def connected({:call, from}, {send_type, message, options}, state) + when send_type in [:send, :send_async] do payload = MLLP.Envelope.wrap_message(message) case state.tcp.send(state.socket, payload) do :ok -> - {:reply, {:ok, :sent}, Map.put(state, :context, :recv)} + {:next_state, :receiving, + state + |> Map.put(:context, :recv) + |> Map.put(:caller, from), send_action(send_type, from, options, state)} {:error, reason} -> telemetry( :status, - %{status: :disconnected, error: format_error(reason), context: "send message failure"}, + %{ + status: :disconnected, + error: format_error(reason), + context: "send message failure" + }, state ) - new_state = maintain_reconnect_timer(state) - reply = {:error, new_error(:send, reason)} - {:reply, reply, new_state} + error_reply = {:error, new_error(:send, reason)} + {:keep_state_and_data, [{:reply, from, error_reply}]} end end - def handle_call(_msg, _from, %State{socket: nil} = state) do - telemetry( - :status, - %{ - status: :disconnected, - error: :no_socket, - context: "MLLP.Client disconnected failure" - }, - state - ) + def connected({:call, from}, :is_connected, _state) do + {:keep_state_and_data, [{:reply, from, true}]} + end - err = new_error(:connect, state.connect_failure) - {:reply, {:error, err}, state} + def connected({:call, from}, :reconnect, _state) do + {:keep_state_and_data, [{:reply, from, :ok}]} end - @doc false - def handle_info(:timeout, state) do - new_state = - state - |> stop_connection(:timeout, "timeout message") - |> attempt_connection() + def connected(:info, {transport_closed, _socket}, state) + when transport_closed in [:tcp_closed, :ssl_closed] do + {:next_state, :disconnected, handle_closed(state)} + end + + def connected(event, unknown, _state) do + unexpected_message(event, unknown) + end + + defp reconnect_action( + %State{backoff: backoff, auto_reconnect_interval: auto_reconnect_interval} = _state + ) do + [{:state_timeout, reconnect_timeout(backoff, auto_reconnect_interval), :reconnect}] + end + + defp send_action(:send, _from, options, state) do + reply_timeout = Map.get(options, :reply_timeout, state.send_opts.reply_timeout) + [{:state_timeout, reply_timeout, :receive_timeout}] + end + + defp send_action(:send_async, from, _options, _state) do + [{:reply, from, {:ok, :sent}}] + end + + defp reconnect_timeout(nil, interval) do + interval + end + + defp reconnect_timeout(backoff, _interval) do + backoff + |> :backoff.get() + |> :timer.seconds() + end + + ######################### + #### Receiving state #### + ######################### + def receiving(:enter, :connected, _state) do + Logger.debug("Waiting for response...") + :keep_state_and_data + end - {:noreply, new_state} + def receiving({:call, from}, {:send, _message, _options}, _state) do + {:keep_state_and_data, [{:reply, from, {:error, :busy_with_other_call}}]} end - def handle_info(:reply_timeout, state) do - {:noreply, reply_to_caller({:error, :timeout}, state)} + def receiving(:state_timeout, :receive_timeout, state) do + {:next_state, :connected, reply_to_caller({:error, :timeout}, state)} end - def handle_info({transport, socket, data}, %{socket: socket} = state) + def receiving(:info, {transport, socket, data}, %{socket: socket} = state) when transport in [:tcp, :ssl] do - new_state = handle_received(data, state) - {:noreply, new_state} + {:next_state, :connected, handle_received(data, state)} end - def handle_info({transport_closed, socket}, %{socket: socket} = state) + def receiving(:info, {transport_closed, socket}, %{socket: socket} = state) when transport_closed in [:tcp_closed, :ssl_closed] do - {:noreply, handle_closed(state)} + {:next_state, :disconnected, handle_closed(state)} end - def handle_info({transport_error, socket, reason}, %{socket: socket} = state) + def receiving(:info, {transport_error, socket, reason}, %{socket: socket} = state) when transport_error in [:tcp_error, :ssl_error] do - {:noreply, handle_error(reason, maybe_close(reason, state))} + {:next_state, :disconnected, handle_error(reason, maybe_close(reason, state))} + end + + def receiving(event, unknown, _state) do + unexpected_message(event, unknown) end - def handle_info(unknown, state) do - Logger.warn("Unknown kernel message received => #{inspect(unknown)}") - {:noreply, state} + ######################################## + ### End of GenStateMachine callbacks ### + ######################################## + + defp unexpected_message(event, message) do + Logger.warn("Unknown message received => #{inspect(message)}") + :keep_state_and_data end ## Handle the (fragmented) responses to `send` request from a caller @@ -517,7 +523,7 @@ defmodule MLLP.Client do end defp reply_to_caller(reply, %{caller: caller, context: context} = state) do - caller && GenServer.reply(caller, format_reply(reply, context)) + caller && GenStateMachine.reply(caller, format_reply(reply, context)) reply_cleanup(state) end @@ -548,13 +554,10 @@ defmodule MLLP.Client do end) end - defp reply_cleanup(%State{reply_timer: reply_timer} = state) do - reply_timer && Process.cancel_timer(reply_timer) - + defp reply_cleanup(%State{} = state) do state |> Map.put(:caller, nil) |> Map.put(:receive_buffer, nil) - |> Map.put(:reply_timer, nil) end @doc false @@ -568,14 +571,8 @@ defmodule MLLP.Client do stop_connection(state, reason, "process terminated") end - defp connected?(%{socket: socket, pending_reconnect: pending_reconnect} = _state) do - socket && !pending_reconnect - end - defp maybe_close(reason, %{close_on_recv_error: true, context: context} = state) do - state - |> stop_connection(reason, context) - |> attempt_connection() + stop_connection(state, reason, context) end defp maybe_close(_reason, state), do: state @@ -593,14 +590,6 @@ defmodule MLLP.Client do state |> Map.put(:socket, nil) - |> ensure_pending_reconnect_cancelled() - end - - defp ensure_pending_reconnect_cancelled(%State{pending_reconnect: nil} = state), do: state - - defp ensure_pending_reconnect_cancelled(%State{pending_reconnect: ref} = state) do - :ok = Process.cancel_timer(ref, info: false) - %{state | pending_reconnect: nil} end defp backoff_succeed(%State{backoff: nil} = state), do: state @@ -618,11 +607,10 @@ defmodule MLLP.Client do {:ok, socket} -> state1 = state - |> ensure_pending_reconnect_cancelled() |> backoff_succeed() telemetry(:status, %{status: :connected}, state1) - %{state1 | socket: socket, connect_failure: nil} + {:ok, %{state1 | socket: socket, connect_failure: nil}} {:error, reason} -> message = format_error(reason) @@ -634,31 +622,20 @@ defmodule MLLP.Client do state ) - state - |> maintain_reconnect_timer() - |> Map.put(:connect_failure, reason) + {:error, + state + |> maybe_update_reconnection_timeout() + |> Map.put(:connect_failure, reason)} end end - defp maintain_reconnect_timer(%{pending_reconnect: ref} = state) when is_reference(ref), - do: state - - defp maintain_reconnect_timer(%{backoff: nil} = state) do - ref = Process.send_after(self(), :timeout, state.auto_reconnect_interval) - - %State{state | socket: nil, pending_reconnect: ref} + defp maybe_update_reconnection_timeout(%State{backoff: nil} = state) do + state end - defp maintain_reconnect_timer(%{backoff: backoff} = state) do - seconds = - backoff - |> :backoff.get() - |> :timer.seconds() - - ref = Process.send_after(self(), :timeout, seconds) + defp maybe_update_reconnection_timeout(%State{backoff: backoff} = state) do {_, new_backoff} = :backoff.fail(backoff) - - %State{state | socket: nil, pending_reconnect: ref, backoff: new_backoff} + %{state | backoff: new_backoff} end defp telemetry(_event_name, _measurements, %State{telemetry_module: nil} = _metadata) do diff --git a/lib/mllp/client/client_fsm.ex b/lib/mllp/client/client_fsm.ex deleted file mode 100644 index 9995d68..0000000 --- a/lib/mllp/client/client_fsm.ex +++ /dev/null @@ -1,731 +0,0 @@ -defmodule MLLP.Client.FSM do - @moduledoc """ - MLLP.Client provides a simple tcp client for sending and receiving data - via [MLLP](https://www.hl7.org/documentcenter/public/wg/inm/mllp_transport_specification.PDF) over TCP. - - While MLLP is primarily used to send [HL7](https://en.wikipedia.org/wiki/Health_Level_7) messages, - MLLP.Client can be used to send non-hl7 messages, such as XML. - - ## Connection Behaviour - - Upon successful start up via `start_link/4`, the client will attempt to establish a connection to the given address - on the provided port. If a connection can not be immediately established, the client will keep - trying to establish a connection per the value of `:auto_reconnect_interval` which defaults to - 1 second. Therefore it is possible that before a connection is fully established, the caller - may attempt to send a message which will result in `MLLP.Client.Error.t()` being returned containing - the last error encountered in trying to establish a connection. Additionally, said behavour could be encountered - at any point during life span of an MLLP.Client process if the connection becomes severed on either side. - - All connections, send, and receive failures will be logged as errors. - - ## Examples - - ### Sending messages as strings - ``` - iex> MLLP.Receiver.start(dispatcher: MLLP.EchoDispatcher, port: 4090) - {:ok, - %{ - pid: #PID<0.2167.0>, - port: 4090, - receiver_id: #Reference<0.3312799297.2467299337.218126> - }} - iex> {:ok, client} = MLLP.Client.start_link("127.0.0.1", 4090) - {:ok, #PID<0.369.0>} - iex> msg = "MSH|^~\\&|MegaReg|XYZHospC|SuperOE|XYZImgCtr|20060529090131-0500|..." - "MSH|^~\\&|MegaReg|XYZHospC|SuperOE|XYZImgCtr|20060529090131-0500|..." - iex> MLLP.Client.send(client, msg) - {:ok, "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^A01^ACK|..."} - iex> - ``` - - ### Sending messages with `HL7.Message.t()` - ``` - iex> MLLP.Receiver.start(dispatcher: MLLP.EchoDispatcher, port: 4090) - {:ok, - %{ - pid: #PID<0.2167.0>, - port: 4090, - receiver_id: #Reference<0.3312799297.2467299337.218126> - }} - iex> {:ok, client} = MLLP.Client.start_link("127.0.0.1", 4090) - {:ok, #PID<0.369.0>} - iex> msg = HL7.Message.new(HL7.Examples.wikipedia_sample_hl7()) - iex> MLLP.Client.send(client, msg) - {:ok, :application_accept, - %MLLP.Ack{ - acknowledgement_code: "AA", - hl7_ack_message: nil, - text_message: "A real MLLP message dispatcher was not provided" - }} - ``` - - ### Using TLS - - ``` - iex> tls_opts = [ - cacertfile: "/path/to/ca_certificate.pem", - verify: :verify_peer, - certfile: "/path/to/server_certificate.pem", - keyfile: "/path/to/private_key.pem" - ] - iex> MLLP.Receiver.start(dispatcher: MLLP.EchoDispatcher, port: 4090, tls: tls_opts) - iex> {:ok, client} = MLLP.Client.start_link("localhost", 8154, tls: [verify: :verify_peer, cacertfile: "path/to/ca_certfile.pem"]) - iex> msg = HL7.Message.new(HL7.Examples.wikipedia_sample_hl7()) - iex> MLLP.Client.send(client, msg) - {:ok, :application_accept, - %MLLP.Ack{ - acknowledgement_code: "AA", - hl7_ack_message: nil, - text_message: "A real MLLP message dispatcher was not provided" - }} - ``` - """ - - require Logger - - alias MLLP.{Envelope, Ack, ClientContract, TCP, TLS} - - @behaviour MLLP.ClientContract - - use GenStateMachine, callback_mode: [:state_functions, :state_enter] - - @type pid_ref :: atom | pid | {atom, any} | {:via, atom, any} - @type ip_address :: :inet.socket_address() | String.t() - - @type t :: %MLLP.Client.FSM{ - socket: any(), - socket_address: String.t(), - address: ip_address(), - port: char(), - auto_reconnect_interval: non_neg_integer(), - pid: pid() | nil, - telemetry_module: module() | nil, - tcp: module() | nil, - tls_opts: Keyword.t(), - socket_opts: Keyword.t(), - close_on_recv_error: boolean(), - backoff: any(), - caller: pid() | nil, - receive_buffer: binary() | nil, - context: atom() - } - - defstruct socket: nil, - socket_address: "127.0.0.1:0", - auto_reconnect_interval: 1000, - address: {127, 0, 0, 1}, - port: 0, - pid: nil, - telemetry_module: nil, - tcp: nil, - connect_failure: nil, - host_string: nil, - send_opts: %{}, - tls_opts: [], - socket_opts: [], - close_on_recv_error: true, - backoff: nil, - caller: nil, - receive_buffer: nil, - context: :connect - - alias __MODULE__, as: State - - ## API - @doc false - @spec format_error(term()) :: String.t() - def format_error({:tls_alert, _} = err) do - to_string(:ssl.format_error({:error, err})) - end - - def format_error(:closed), do: "connection closed" - def format_error(:timeout), do: "timed out" - def format_error(:system_limit), do: "all available erlang emulator ports in use" - - def format_error(:invalid_reply) do - "Invalid header received in server acknowledgment" - 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) - end - end - - def format_error(err) when is_binary(err), do: err - - def format_error(err), do: inspect(err) - - @doc """ - Starts a new MLLP.Client. - - MLLP.Client.start_link/4 will start a new MLLP.Client process. - - This function will raise a `ArgumentError` if an invalid `ip_address()` is provided. - - ## Options - - * `:use_backoff` - Specify if an exponential backoff should be used for connection. When an attempt - to establish a connection fails, either post-init or at some point during the life span of the client, - the backoff value will determine how often to retry a reconnection. Starts at 1 second and increases - exponentially until reaching `backoff_max_seconds` seconds. Defaults to `true`. - - * `:backoff_max_seconds` - Specify the max limit of seconds the backoff reconection attempt should take, - defauls to 180 (3 mins). - - * `:auto_reconnect_interval` - Specify the interval between connection attempts. Specifically, if an attempt - to establish a connection fails, either post-init or at some point during the life span of the client, the value - of this option shall determine how often to retry a reconnection. Defaults to 1000 milliseconds. - This option will only be used if `use_backoff` is set to `false`. - - * `:reply_timeout` - Optionally specify a timeout value for receiving a response. Must be a positive integer or - `:infinity`. Defaults to 60 seconds. - - * `:socket_opts` - A list of socket options as supported by [`:gen_tcp`](`:gen_tcp`). - Note that `:binary`, `:packet`, and `:active` can not be overridden. Default options are enumerated below. - - send_timeout: Defaults to 60 seconds - - * `:close_on_recv_error` - A boolean value which dictates whether the client socket will be - closed when an error in receiving a reply is encountered, this includes timeouts. - Setting this to `true` is usually the safest behaviour to avoid a "dead lock" situation between a - client and a server. This functions similarly to the `:send_timeout` option provided by - [`:gen_tcp`](`:gen_tcp`). Defaults to `true`. - - * `:tls` - A list of tls options as supported by [`:ssl`](`:ssl`). When using TLS it is highly recommendeded you - set `:verify` to `:verify_peer`, select a CA trust store using the `:cacertfile` or `:cacerts` options. - Additionally, further hardening can be achieved through other ssl options such as enabling - certificate revocation via the `:crl_check` and `:crl_cache` options and customization of - enabled protocols and cipher suites for your specific use-case. See [`:ssl`](`:ssl`) for details. - - """ - @spec start_link( - address :: ip_address(), - port :: :inet.port_number(), - options :: ClientContract.options() - ) :: {:ok, pid()} - - def start_link(address, port, options \\ []) do - GenStateMachine.start_link( - __MODULE__, - [address: normalize_address!(address), port: port] ++ options - ) - end - - @doc """ - Returns true if the connection is open and established, otherwise false. - """ - @spec is_connected?(pid :: pid()) :: boolean() - def is_connected?(pid) when is_pid(pid), do: GenStateMachine.call(pid, :is_connected) - - @doc """ - Instructs the client to disconnect (if connected) and attempt a reconnect. - """ - @spec reconnect(pid :: pid()) :: :ok - def reconnect(pid), do: GenStateMachine.call(pid, :reconnect) - - @doc """ - Sends a message and receives a response. - - send/4 supports both `HL7.Message` and String.t(). - - All messages and responses will be wrapped and unwrapped via `MLLP.Envelope.wrap_message/1` and - `MLLP.Envelope.unwrap_message/1` respectively - - In case the payload provided is an `HL7.Message.t()` the acknowledgment returned from the server - will always be verified via `MLLP.Ack.verify_ack_against_message/2`. This is the only case - where an `MLLP.Ack.ack_verification_result()` will be returned. - - ## Options - - * `:reply_timeout` - Optionally specify a timeout value for receiving a response. Must be a positive integer or - `:infinity`. Defaults to 60 seconds. - """ - @impl true - @spec send( - pid :: pid, - payload :: HL7.Message.t() | String.t() | binary(), - options :: ClientContract.send_options(), - timeout :: non_neg_integer() | :infinity - ) :: - {:ok, String.t()} - | MLLP.Ack.ack_verification_result() - | {:error, ClientContract.client_error()} - - def send(pid, payload, options \\ %{}, timeout \\ :infinity) - - def send(pid, %HL7.Message{} = payload, options, timeout) do - raw_message = to_string(payload) - - case GenStateMachine.call(pid, {:send, raw_message, options}, timeout) do - {:ok, reply} -> - verify_ack(reply, raw_message) - - err -> - err - end - end - - def send(pid, payload, options, timeout) do - case GenStateMachine.call(pid, {:send, payload, options}, timeout) do - {:ok, wrapped_message} -> - {:ok, MLLP.Envelope.unwrap_message(wrapped_message)} - - err -> - err - end - end - - @doc """ - Sends a message without awaiting a response. - - Given the synchronous nature of MLLP/HL7 this function is mainly useful for - testing purposes. - """ - @impl true - def send_async(pid, payload, timeout \\ :infinity) - - def send_async(pid, %HL7.Message{} = payload, timeout) do - send_async(pid, to_string(payload), timeout) - end - - def send_async(pid, payload, timeout) when is_binary(payload) do - GenStateMachine.call(pid, {:send_async, payload}, timeout) - end - - @doc """ - Stops an MLLP.Client given a MLLP.Client pid. - - This function will always return `:ok` per `GenStateMachine.stop/1`, thus - you may give it a pid that references a client which is already stopped. - """ - @spec stop(pid :: pid()) :: :ok - def stop(pid), do: GenStateMachine.stop(pid) - - @header MLLP.Envelope.sb() - @trailer MLLP.Envelope.eb_cr() - - ## GenStateMachine callbacks - - @impl true - @spec init(Keyword.t()) :: - {:ok, :disconnected, MLLP.Client.t(), [{:next_event, :internal, :connect}]} - def init(options) do - opts = - options - |> Enum.into(%{tls: []}) - |> validate_options() - |> maybe_set_default_options() - |> put_socket_address() - - {:ok, :disconnected, struct(State, opts), [{:next_event, :internal, :connect}]} - end - - ############################ - #### Disconnected state #### - ############################ - - def disconnected(:enter, :disconnected, state) do - {:keep_state, state, reconnect_action(state)} - end - - def disconnected(:enter, current_state, state) when current_state in [:connected, :receiving] do - Logger.error("Connection closed") - {:keep_state, state, reconnect_action(state)} - end - - def disconnected(:internal, :connect, state) do - {result, new_state} = attempt_connection(state) - - case result do - :error -> - {:keep_state, new_state, reconnect_action(new_state)} - - :ok -> - {:next_state, :connected, new_state} - end - end - - def disconnected(:state_timeout, :reconnect, data) do - actions = [{:next_event, :internal, :connect}] - {:keep_state, data, actions} - end - - def disconnected({:call, from}, :reconnect, _data) do - Logger.debug("Request to reconnect accepted") - {:keep_state_and_data, [{:reply, from, :ok}, {:next_event, :internal, :connect}]} - end - - def disconnected({:call, from}, {:send, _message, _options}, state) do - actions = [{:reply, from, {:error, new_error(:send, state.connect_failure)}}] - {:keep_state_and_data, actions} - end - - def disconnected({:call, from}, :is_connected, _state) do - {:keep_state_and_data, [{:reply, from, false}]} - end - - ######################### - #### Connected state #### - ######################### - def connected(:enter, :disconnected, _state) do - Logger.debug("Connection established") - :keep_state_and_data - end - - def connected(:enter, :receiving, _state) do - Logger.debug("Response received!") - :keep_state_and_data - end - - def connected({:call, from}, {send_type, message, options}, state) - when send_type in [:send, :send_async] do - payload = MLLP.Envelope.wrap_message(message) - - case state.tcp.send(state.socket, payload) do - :ok -> - {:next_state, :receiving, - state - |> Map.put(:context, :recv) - |> Map.put(:caller, from), send_action(send_type, from, options, state)} - - {:error, reason} -> - telemetry( - :status, - %{ - status: :disconnected, - error: format_error(reason), - context: "send message failure" - }, - state - ) - - error_reply = {:error, new_error(:send, reason)} - {:keep_state_and_data, [{:reply, from, error_reply}]} - end - end - - def connected({:call, from}, :is_connected, _state) do - {:keep_state_and_data, [{:reply, from, true}]} - end - - def connected({:call, from}, :reconnect, _state) do - {:keep_state_and_data, [{:reply, from, :ok}]} - end - - def connected(:info, {transport_closed, _socket}, state) - when transport_closed in [:tcp_closed, :ssl_closed] do - {:next_state, :disconnected, handle_closed(state)} - end - - defp reconnect_action( - %State{backoff: backoff, auto_reconnect_interval: auto_reconnect_interval} = _state - ) do - [{:state_timeout, reconnect_timeout(backoff, auto_reconnect_interval), :reconnect}] - end - - defp send_action(:send, _from, options, state) do - reply_timeout = Map.get(options, :reply_timeout, state.send_opts.reply_timeout) - [{:state_timeout, reply_timeout, :receive_timeout}] - end - - defp send_action(:send_async, from, _options, _state) do - [{:reply, from, {:ok, :sent}}] - end - - defp reconnect_timeout(nil, interval) do - interval - end - - defp reconnect_timeout(backoff, _interval) do - backoff - |> :backoff.get() - |> :timer.seconds() - end - - ######################### - #### Receiving state #### - ######################### - def receiving(:enter, :connected, _state) do - Logger.debug("Waiting for response...") - :keep_state_and_data - end - - def receiving({:call, from}, {:send, _message, _options}, _state) do - {:keep_state_and_data, [{:reply, from, {:error, :busy_with_other_call}}]} - end - - def receiving(:state_timeout, :reply_timeout, state) do - {:next_state, :connected, reply_to_caller({:error, :timeout}, state)} - end - - def receiving(:info, {transport, socket, data}, %{socket: socket} = state) - when transport in [:tcp, :ssl] do - {:next_state, :connected, handle_received(data, state)} - end - - def receiving(:info, {transport_closed, socket}, %{socket: socket} = state) - when transport_closed in [:tcp_closed, :ssl_closed] do - {:next_state, :disconnected, handle_closed(state)} - end - - def receiving(:info, {transport_error, socket, reason}, %{socket: socket} = state) - when transport_error in [:tcp_error, :ssl_error] do - {:next_state, :disconnected, handle_error(reason, maybe_close(reason, state))} - end - - def receiving(:info, unknown, _state) do - Logger.warn("Unknown kernel message received => #{inspect(unknown)}") - :keep_state_and_data - end - - ## Handle the (fragmented) responses to `send` request from a caller - - defp handle_received(_reply, %{caller: nil} = state) do - ## No caller, ignore - state - end - - defp handle_received(reply, %{receive_buffer: buffer} = state) do - new_buf = (buffer && buffer <> reply) || reply - check = byte_size(new_buf) - 3 - - case new_buf do - <<@header, _ack::binary-size(check), @trailer>> -> - ## The response is completed, send back to caller - reply_to_caller({:ok, new_buf}, state) - - <<@header, _rest::binary>> -> - Map.put(state, :receive_buffer, new_buf) - - _ -> - reply_to_caller({:error, :invalid_reply}, state) - end - end - - ######################################### - - defp reply_to_caller(reply, %{caller: caller, context: context} = state) do - caller && GenStateMachine.reply(caller, format_reply(reply, context)) - reply_cleanup(state) - end - - defp format_reply({:ok, result}, _context) do - {:ok, result} - end - - defp format_reply({:error, error}, context) do - {:error, new_error(context, error)} - end - - defp handle_closed(state) do - handle_error(:closed, state) - end - - ## Handle transport errors - defp handle_error(reason, state) do - Logger.error("Error: #{inspect(reason)}, state: #{inspect(state)}") - - reply_to_caller({:error, new_error(get_context(state), reason)}, state) - |> stop_connection(reason, "closing connection to cleanup") - |> tap(fn state -> - telemetry( - :status, - %{status: :disconnected, error: format_error(reason), context: "send message failure"}, - state - ) - end) - end - - defp reply_cleanup(%State{} = state) do - state - |> Map.put(:caller, nil) - |> Map.put(:receive_buffer, nil) - end - - @doc false - def terminate(reason = :normal, state) do - Logger.debug("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") - stop_connection(state, reason, "process terminated") - end - - def terminate(reason, state) do - Logger.error("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") - stop_connection(state, reason, "process terminated") - end - - defp maybe_close(reason, %{close_on_recv_error: true, context: context} = state) do - stop_connection(state, reason, context) - end - - defp maybe_close(_reason, state), do: state - - defp stop_connection(%State{} = state, error, context) do - if state.socket != nil do - telemetry( - :status, - %{status: :disconnected, error: format_error(error), context: context}, - state - ) - - state.tcp.close(state.socket) - end - - state - |> Map.put(:socket, nil) - end - - defp backoff_succeed(%State{backoff: nil} = state), do: state - - defp backoff_succeed(%State{backoff: backoff} = state) do - {_, new_backoff} = :backoff.succeed(backoff) - %{state | backoff: new_backoff} - end - - defp attempt_connection(%State{} = state) do - telemetry(:status, %{status: :connecting}, state) - opts = [:binary, {:packet, 0}, {:active, true}] ++ state.socket_opts ++ state.tls_opts - - case state.tcp.connect(state.address, state.port, opts, 2000) do - {:ok, socket} -> - state1 = - state - |> backoff_succeed() - - telemetry(:status, %{status: :connected}, state1) - {:ok, %{state1 | socket: socket, connect_failure: nil}} - - {:error, reason} -> - message = format_error(reason) - Logger.error(fn -> "Error connecting to #{state.socket_address} => #{message}" end) - - telemetry( - :status, - %{status: :disconnected, error: format_error(reason), context: "connect failure"}, - state - ) - - {:error, - state - |> maybe_update_reconnection_timeout() - |> Map.put(:connect_failure, reason)} - end - end - - defp maybe_update_reconnection_timeout(%State{backoff: nil} = state) do - state - end - - defp maybe_update_reconnection_timeout(%State{backoff: backoff} = state) do - {_, new_backoff} = :backoff.fail(backoff) - %{state | backoff: new_backoff} - end - - defp telemetry(_event_name, _measurements, %State{telemetry_module: nil} = _metadata) do - :ok - end - - defp telemetry(event_name, measurements, %State{telemetry_module: telemetry_module} = metadata) do - telemetry_module.execute([:client, event_name], add_timestamps(measurements), metadata) - end - - defp add_timestamps(measurements) do - measurements - |> Map.put(:monotonic, :erlang.monotonic_time()) - |> Map.put(:utc_datetime, DateTime.utc_now()) - end - - defp validate_options(opts) do - Map.get(opts, :address) || raise "No server address provided to connect to!" - Map.get(opts, :port) || raise "No server port provdided to connect to!" - opts - end - - @default_opts %{ - telemetry_module: MLLP.DefaultTelemetry, - tls_opts: [], - socket_opts: [send_timeout: 60_000] - } - - @default_send_opts %{ - reply_timeout: 60_000 - } - - defp maybe_set_default_options(opts) do - socket_module = if opts.tls == [], do: TCP, else: TLS - - backoff = - case opts[:use_backoff] do - false -> - nil - - _ -> - backoff_seconds = opts[:backoff_max_seconds] || 180 - :backoff.init(1, backoff_seconds) - end - - send_opts = Map.take(opts, Map.keys(@default_send_opts)) - - send_opts = Map.merge(@default_send_opts, send_opts) - - socket_opts = Keyword.merge(@default_opts[:socket_opts], opts[:socket_opts] || []) - - opts - |> Map.merge(@default_opts) - |> Map.put_new(:tcp, socket_module) - |> Map.put(:pid, self()) - |> Map.put(:tls_opts, opts.tls) - |> Map.put(:send_opts, send_opts) - |> Map.put(:socket_opts, socket_opts) - |> Map.put(:backoff, backoff) - end - - defp put_socket_address(%{address: address, port: port} = opts) do - Map.put(opts, :socket_address, "#{format_address(address)}:#{port}") - end - - defp format_address(address) when is_list(address) or is_atom(address) or is_binary(address) do - to_string(address) - end - - defp format_address(address), do: :inet.ntoa(address) - - defp verify_ack(raw_ack, raw_message) do - ack = Envelope.unwrap_message(raw_ack) - unwrapped_message = Envelope.unwrap_message(raw_message) - Ack.verify_ack_against_message(unwrapped_message, ack) - end - - defp new_error(context, %MLLP.Client.Error{} = error) do - Map.put(error, :context, context) - end - - defp new_error(context, error) do - %MLLP.Client.Error{ - reason: error, - context: context, - message: format_error(error) - } - end - - defp get_context(%State{context: context}) do - (context && context) || :unknown - end - - defp normalize_address!({_, _, _, _} = addr), do: addr - defp normalize_address!({_, _, _, _, _, _, _, _} = addr), do: addr - - defp normalize_address!(addr) when is_binary(addr) do - String.to_charlist(addr) - end - - defp normalize_address!(addr) when is_list(addr), do: addr - - defp normalize_address!(addr) when is_atom(addr), do: addr - - defp normalize_address!(addr), - do: raise(ArgumentError, "Invalid server ip address : #{inspect(addr)}") -end diff --git a/test/client_test.exs b/test/client_test.exs index 908568f..4e38750 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -91,7 +91,7 @@ defmodule ClientTest do end) {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) # Assert we have the correct socket_opts in the state assert state.socket_opts == [send_timeout: 60_000] @@ -110,7 +110,7 @@ defmodule ClientTest do end) {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock, socket_opts: socket_opts) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) # Assert we have the correct socket_opts in the state assert state.socket_opts == [send_timeout: 10_000] @@ -130,7 +130,7 @@ defmodule ClientTest do end) {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock, socket_opts: socket_opts) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) # Assert we have the correct socket_opts in the state assert state.socket_opts[:send_timeout] == 60_000 @@ -158,7 +158,7 @@ defmodule ClientTest do {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) assert {:backoff, 1, 180, 1, :normal, _, _} = state.backoff end @@ -181,7 +181,7 @@ defmodule ClientTest do {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) assert {:backoff, 1, 180, 2, :normal, _, _} = state.backoff end @@ -195,22 +195,16 @@ defmodule ClientTest do Kernel.send(pid, :eh?) Process.sleep(100) assert Process.alive?(pid) - end) =~ "Unknown kernel message received => :eh?" + end) =~ "Unknown message received => :eh?" end end describe "send/2" do setup do - address = {127, 0, 0, 1} - port = 4090 - {:ok, _receiver} = MLLP.Receiver.start(port: port, dispatcher: ClientTest.TestDispatcher) - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCP) - on_exit(fn -> MLLP.Receiver.stop(port); Process.sleep(100); Process.exit(client, :kill) end) - %{client: client} + setup_client_receiver() end test "with valid HL7 returns an AA", ctx do - raw_hl7 = HL7.Examples.wikipedia_sample_hl7() message = HL7.Message.new(raw_hl7) expected_ack = %MLLP.Ack{acknowledgement_code: "AA", text_message: ""} @@ -219,7 +213,6 @@ defmodule ClientTest do {:ok, :application_accept, expected_ack} == Client.send(ctx.client, message, %{reply_timeout: 1000}) ) - end test "when replies are fragmented", ctx do @@ -244,7 +237,6 @@ defmodule ClientTest do {ack_frag2, ack_frag3} = String.split_at(ack_frag2, 10) - assert( {:ok, :application_accept, expected_ack} == Client.send(ctx.client, message) @@ -296,13 +288,9 @@ defmodule ClientTest do end test "when reply header is invalid", ctx do - raw_hl7 = HL7.Examples.wikipedia_sample_hl7() - message = HL7.Message.new(raw_hl7) - packet = MLLP.Envelope.wrap_message(raw_hl7) - - tcp_reply1 = - "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|01052901|P|2.5\rMSA|AA|01052901|You win!\r" - + ## This HL7 message triggers :invalid_reply due to TestDispatcher implementation (note DONOTWRAP!) + message = + "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|DONOTWRAP|P|2.5\rMSA|AA|DONOTWRAP\r" expected_err = %MLLP.Client.Error{ context: :recv, @@ -312,7 +300,7 @@ defmodule ClientTest do assert( {:error, expected_err} == - Client.send(ctx.client, tcp_reply1) + Client.send(ctx.client, message) ) end @@ -357,34 +345,18 @@ defmodule ClientTest do end describe "send_async/2" do - test "as a message" do - address = {127, 0, 0, 1} - port = 4090 - socket = make_ref() + setup do + setup_client_receiver() + end + test "as a message", ctx do raw_hl7 = HL7.Examples.wikipedia_sample_hl7() message = raw_hl7 |> HL7.Message.new() - packet = MLLP.Envelope.wrap_message(raw_hl7) - - MLLP.TCPMock - |> expect( - :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> - {:ok, socket} - end - ) - |> expect(:send, fn ^socket, ^packet -> :ok end) - - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock) - - assert({:ok, :sent} == Client.send_async(client, message)) + assert({:ok, :sent} == Client.send_async(ctx.client, message)) end test "when given non hl7" do @@ -443,7 +415,7 @@ defmodule ClientTest do test "logs debug message when reason is :normal" do Logger.configure(level: :debug) {:ok, pid} = Client.start_link({127, 0, 0, 1}, 9999) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) assert capture_log([level: :debug], fn -> Client.terminate(:normal, state) @@ -453,7 +425,7 @@ defmodule ClientTest do test "logs error for any other reason" do Logger.configure(level: :debug) {:ok, pid} = Client.start_link({127, 0, 0, 1}, 9999) - state = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(pid) assert capture_log([level: :error], fn -> Client.terminate(:shutdown, state) @@ -461,6 +433,21 @@ defmodule ClientTest do end end + defp setup_client_receiver() do + address = {127, 0, 0, 1} + port = 4090 + {:ok, _receiver} = MLLP.Receiver.start(port: port, dispatcher: ClientTest.TestDispatcher) + {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCP) + + on_exit(fn -> + MLLP.Receiver.stop(port) + Process.sleep(100) + Process.exit(client, :kill) + end) + + %{client: client} + end + defp telemetry_event( [:mllp, :client, event_name] = _full_event_name, measurements, @@ -503,7 +490,7 @@ defmodule ClientTest do :application_accept ) |> to_string() - |> MLLP.Envelope.wrap_message() + |> wrap_message() {:ok, %{state | reply_buffer: reply}} end @@ -511,6 +498,13 @@ defmodule ClientTest do def dispatch(non_hl7_type, message, state) do {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message("NACK")}} end - end + defp wrap_message(message) do + if String.contains?(message, "DONOTWRAP") do + message + else + MLLP.Envelope.wrap_message(message) + end + end + end end From 472155ad6a198d553386ee9b00a1b00b7cfb686a Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Mon, 10 Jul 2023 14:53:44 -0400 Subject: [PATCH 13/47] Bug fixes, tests for fragmented messages --- lib/mllp/client.ex | 71 +++++++++++++++++++++--- mix.exs | 4 +- mix.lock | 26 ++++----- test/client_test.exs | 125 ++++++++++++++++++------------------------- 4 files changed, 127 insertions(+), 99 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 1c8cce1..0254512 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -1,3 +1,47 @@ +defmodule MLLP.ClientContract do + @moduledoc """ + MLLP.ClientContract provides the behavior implemented by MLLP.Client. It may be useful + for testing in your own application with tools such as [`Mox`](https://hexdocs.pm/mox/) + """ + @type error_type :: :connect_failure | :send_error | :recv_error + @type error_reason :: :closed | :timeout | :no_socket | :inet.posix() + + @type client_error :: MLLP.Client.Error.t() + + @type options :: [ + auto_reconnect_interval: non_neg_integer(), + use_backoff: boolean(), + backoff_max_seconds: integer(), + reply_timeout: non_neg_integer() | :infinity, + socket_opts: [:gen_tcp.option()], + telemetry_module: nil, + close_on_recv_error: boolean(), + tls: [:ssl.tls_client_option()] + ] + + @type send_options :: %{ + optional(:reply_timeout) => non_neg_integer() | :infinity + } + + @callback send( + pid :: pid, + payload :: HL7.Message.t() | String.t(), + options :: send_options(), + timeout :: non_neg_integer() | :infinity + ) :: + {:ok, String.t()} + | MLLP.Ack.ack_verification_result() + | {:error, client_error()} + + @callback send_async( + pid :: pid, + payload :: HL7.Message.t() | String.t(), + timeout :: non_neg_integer | :infinity + ) :: + {:ok, :sent} + | {:error, client_error()} +end + defmodule MLLP.Client do @moduledoc """ MLLP.Client provides a simple tcp client for sending and receiving data @@ -195,7 +239,7 @@ defmodule MLLP.Client do client and a server. This functions similarly to the `:send_timeout` option provided by [`:gen_tcp`](`:gen_tcp`). Defaults to `true`. - * `:tls` - A list of tls options as supported by [`:ssl`](`:ssl`). When using TLS it is highly recommendeded you + * `:tls` - A list of tls options as supported by [`:ssl`](`:ssl`). When using TLS it is highly recommended you set `:verify` to `:verify_peer`, select a CA trust store using the `:cacertfile` or `:cacerts` options. Additionally, further hardening can be achieved through other ssl options such as enabling certificate revocation via the `:crl_check` and `:crl_cache` options and customization of @@ -369,7 +413,7 @@ defmodule MLLP.Client do end def disconnected(event, unknown, _state) do - unexpected_message(event, unknown) + unexpected_message(:disconnected, event, unknown) end ######################### @@ -381,7 +425,6 @@ defmodule MLLP.Client do end def connected(:enter, :receiving, _state) do - Logger.debug("Response received!") :keep_state_and_data end @@ -420,13 +463,18 @@ defmodule MLLP.Client do {:keep_state_and_data, [{:reply, from, :ok}]} end + def connected(:info, {transport, socket, data} = msg, %{socket: socket} = state) + when transport in [:tcp, :ssl] do + receiving(:info, msg, state) + end + def connected(:info, {transport_closed, _socket}, state) when transport_closed in [:tcp_closed, :ssl_closed] do {:next_state, :disconnected, handle_closed(state)} end def connected(event, unknown, _state) do - unexpected_message(event, unknown) + unexpected_message(:connected, event, unknown) end defp reconnect_action( @@ -472,7 +520,9 @@ defmodule MLLP.Client do def receiving(:info, {transport, socket, data}, %{socket: socket} = state) when transport in [:tcp, :ssl] do - {:next_state, :connected, handle_received(data, state)} + new_data = handle_received(data, state) + next_state = (new_data.caller && :receiving) || :connected + {:next_state, next_state, new_data} end def receiving(:info, {transport_closed, socket}, %{socket: socket} = state) @@ -486,15 +536,18 @@ defmodule MLLP.Client do end def receiving(event, unknown, _state) do - unexpected_message(event, unknown) + unexpected_message(:receiving, event, unknown) end ######################################## ### End of GenStateMachine callbacks ### ######################################## - defp unexpected_message(event, message) do - Logger.warn("Unknown message received => #{inspect(message)}") + defp unexpected_message(state, event, message) do + Logger.warn( + "Event: #{inspect(event)} in state #{state}. Unknown message received => #{inspect(message)}" + ) + :keep_state_and_data end @@ -512,9 +565,11 @@ defmodule MLLP.Client do case new_buf do <<@header, _ack::binary-size(check), @trailer>> -> ## The response is completed, send back to caller + Logger.debug("Client #{inspect(self())} received a full MLLP!") reply_to_caller({:ok, new_buf}, state) <<@header, _rest::binary>> -> + Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") Map.put(state, :receive_buffer, new_buf) _ -> diff --git a/mix.exs b/mix.exs index ec537ed..e81e6c1 100644 --- a/mix.exs +++ b/mix.exs @@ -43,9 +43,7 @@ defmodule MLLP.MixProject do {:dialyxir, "~> 1.1.0", only: [:dev, :test], runtime: false}, {:mix_test_watch, "~> 1.0.2", only: :dev, runtime: false}, {:mox, "~> 1.0.0", only: :test}, - {:excoveralls, "~> 0.14.4", only: :test, runtime: false}, - ## Debugging - {:replbug, github: "bokner/replbug"} + {:excoveralls, "~> 0.14.4", only: :test, runtime: false} ] end diff --git a/mix.lock b/mix.lock index e2b70f6..8e726eb 100644 --- a/mix.lock +++ b/mix.lock @@ -2,9 +2,8 @@ "backoff": {:hex, :backoff, "1.1.6", "83b72ed2108ba1ee8f7d1c22e0b4a00cfe3593a67dbc792799e8cce9f42f796b", [:rebar3], [], "hexpm", "cf0cfff8995fb20562f822e5cc47d8ccf664c5ecdc26a684cbe85c225f9d7c39"}, "certifi": {:hex, :certifi, "2.9.0", "6f2a475689dd47f19fb74334859d460a2dc4e3252a3324bd2111b8f0429e7e21", [:rebar3], [], "hexpm", "266da46bdb06d6c6d35fde799bcb28d36d985d424ad7c08b5bb48f5b5cdd4641"}, "dialyxir": {:hex, :dialyxir, "1.1.0", "c5aab0d6e71e5522e77beff7ba9e08f8e02bad90dfbeffae60eaf0cb47e29488", [:mix], [{:erlex, ">= 0.2.6", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "07ea8e49c45f15264ebe6d5b93799d4dd56a44036cf42d0ad9c960bc266c0b9a"}, - "earmark_parser": {:hex, :earmark_parser, "1.4.17", "6f3c7e94170377ba45241d394389e800fb15adc5de51d0a3cd52ae766aafd63f", [:mix], [], "hexpm", "f93ac89c9feca61c165b264b5837bf82344d13bebc634cd575cb711e2e342023"}, - "elixir_hl7": {:hex, :elixir_hl7, "0.6.2", "b066608f2e63258da596d99794745ab42cb4e62ac9b363014d1611b49146da07", [:mix], [], "hexpm", "43db06b2f9333581b02a03ada7a22c3406088cd9b4564a60b2ab63e2191e5ee9"}, - "erlang_term": {:hex, :erlang_term, "2.0.6", "b004de5bc7e83785c7bf69fff1ccff838ac49a75af693f397308306213b41ea8", [:rebar3], [], "hexpm", "b9f227336ea08d4e416824899e2613d50470246d7d28776856cace9d7c9c0f07"}, + "earmark_parser": {:hex, :earmark_parser, "1.4.33", "3c3fd9673bb5dcc9edc28dd90f50c87ce506d1f71b70e3de69aa8154bc695d44", [:mix], [], "hexpm", "2d526833729b59b9fdb85785078697c72ac5e5066350663e5be6a1182da61b8f"}, + "elixir_hl7": {:hex, :elixir_hl7, "0.6.6", "ae01b991eb1aa8d199bb75006a87f3f37f02238a82443bea7cd5f36c7f70204a", [:mix], [], "hexpm", "8e9fd9ad2512f9560a4176c4ae9e9613bee4857103b2521a76aa47fbdc26369c"}, "erlex": {:hex, :erlex, "0.2.6", "c7987d15e899c7a2f34f5420d2a2ea0d659682c06ac607572df55a43753aa12e", [:mix], [], "hexpm", "2ed2e25711feb44d52b17d2780eabf998452f6efda104877a3881c2f8c0c0c75"}, "ex_doc": {:hex, :ex_doc, "0.24.2", "e4c26603830c1a2286dae45f4412a4d1980e1e89dc779fcd0181ed1d5a05c8d9", [:mix], [{:earmark_parser, "~> 1.4.0", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "e134e1d9e821b8d9e4244687fb2ace58d479b67b282de5158333b0d57c6fb7da"}, "excoveralls": {:hex, :excoveralls, "0.14.6", "610e921e25b180a8538229ef547957f7e04bd3d3e9a55c7c5b7d24354abbba70", [:mix], [{:hackney, "~> 1.16", [hex: :hackney, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm", "0eceddaa9785cfcefbf3cd37812705f9d8ad34a758e513bb975b081dce4eb11e"}, @@ -12,21 +11,18 @@ "gen_state_machine": {:hex, :gen_state_machine, "3.0.0", "1e57f86a494e5c6b14137ebef26a7eb342b3b0070c7135f2d6768ed3f6b6cdff", [:mix], [], "hexpm", "0a59652574bebceb7309f6b749d2a41b45fdeda8dbb4da0791e355dd19f0ed15"}, "hackney": {:hex, :hackney, "1.18.1", "f48bf88f521f2a229fc7bae88cf4f85adc9cd9bcf23b5dc8eb6a1788c662c4f6", [:rebar3], [{:certifi, "~>2.9.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "~>6.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "~>1.0.0", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "~>1.1", [hex: :mimerl, repo: "hexpm", optional: false]}, {:parse_trans, "3.3.1", [hex: :parse_trans, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "~>1.1.0", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}, {:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "a4ecdaff44297e9b5894ae499e9a070ea1888c84afdd1fd9b7b2bc384950128e"}, "idna": {:hex, :idna, "6.1.1", "8a63070e9f7d0c62eb9d9fcb360a7de382448200fbbd1b106cc96d3d8099df8d", [:rebar3], [{:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "92376eb7894412ed19ac475e4a86f7b413c1b9fbb5bd16dccd57934157944cea"}, - "jason": {:hex, :jason, "1.4.0", "e855647bc964a44e2f67df589ccf49105ae039d4179db7f6271dfd3843dc27e6", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "79a3791085b2a0f743ca04cec0f7be26443738779d09302e01318f97bdb82121"}, - "makeup": {:hex, :makeup, "1.0.5", "d5a830bc42c9800ce07dd97fa94669dfb93d3bf5fcf6ea7a0c67b2e0e4a7f26c", [:mix], [{:nimble_parsec, "~> 0.5 or ~> 1.0", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "cfa158c02d3f5c0c665d0af11512fed3fba0144cf1aadee0f2ce17747fba2ca9"}, - "makeup_elixir": {:hex, :makeup_elixir, "0.15.2", "dc72dfe17eb240552857465cc00cce390960d9a0c055c4ccd38b70629227e97c", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.1", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "fd23ae48d09b32eff49d4ced2b43c9f086d402ee4fd4fcb2d7fad97fa8823e75"}, - "makeup_erlang": {:hex, :makeup_erlang, "0.1.1", "3fcb7f09eb9d98dc4d208f49cc955a34218fc41ff6b84df7c75b3e6e533cc65f", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "174d0809e98a4ef0b3309256cbf97101c6ec01c4ab0b23e926a9e17df2077cbb"}, + "jason": {:hex, :jason, "1.4.1", "af1504e35f629ddcdd6addb3513c3853991f694921b1b9368b0bd32beb9f1b63", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "fbb01ecdfd565b56261302f7e1fcc27c4fb8f32d56eab74db621fc154604a7a1"}, + "makeup": {:hex, :makeup, "1.1.0", "6b67c8bc2882a6b6a445859952a602afc1a41c2e08379ca057c0f525366fc3ca", [:mix], [{:nimble_parsec, "~> 1.2.2 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "0a45ed501f4a8897f580eabf99a2e5234ea3e75a4373c8a52824f6e873be57a6"}, + "makeup_elixir": {:hex, :makeup_elixir, "0.16.1", "cc9e3ca312f1cfeccc572b37a09980287e243648108384b97ff2b76e505c3555", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.2.3 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "e127a341ad1b209bd80f7bd1620a15693a9908ed780c3b763bccf7d200c767c6"}, + "makeup_erlang": {:hex, :makeup_erlang, "0.1.2", "ad87296a092a46e03b7e9b0be7631ddcf64c790fa68a9ef5323b6cbb36affc72", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "f3f5a1ca93ce6e092d92b6d9c049bcda58a3b617a8d888f8e7231c85630e8108"}, "metrics": {:hex, :metrics, "1.0.1", "25f094dea2cda98213cecc3aeff09e940299d950904393b2a29d191c346a8486", [:rebar3], [], "hexpm", "69b09adddc4f74a40716ae54d140f93beb0fb8978d8636eaded0c31b6f099f16"}, "mimerl": {:hex, :mimerl, "1.2.0", "67e2d3f571088d5cfd3e550c383094b47159f3eee8ffa08e64106cdf5e981be3", [:rebar3], [], "hexpm", "f278585650aa581986264638ebf698f8bb19df297f66ad91b18910dfc6e19323"}, - "mix_test_watch": {:hex, :mix_test_watch, "1.0.2", "34900184cbbbc6b6ed616ed3a8ea9b791f9fd2088419352a6d3200525637f785", [:mix], [{:file_system, "~> 0.2.1 or ~> 0.3", [hex: :file_system, repo: "hexpm", optional: false]}], "hexpm", "47ac558d8b06f684773972c6d04fcc15590abdb97aeb7666da19fcbfdc441a07"}, - "mox": {:hex, :mox, "1.0.0", "4b3c7005173f47ff30641ba044eb0fe67287743eec9bd9545e37f3002b0a9f8b", [:mix], [], "hexpm", "201b0a20b7abdaaab083e9cf97884950f8a30a1350a1da403b3145e213c6f4df"}, - "nimble_parsec": {:hex, :nimble_parsec, "1.2.0", "b44d75e2a6542dcb6acf5d71c32c74ca88960421b6874777f79153bbbbd7dccc", [:mix], [], "hexpm", "52b2871a7515a5ac49b00f214e4165a40724cf99798d8e4a65e4fd64ebd002c1"}, + "mix_test_watch": {:hex, :mix_test_watch, "1.0.3", "63d5b21e9278abf519f359e6d59aed704ed3c72ec38be6ab22306ae5dc9a2e06", [:mix], [{:file_system, "~> 0.2.1 or ~> 0.3", [hex: :file_system, repo: "hexpm", optional: false]}], "hexpm", "7352e91952d9748fb4f8aebe0a60357cdaf4bd6d6c42b5139c78fbcda6a0d7a2"}, + "mox": {:hex, :mox, "1.0.2", "dc2057289ac478b35760ba74165b4b3f402f68803dd5aecd3bfd19c183815d64", [:mix], [], "hexpm", "f9864921b3aaf763c8741b5b8e6f908f44566f1e427b2630e89e9a73b981fef2"}, + "nimble_parsec": {:hex, :nimble_parsec, "1.3.1", "2c54013ecf170e249e9291ed0a62e5832f70a476c61da16f6aac6dca0189f2af", [:mix], [], "hexpm", "2682e3c0b2eb58d90c6375fc0cc30bc7be06f365bf72608804fb9cffa5e1b167"}, "parse_trans": {:hex, :parse_trans, "3.3.1", "16328ab840cc09919bd10dab29e431da3af9e9e7e7e6f0089dd5a2d2820011d8", [:rebar3], [], "hexpm", "07cd9577885f56362d414e8c4c4e6bdf10d43a8767abb92d24cbe8b24c54888b"}, "ranch": {:hex, :ranch, "1.8.0", "8c7a100a139fd57f17327b6413e4167ac559fbc04ca7448e9be9057311597a1d", [:make, :rebar3], [], "hexpm", "49fbcfd3682fab1f5d109351b61257676da1a2fdbe295904176d5e521a2ddfe5"}, - "redbug": {:git, "git@github.com:massemanet/redbug.git", "a249400ee173e1cb7db37e725df973a7a3b0d9b9", []}, - "replbug": {:git, "https://github.com/bokner/replbug.git", "0670e5d07c909a8635fb2aae79cc220696c26a2a", []}, - "rexbug": {:hex, :rexbug, "1.0.6", "024071c67d970151fbdc06f299faf8db3e1b2ac759a28623a9cc80a517fc74f2", [:mix], [{:mix_test_watch, ">= 0.5.0", [hex: :mix_test_watch, repo: "hexpm", optional: true]}, {:redbug, "~> 1.2", [hex: :redbug, repo: "hexpm", optional: false]}], "hexpm", "148ea724979413e9fd84ca3b4bb5d2d8b840ac481adfd645f5846fda409a642c"}, - "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.6", "cf344f5692c82d2cd7554f5ec8fd961548d4fd09e7d22f5b62482e5aeaebd4b0", [:make, :mix, :rebar3], [], "hexpm", "bdb0d2471f453c88ff3908e7686f86f9be327d065cc1ec16fa4540197ea04680"}, - "telemetry": {:hex, :telemetry, "1.1.0", "a589817034a27eab11144ad24d5c0f9fab1f58173274b1e9bae7074af9cbee51", [:rebar3], [], "hexpm", "b727b2a1f75614774cff2d7565b64d0dfa5bd52ba517f16543e6fc7efcc0df48"}, + "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.7", "354c321cf377240c7b8716899e182ce4890c5938111a1296add3ec74cf1715df", [:make, :mix, :rebar3], [], "hexpm", "fe4c190e8f37401d30167c8c405eda19469f34577987c76dde613e838bbc67f8"}, + "telemetry": {:hex, :telemetry, "1.2.1", "68fdfe8d8f05a8428483a97d7aab2f268aaff24b49e0f599faa091f1d4e7f61c", [:rebar3], [], "hexpm", "dad9ce9d8effc621708f99eac538ef1cbe05d6a874dd741de2e689c47feafed5"}, "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.0", "bc84380c9ab48177092f43ac89e4dfa2c6d62b40b8bd132b1059ecc7232f9a78", [:rebar3], [], "hexpm", "25eee6d67df61960cf6a794239566599b09e17e668d3700247bc498638152521"}, } diff --git a/test/client_test.exs b/test/client_test.exs index 4e38750..e01e332 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -10,8 +10,6 @@ defmodule ClientTest do setup :verify_on_exit! setup :set_mox_global - @default_port 4090 - setup do attach_telemetry() on_exit(fn -> detach_telemetry() end) @@ -201,6 +199,7 @@ defmodule ClientTest do describe "send/2" do setup do + Logger.configure(level: :debug) setup_client_receiver() end @@ -216,75 +215,50 @@ defmodule ClientTest do end test "when replies are fragmented", ctx do - raw_hl7 = HL7.Examples.wikipedia_sample_hl7() - message = HL7.Message.new(raw_hl7) - packet = MLLP.Envelope.wrap_message(raw_hl7) + raw_hl7 = HL7.Examples.nist_immunization_hl7() - tcp_reply1 = - MLLP.Envelope.wrap_message( - "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|01052901|P|2.5\rMSA|AA|01052901|You win!\r" - ) + message = HL7.Message.new(raw_hl7) - {ack_frag1, ack_frag2} = String.split_at(tcp_reply1, 50) expected_ack = %MLLP.Ack{acknowledgement_code: "AA", text_message: ""} - assert( - {:ok, :application_accept, expected_ack} == - Client.send(ctx.client, message) - ) + log = + capture_log([level: :debug], fn -> + {:ok, :application_accept, expected_ack} == + Client.send(ctx.client, message) + end) - {ack_frag1, ack_frag2} = String.split_at(tcp_reply1, 50) + fragment_log = "Client #{inspect(ctx.client)} received a MLLP fragment" + ## One fragment... + assert count_occurences(log, fragment_log) == 1 + ## ..before the MLLP is fully received + received_log = "Client #{inspect(ctx.client)} received a full MLLP!" + num_receives = count_occurences(log, received_log) - {ack_frag2, ack_frag3} = String.split_at(ack_frag2, 10) - - assert( - {:ok, :application_accept, expected_ack} == - Client.send(ctx.client, message) - ) + assert num_receives == 1 end - test "when replies are fragmented and the last fragment is not received" do - address = {127, 0, 0, 1} - port = 4090 - socket = make_ref() - raw_hl7 = HL7.Examples.wikipedia_sample_hl7() - message = HL7.Message.new(raw_hl7) - packet = MLLP.Envelope.wrap_message(raw_hl7) - - tcp_reply1 = - MLLP.Envelope.wrap_message( - "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|01052901|P|2.5\rMSA|AA|01052901|You win!\r" - ) - - {ack_frag1, ack_frag2} = String.split_at(tcp_reply1, 50) - - {ack_frag2, _ack_frag3} = String.split_at(ack_frag2, 10) + test "when replies are fragmented and the last fragment is not received", ctx do + ## for this HL7 message, TestDispatcher implementation cuts the trailer (note NOTRAILER) + ## , which should result in the client timing out while waiting for the last fragment. + message = + "MSH|^~\\&|SuperOE|XYZImgCtr|MegaReg|XYZHospC|20060529090131-0500||ACK^O01|NOTRAILER|P|2.5\rMSA|AA|NOTRAILER\r" - MLLP.TCPMock - |> expect( - :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> - {:ok, socket} - end - ) - |> expect(:send, fn ^socket, ^packet -> :ok end) + expected_err = %MLLP.Client.Error{context: :recv, reason: :timeout, message: "timed out"} - {:ok, client} = - Client.start_link(address, port, - tcp: MLLP.TCPMock, - use_backoff: true, - reply_timeout: 3 - ) + log = + capture_log([level: :debug], fn -> + {:error, expected_err} == + Client.send(ctx.client, message, %{reply_timeout: 1000}) + end) - expected_err = %MLLP.Client.Error{context: :recv, reason: :timeout, message: "timed out"} + fragment_log = "Client #{inspect(ctx.client)} received a MLLP fragment" + ## One fragment... + assert count_occurences(log, fragment_log) == 1 + ## ..before the MLLP is fully received + received_log = "Client #{inspect(ctx.client)} received a full MLLP!" + num_receives = count_occurences(log, received_log) - assert( - {:error, expected_err} == - Client.send(client, message) - ) + assert num_receives == 0 end test "when reply header is invalid", ctx do @@ -304,17 +278,12 @@ defmodule ClientTest do ) end - test "when given non hl7" do - address = {127, 0, 0, 1} - port = 4090 - - socket = make_ref() - message = "Hello, it's me" + test "when given non hl7", ctx do + message = HL7.Examples.nist_immunization_hl7() - {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCP) - assert Client.is_connected?(client) + assert Client.is_connected?(ctx.client) - assert {:ok, "NACK"} = Client.send(client, message) + assert {:ok, message} = Client.send(ctx.client, message) end test "when server closes connection on send" do @@ -474,6 +443,10 @@ defmodule ClientTest do :telemetry.detach("telemetry_events") end + defp count_occurences(str, substr) do + str |> String.split(substr) |> length() |> Kernel.-(1) + end + defmodule TestDispatcher do require Logger @@ -485,18 +458,17 @@ defmodule ClientTest do def dispatch(:mllp_hl7, message, state) when is_binary(message) do reply = - MLLP.Ack.get_ack_for_message( - message, - :application_accept - ) + message + |> MLLP.Ack.get_ack_for_message(:application_accept) |> to_string() + |> Kernel.<>(message) |> wrap_message() {:ok, %{state | reply_buffer: reply}} end def dispatch(non_hl7_type, message, state) do - {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message("NACK")}} + {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message("NIST")}} end defp wrap_message(message) do @@ -504,6 +476,13 @@ defmodule ClientTest do message else MLLP.Envelope.wrap_message(message) + |> then(fn wrapped_message -> + if String.contains?(wrapped_message, "NOTRAILER") do + String.slice(wrapped_message, 0, String.length(message) - 1) + else + wrapped_message + end + end) end end end From a1174f4e75c5a5571ad703d677f467819c60f234 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Mon, 10 Jul 2023 17:50:56 -0400 Subject: [PATCH 14/47] Switching to latest elixir_hl7 breaks the tests --- mix.exs | 2 +- mix.lock | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/mix.exs b/mix.exs index e81e6c1..ff0709c 100644 --- a/mix.exs +++ b/mix.exs @@ -36,7 +36,7 @@ defmodule MLLP.MixProject do [ {:telemetry, "~> 1.0"}, {:ranch, "~> 1.8.0"}, - {:elixir_hl7, "~> 0.6.0"}, + {:elixir_hl7, "== 0.6.2"}, {:backoff, "~> 1.1.6"}, {:gen_state_machine, "~> 3.0"}, {:ex_doc, "~> 0.24.2", only: :dev, runtime: false}, diff --git a/mix.lock b/mix.lock index 8e726eb..2b500b9 100644 --- a/mix.lock +++ b/mix.lock @@ -3,7 +3,7 @@ "certifi": {:hex, :certifi, "2.9.0", "6f2a475689dd47f19fb74334859d460a2dc4e3252a3324bd2111b8f0429e7e21", [:rebar3], [], "hexpm", "266da46bdb06d6c6d35fde799bcb28d36d985d424ad7c08b5bb48f5b5cdd4641"}, "dialyxir": {:hex, :dialyxir, "1.1.0", "c5aab0d6e71e5522e77beff7ba9e08f8e02bad90dfbeffae60eaf0cb47e29488", [:mix], [{:erlex, ">= 0.2.6", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "07ea8e49c45f15264ebe6d5b93799d4dd56a44036cf42d0ad9c960bc266c0b9a"}, "earmark_parser": {:hex, :earmark_parser, "1.4.33", "3c3fd9673bb5dcc9edc28dd90f50c87ce506d1f71b70e3de69aa8154bc695d44", [:mix], [], "hexpm", "2d526833729b59b9fdb85785078697c72ac5e5066350663e5be6a1182da61b8f"}, - "elixir_hl7": {:hex, :elixir_hl7, "0.6.6", "ae01b991eb1aa8d199bb75006a87f3f37f02238a82443bea7cd5f36c7f70204a", [:mix], [], "hexpm", "8e9fd9ad2512f9560a4176c4ae9e9613bee4857103b2521a76aa47fbdc26369c"}, + "elixir_hl7": {:hex, :elixir_hl7, "0.6.2", "b066608f2e63258da596d99794745ab42cb4e62ac9b363014d1611b49146da07", [:mix], [], "hexpm", "43db06b2f9333581b02a03ada7a22c3406088cd9b4564a60b2ab63e2191e5ee9"}, "erlex": {:hex, :erlex, "0.2.6", "c7987d15e899c7a2f34f5420d2a2ea0d659682c06ac607572df55a43753aa12e", [:mix], [], "hexpm", "2ed2e25711feb44d52b17d2780eabf998452f6efda104877a3881c2f8c0c0c75"}, "ex_doc": {:hex, :ex_doc, "0.24.2", "e4c26603830c1a2286dae45f4412a4d1980e1e89dc779fcd0181ed1d5a05c8d9", [:mix], [{:earmark_parser, "~> 1.4.0", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "e134e1d9e821b8d9e4244687fb2ace58d479b67b282de5158333b0d57c6fb7da"}, "excoveralls": {:hex, :excoveralls, "0.14.6", "610e921e25b180a8538229ef547957f7e04bd3d3e9a55c7c5b7d24354abbba70", [:mix], [{:hackney, "~> 1.16", [hex: :hackney, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm", "0eceddaa9785cfcefbf3cd37812705f9d8ad34a758e513bb975b081dce4eb11e"}, From 2daeb38c0174467f45f280d30c098ef8807d1833 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Mon, 10 Jul 2023 17:52:18 -0400 Subject: [PATCH 15/47] Fix some tests --- lib/mllp/client.ex | 2 +- test/client_test.exs | 12 ++++++------ 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 0254512..c85277c 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -463,7 +463,7 @@ defmodule MLLP.Client do {:keep_state_and_data, [{:reply, from, :ok}]} end - def connected(:info, {transport, socket, data} = msg, %{socket: socket} = state) + def connected(:info, {transport, socket, _data} = msg, %{socket: socket} = state) when transport in [:tcp, :ssl] do receiving(:info, msg, state) end diff --git a/test/client_test.exs b/test/client_test.exs index e01e332..3434665 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -279,11 +279,11 @@ defmodule ClientTest do end test "when given non hl7", ctx do - message = HL7.Examples.nist_immunization_hl7() + message = "NON HL7" assert Client.is_connected?(ctx.client) - assert {:ok, message} = Client.send(ctx.client, message) + assert {:ok, message} == Client.send(ctx.client, message) end test "when server closes connection on send" do @@ -308,7 +308,7 @@ defmodule ClientTest do {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock) - assert {:error, %Error{message: "connection closed", context: :send}} = + assert {:error, %Error{message: "connection closed", context: :send, reason: :closed}} == Client.send(client, message) end end @@ -375,7 +375,7 @@ defmodule ClientTest do {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCPMock) - assert {:error, %Error{message: "connection closed", context: :send}} = + assert {:error, %Error{message: "connection closed", context: :send, reason: :closed}} == Client.send_async(client, message) end end @@ -467,8 +467,8 @@ defmodule ClientTest do {:ok, %{state | reply_buffer: reply}} end - def dispatch(non_hl7_type, message, state) do - {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message("NIST")}} + def dispatch(_non_hl7_type, message, state) do + {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message(message)}} end defp wrap_message(message) do From 903d7797a4cb591f95e2eb5eb462af4c08d13311 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 11 Jul 2023 09:13:55 -0400 Subject: [PATCH 16/47] Fix flaky test (disconnect on server side could result either in :closed or :einval depending on timing of send call) --- lib/mllp/client.ex | 13 +++++++------ test/client_and_receiver_integration_test.exs | 12 ++++++++---- 2 files changed, 15 insertions(+), 10 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index c85277c..638ea73 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -3,7 +3,7 @@ defmodule MLLP.ClientContract do MLLP.ClientContract provides the behavior implemented by MLLP.Client. It may be useful for testing in your own application with tools such as [`Mox`](https://hexdocs.pm/mox/) """ - @type error_type :: :connect_failure | :send_error | :recv_error + @type error_type :: :tcp_error | :send_error | :recv_error @type error_reason :: :closed | :timeout | :no_socket | :inet.posix() @type client_error :: MLLP.Client.Error.t() @@ -162,7 +162,7 @@ defmodule MLLP.Client do pid: nil, telemetry_module: nil, tcp: nil, - connect_failure: nil, + tcp_error: nil, host_string: nil, send_opts: %{}, tls_opts: [], @@ -404,7 +404,7 @@ defmodule MLLP.Client do end def disconnected({:call, from}, {:send, _message, _options}, state) do - actions = [{:reply, from, {:error, new_error(:send, state.connect_failure)}}] + actions = [{:reply, from, {:error, new_error(:send, state.tcp_error)}}] {:keep_state_and_data, actions} end @@ -603,7 +603,7 @@ defmodule MLLP.Client do |> tap(fn state -> telemetry( :status, - %{status: :disconnected, error: format_error(reason), context: "send message failure"}, + %{status: :disconnected, error: format_error(reason)}, state ) end) @@ -645,6 +645,7 @@ defmodule MLLP.Client do state |> Map.put(:socket, nil) + |> Map.put(:tcp_error, error) end defp backoff_succeed(%State{backoff: nil} = state), do: state @@ -665,7 +666,7 @@ defmodule MLLP.Client do |> backoff_succeed() telemetry(:status, %{status: :connected}, state1) - {:ok, %{state1 | socket: socket, connect_failure: nil}} + {:ok, %{state1 | socket: socket, tcp_error: nil}} {:error, reason} -> message = format_error(reason) @@ -680,7 +681,7 @@ defmodule MLLP.Client do {:error, state |> maybe_update_reconnection_timeout() - |> Map.put(:connect_failure, reason)} + |> Map.put(:tcp_error, reason)} end end diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 02454d3..ff4218d 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -221,10 +221,14 @@ defmodule ClientAndReceiverIntegrationTest do MLLP.Receiver.stop(port) refute Process.alive?(receiver_pid) - assert match?( - {:error, %Error{context: _, message: "connection closed"}}, - MLLP.Client.send(client_pid, "Simple message") - ) + {:error, %Error{context: context, message: message}} = + MLLP.Client.send(client_pid, "Simple message") + + assert context in [:send, :recv] + assert message in [MLLP.Client.format_error(:closed), MLLP.Client.format_error(:einval)] + + refute MLLP.Client.is_connected?(client_pid) + end test "with a larger message" do From ee9e428b45ed248e72fe78b5cbe77720277e7ad3 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 11 Jul 2023 09:46:00 -0400 Subject: [PATCH 17/47] Switch to gen_statem --- lib/mllp/client.ex | 31 +++++++++++-------- mix.exs | 1 - mix.lock | 1 - test/client_and_receiver_integration_test.exs | 1 - 4 files changed, 18 insertions(+), 16 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 638ea73..2cf28c4 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -131,7 +131,7 @@ defmodule MLLP.Client do @behaviour MLLP.ClientContract - use GenStateMachine, callback_mode: [:state_functions, :state_enter] + @behaviour :gen_statem @type pid_ref :: atom | pid | {atom, any} | {:via, atom, any} @type ip_address :: :inet.socket_address() | String.t() @@ -253,9 +253,10 @@ defmodule MLLP.Client do ) :: {:ok, pid()} def start_link(address, port, options \\ []) do - GenStateMachine.start_link( + :gen_statem.start_link( __MODULE__, - [address: normalize_address!(address), port: port] ++ options + [address: normalize_address!(address), port: port] ++ options, + [] ) end @@ -263,13 +264,13 @@ defmodule MLLP.Client do Returns true if the connection is open and established, otherwise false. """ @spec is_connected?(pid :: pid()) :: boolean() - def is_connected?(pid) when is_pid(pid), do: GenStateMachine.call(pid, :is_connected) + def is_connected?(pid) when is_pid(pid), do: :gen_statem.call(pid, :is_connected) @doc """ Instructs the client to disconnect (if connected) and attempt a reconnect. """ @spec reconnect(pid :: pid()) :: :ok - def reconnect(pid), do: GenStateMachine.call(pid, :reconnect) + def reconnect(pid), do: :gen_statem.call(pid, :reconnect) @doc """ Sends a message and receives a response. @@ -304,7 +305,7 @@ defmodule MLLP.Client do def send(pid, %HL7.Message{} = payload, options, timeout) do raw_message = to_string(payload) - case GenStateMachine.call(pid, {:send, raw_message, options}, timeout) do + case :gen_statem.call(pid, {:send, raw_message, options}, timeout) do {:ok, reply} -> verify_ack(reply, raw_message) @@ -314,7 +315,7 @@ defmodule MLLP.Client do end def send(pid, payload, options, timeout) do - case GenStateMachine.call(pid, {:send, payload, options}, timeout) do + case :gen_statem.call(pid, {:send, payload, options}, timeout) do {:ok, wrapped_message} -> {:ok, MLLP.Envelope.unwrap_message(wrapped_message)} @@ -337,22 +338,26 @@ defmodule MLLP.Client do end def send_async(pid, payload, timeout) when is_binary(payload) do - GenStateMachine.call(pid, {:send_async, payload, []}, timeout) + :gen_statem.call(pid, {:send_async, payload, []}, timeout) end @doc """ Stops an MLLP.Client given a MLLP.Client pid. - This function will always return `:ok` per `GenStateMachine.stop/1`, thus + This function will always return `:ok` per `:gen_statem.stop/1`, thus you may give it a pid that references a client which is already stopped. """ @spec stop(pid :: pid()) :: :ok - def stop(pid), do: GenStateMachine.stop(pid) + def stop(pid), do: :gen_statem.stop(pid) @header MLLP.Envelope.sb() @trailer MLLP.Envelope.eb_cr() - ## GenStateMachine callbacks + ## :gen_statem callbacks + @impl true + def callback_mode() do + [:state_functions, :state_enter] + end @impl true @spec init(Keyword.t()) :: @@ -540,7 +545,7 @@ defmodule MLLP.Client do end ######################################## - ### End of GenStateMachine callbacks ### + ### End of :gen_statem callbacks ### ######################################## defp unexpected_message(state, event, message) do @@ -578,7 +583,7 @@ defmodule MLLP.Client do end defp reply_to_caller(reply, %{caller: caller, context: context} = state) do - caller && GenStateMachine.reply(caller, format_reply(reply, context)) + caller && :gen_statem.reply(caller, format_reply(reply, context)) reply_cleanup(state) end diff --git a/mix.exs b/mix.exs index ff0709c..f3b92a2 100644 --- a/mix.exs +++ b/mix.exs @@ -38,7 +38,6 @@ defmodule MLLP.MixProject do {:ranch, "~> 1.8.0"}, {:elixir_hl7, "== 0.6.2"}, {:backoff, "~> 1.1.6"}, - {:gen_state_machine, "~> 3.0"}, {:ex_doc, "~> 0.24.2", only: :dev, runtime: false}, {:dialyxir, "~> 1.1.0", only: [:dev, :test], runtime: false}, {:mix_test_watch, "~> 1.0.2", only: :dev, runtime: false}, diff --git a/mix.lock b/mix.lock index 2b500b9..94050a2 100644 --- a/mix.lock +++ b/mix.lock @@ -8,7 +8,6 @@ "ex_doc": {:hex, :ex_doc, "0.24.2", "e4c26603830c1a2286dae45f4412a4d1980e1e89dc779fcd0181ed1d5a05c8d9", [:mix], [{:earmark_parser, "~> 1.4.0", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "e134e1d9e821b8d9e4244687fb2ace58d479b67b282de5158333b0d57c6fb7da"}, "excoveralls": {:hex, :excoveralls, "0.14.6", "610e921e25b180a8538229ef547957f7e04bd3d3e9a55c7c5b7d24354abbba70", [:mix], [{:hackney, "~> 1.16", [hex: :hackney, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm", "0eceddaa9785cfcefbf3cd37812705f9d8ad34a758e513bb975b081dce4eb11e"}, "file_system": {:hex, :file_system, "0.2.10", "fb082005a9cd1711c05b5248710f8826b02d7d1784e7c3451f9c1231d4fc162d", [:mix], [], "hexpm", "41195edbfb562a593726eda3b3e8b103a309b733ad25f3d642ba49696bf715dc"}, - "gen_state_machine": {:hex, :gen_state_machine, "3.0.0", "1e57f86a494e5c6b14137ebef26a7eb342b3b0070c7135f2d6768ed3f6b6cdff", [:mix], [], "hexpm", "0a59652574bebceb7309f6b749d2a41b45fdeda8dbb4da0791e355dd19f0ed15"}, "hackney": {:hex, :hackney, "1.18.1", "f48bf88f521f2a229fc7bae88cf4f85adc9cd9bcf23b5dc8eb6a1788c662c4f6", [:rebar3], [{:certifi, "~>2.9.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "~>6.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "~>1.0.0", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "~>1.1", [hex: :mimerl, repo: "hexpm", optional: false]}, {:parse_trans, "3.3.1", [hex: :parse_trans, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "~>1.1.0", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}, {:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "a4ecdaff44297e9b5894ae499e9a070ea1888c84afdd1fd9b7b2bc384950128e"}, "idna": {:hex, :idna, "6.1.1", "8a63070e9f7d0c62eb9d9fcb360a7de382448200fbbd1b106cc96d3d8099df8d", [:rebar3], [{:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "92376eb7894412ed19ac475e4a86f7b413c1b9fbb5bd16dccd57934157944cea"}, "jason": {:hex, :jason, "1.4.1", "af1504e35f629ddcdd6addb3513c3853991f694921b1b9368b0bd32beb9f1b63", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "fbb01ecdfd565b56261302f7e1fcc27c4fb8f32d56eab74db621fc154604a7a1"}, diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index ff4218d..852d486 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -228,7 +228,6 @@ defmodule ClientAndReceiverIntegrationTest do assert message in [MLLP.Client.format_error(:closed), MLLP.Client.format_error(:einval)] refute MLLP.Client.is_connected?(client_pid) - end test "with a larger message" do From 43489e516368a937f26e8b3bdcb21496515facd2 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 11 Jul 2023 12:14:06 -0400 Subject: [PATCH 18/47] Another flaky test --- test/client_and_receiver_integration_test.exs | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 852d486..718986b 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -390,13 +390,14 @@ defmodule ClientAndReceiverIntegrationTest do test "can restrict client if client IP is not allowed", ctx do {:ok, client_pid} = MLLP.Client.start_link("localhost", ctx.port) - exp = %Error{context: :recv, reason: :closed, message: "connection closed"} + {:error, error} = + MLLP.Client.send( + client_pid, + HL7.Examples.wikipedia_sample_hl7() |> HL7.Message.new() + ) - assert {:error, ^exp} = - MLLP.Client.send( - client_pid, - HL7.Examples.wikipedia_sample_hl7() |> HL7.Message.new() - ) + assert error.context in [:send, :recv] + assert error.reason == :closed end @tag allowed_clients: ["127.0.0.0", "localhost"] From 295a44ee606cd1b1889ff91546e0eac2a197e62a Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 11 Jul 2023 16:35:04 -0400 Subject: [PATCH 19/47] Add test for 'one-at-a-time' send request --- lib/mllp/client.ex | 2 +- test/client_test.exs | 17 +++++++++++++++++ 2 files changed, 18 insertions(+), 1 deletion(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 2cf28c4..df0e757 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -516,7 +516,7 @@ defmodule MLLP.Client do end def receiving({:call, from}, {:send, _message, _options}, _state) do - {:keep_state_and_data, [{:reply, from, {:error, :busy_with_other_call}}]} + {:keep_state_and_data, [{:reply, from, format_reply({:error, :busy_with_other_call}, :send)}]} end def receiving(:state_timeout, :receive_timeout, state) do diff --git a/test/client_test.exs b/test/client_test.exs index 3434665..cd2c4a3 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -311,6 +311,23 @@ defmodule ClientTest do assert {:error, %Error{message: "connection closed", context: :send, reason: :closed}} == Client.send(client, message) end + + test "one send request at a time", ctx do + test_message = "test_one_send_at_a_time" + + concurrent_requests = + Task.async_stream(1..2, fn _i -> Client.send(ctx.client, test_message) end) + |> Enum.map(fn {:ok, res} -> res end) + + assert length(concurrent_requests) == 2 + + assert Enum.count(concurrent_requests, fn resp -> + case resp do + {:ok, message} when message == test_message -> true + {:error, %MLLP.Client.Error{reason: :busy_with_other_call}} -> false + end + end) == 1 + end end describe "send_async/2" do From d85d863497478b625487d156745872da80f46d36 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 11 Jul 2023 16:46:07 -0400 Subject: [PATCH 20/47] Restore mix files --- mix.exs | 2 +- mix.lock | 20 ++++++++++---------- 2 files changed, 11 insertions(+), 11 deletions(-) diff --git a/mix.exs b/mix.exs index f3b92a2..a013de1 100644 --- a/mix.exs +++ b/mix.exs @@ -36,7 +36,7 @@ defmodule MLLP.MixProject do [ {:telemetry, "~> 1.0"}, {:ranch, "~> 1.8.0"}, - {:elixir_hl7, "== 0.6.2"}, + {:elixir_hl7, "~> 0.6.0"}, {:backoff, "~> 1.1.6"}, {:ex_doc, "~> 0.24.2", only: :dev, runtime: false}, {:dialyxir, "~> 1.1.0", only: [:dev, :test], runtime: false}, diff --git a/mix.lock b/mix.lock index 94050a2..cbd0c5a 100644 --- a/mix.lock +++ b/mix.lock @@ -2,7 +2,7 @@ "backoff": {:hex, :backoff, "1.1.6", "83b72ed2108ba1ee8f7d1c22e0b4a00cfe3593a67dbc792799e8cce9f42f796b", [:rebar3], [], "hexpm", "cf0cfff8995fb20562f822e5cc47d8ccf664c5ecdc26a684cbe85c225f9d7c39"}, "certifi": {:hex, :certifi, "2.9.0", "6f2a475689dd47f19fb74334859d460a2dc4e3252a3324bd2111b8f0429e7e21", [:rebar3], [], "hexpm", "266da46bdb06d6c6d35fde799bcb28d36d985d424ad7c08b5bb48f5b5cdd4641"}, "dialyxir": {:hex, :dialyxir, "1.1.0", "c5aab0d6e71e5522e77beff7ba9e08f8e02bad90dfbeffae60eaf0cb47e29488", [:mix], [{:erlex, ">= 0.2.6", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "07ea8e49c45f15264ebe6d5b93799d4dd56a44036cf42d0ad9c960bc266c0b9a"}, - "earmark_parser": {:hex, :earmark_parser, "1.4.33", "3c3fd9673bb5dcc9edc28dd90f50c87ce506d1f71b70e3de69aa8154bc695d44", [:mix], [], "hexpm", "2d526833729b59b9fdb85785078697c72ac5e5066350663e5be6a1182da61b8f"}, + "earmark_parser": {:hex, :earmark_parser, "1.4.17", "6f3c7e94170377ba45241d394389e800fb15adc5de51d0a3cd52ae766aafd63f", [:mix], [], "hexpm", "f93ac89c9feca61c165b264b5837bf82344d13bebc634cd575cb711e2e342023"}, "elixir_hl7": {:hex, :elixir_hl7, "0.6.2", "b066608f2e63258da596d99794745ab42cb4e62ac9b363014d1611b49146da07", [:mix], [], "hexpm", "43db06b2f9333581b02a03ada7a22c3406088cd9b4564a60b2ab63e2191e5ee9"}, "erlex": {:hex, :erlex, "0.2.6", "c7987d15e899c7a2f34f5420d2a2ea0d659682c06ac607572df55a43753aa12e", [:mix], [], "hexpm", "2ed2e25711feb44d52b17d2780eabf998452f6efda104877a3881c2f8c0c0c75"}, "ex_doc": {:hex, :ex_doc, "0.24.2", "e4c26603830c1a2286dae45f4412a4d1980e1e89dc779fcd0181ed1d5a05c8d9", [:mix], [{:earmark_parser, "~> 1.4.0", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "e134e1d9e821b8d9e4244687fb2ace58d479b67b282de5158333b0d57c6fb7da"}, @@ -10,18 +10,18 @@ "file_system": {:hex, :file_system, "0.2.10", "fb082005a9cd1711c05b5248710f8826b02d7d1784e7c3451f9c1231d4fc162d", [:mix], [], "hexpm", "41195edbfb562a593726eda3b3e8b103a309b733ad25f3d642ba49696bf715dc"}, "hackney": {:hex, :hackney, "1.18.1", "f48bf88f521f2a229fc7bae88cf4f85adc9cd9bcf23b5dc8eb6a1788c662c4f6", [:rebar3], [{:certifi, "~>2.9.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "~>6.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "~>1.0.0", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "~>1.1", [hex: :mimerl, repo: "hexpm", optional: false]}, {:parse_trans, "3.3.1", [hex: :parse_trans, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "~>1.1.0", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}, {:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "a4ecdaff44297e9b5894ae499e9a070ea1888c84afdd1fd9b7b2bc384950128e"}, "idna": {:hex, :idna, "6.1.1", "8a63070e9f7d0c62eb9d9fcb360a7de382448200fbbd1b106cc96d3d8099df8d", [:rebar3], [{:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "92376eb7894412ed19ac475e4a86f7b413c1b9fbb5bd16dccd57934157944cea"}, - "jason": {:hex, :jason, "1.4.1", "af1504e35f629ddcdd6addb3513c3853991f694921b1b9368b0bd32beb9f1b63", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "fbb01ecdfd565b56261302f7e1fcc27c4fb8f32d56eab74db621fc154604a7a1"}, - "makeup": {:hex, :makeup, "1.1.0", "6b67c8bc2882a6b6a445859952a602afc1a41c2e08379ca057c0f525366fc3ca", [:mix], [{:nimble_parsec, "~> 1.2.2 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "0a45ed501f4a8897f580eabf99a2e5234ea3e75a4373c8a52824f6e873be57a6"}, - "makeup_elixir": {:hex, :makeup_elixir, "0.16.1", "cc9e3ca312f1cfeccc572b37a09980287e243648108384b97ff2b76e505c3555", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.2.3 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "e127a341ad1b209bd80f7bd1620a15693a9908ed780c3b763bccf7d200c767c6"}, - "makeup_erlang": {:hex, :makeup_erlang, "0.1.2", "ad87296a092a46e03b7e9b0be7631ddcf64c790fa68a9ef5323b6cbb36affc72", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "f3f5a1ca93ce6e092d92b6d9c049bcda58a3b617a8d888f8e7231c85630e8108"}, + "jason": {:hex, :jason, "1.4.0", "e855647bc964a44e2f67df589ccf49105ae039d4179db7f6271dfd3843dc27e6", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "79a3791085b2a0f743ca04cec0f7be26443738779d09302e01318f97bdb82121"}, + "makeup": {:hex, :makeup, "1.0.5", "d5a830bc42c9800ce07dd97fa94669dfb93d3bf5fcf6ea7a0c67b2e0e4a7f26c", [:mix], [{:nimble_parsec, "~> 0.5 or ~> 1.0", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "cfa158c02d3f5c0c665d0af11512fed3fba0144cf1aadee0f2ce17747fba2ca9"}, + "makeup_elixir": {:hex, :makeup_elixir, "0.15.2", "dc72dfe17eb240552857465cc00cce390960d9a0c055c4ccd38b70629227e97c", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.1", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "fd23ae48d09b32eff49d4ced2b43c9f086d402ee4fd4fcb2d7fad97fa8823e75"}, + "makeup_erlang": {:hex, :makeup_erlang, "0.1.1", "3fcb7f09eb9d98dc4d208f49cc955a34218fc41ff6b84df7c75b3e6e533cc65f", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "174d0809e98a4ef0b3309256cbf97101c6ec01c4ab0b23e926a9e17df2077cbb"}, "metrics": {:hex, :metrics, "1.0.1", "25f094dea2cda98213cecc3aeff09e940299d950904393b2a29d191c346a8486", [:rebar3], [], "hexpm", "69b09adddc4f74a40716ae54d140f93beb0fb8978d8636eaded0c31b6f099f16"}, "mimerl": {:hex, :mimerl, "1.2.0", "67e2d3f571088d5cfd3e550c383094b47159f3eee8ffa08e64106cdf5e981be3", [:rebar3], [], "hexpm", "f278585650aa581986264638ebf698f8bb19df297f66ad91b18910dfc6e19323"}, - "mix_test_watch": {:hex, :mix_test_watch, "1.0.3", "63d5b21e9278abf519f359e6d59aed704ed3c72ec38be6ab22306ae5dc9a2e06", [:mix], [{:file_system, "~> 0.2.1 or ~> 0.3", [hex: :file_system, repo: "hexpm", optional: false]}], "hexpm", "7352e91952d9748fb4f8aebe0a60357cdaf4bd6d6c42b5139c78fbcda6a0d7a2"}, - "mox": {:hex, :mox, "1.0.2", "dc2057289ac478b35760ba74165b4b3f402f68803dd5aecd3bfd19c183815d64", [:mix], [], "hexpm", "f9864921b3aaf763c8741b5b8e6f908f44566f1e427b2630e89e9a73b981fef2"}, - "nimble_parsec": {:hex, :nimble_parsec, "1.3.1", "2c54013ecf170e249e9291ed0a62e5832f70a476c61da16f6aac6dca0189f2af", [:mix], [], "hexpm", "2682e3c0b2eb58d90c6375fc0cc30bc7be06f365bf72608804fb9cffa5e1b167"}, + "mix_test_watch": {:hex, :mix_test_watch, "1.0.2", "34900184cbbbc6b6ed616ed3a8ea9b791f9fd2088419352a6d3200525637f785", [:mix], [{:file_system, "~> 0.2.1 or ~> 0.3", [hex: :file_system, repo: "hexpm", optional: false]}], "hexpm", "47ac558d8b06f684773972c6d04fcc15590abdb97aeb7666da19fcbfdc441a07"}, + "mox": {:hex, :mox, "1.0.0", "4b3c7005173f47ff30641ba044eb0fe67287743eec9bd9545e37f3002b0a9f8b", [:mix], [], "hexpm", "201b0a20b7abdaaab083e9cf97884950f8a30a1350a1da403b3145e213c6f4df"}, + "nimble_parsec": {:hex, :nimble_parsec, "1.2.0", "b44d75e2a6542dcb6acf5d71c32c74ca88960421b6874777f79153bbbbd7dccc", [:mix], [], "hexpm", "52b2871a7515a5ac49b00f214e4165a40724cf99798d8e4a65e4fd64ebd002c1"}, "parse_trans": {:hex, :parse_trans, "3.3.1", "16328ab840cc09919bd10dab29e431da3af9e9e7e7e6f0089dd5a2d2820011d8", [:rebar3], [], "hexpm", "07cd9577885f56362d414e8c4c4e6bdf10d43a8767abb92d24cbe8b24c54888b"}, "ranch": {:hex, :ranch, "1.8.0", "8c7a100a139fd57f17327b6413e4167ac559fbc04ca7448e9be9057311597a1d", [:make, :rebar3], [], "hexpm", "49fbcfd3682fab1f5d109351b61257676da1a2fdbe295904176d5e521a2ddfe5"}, - "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.7", "354c321cf377240c7b8716899e182ce4890c5938111a1296add3ec74cf1715df", [:make, :mix, :rebar3], [], "hexpm", "fe4c190e8f37401d30167c8c405eda19469f34577987c76dde613e838bbc67f8"}, - "telemetry": {:hex, :telemetry, "1.2.1", "68fdfe8d8f05a8428483a97d7aab2f268aaff24b49e0f599faa091f1d4e7f61c", [:rebar3], [], "hexpm", "dad9ce9d8effc621708f99eac538ef1cbe05d6a874dd741de2e689c47feafed5"}, + "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.6", "cf344f5692c82d2cd7554f5ec8fd961548d4fd09e7d22f5b62482e5aeaebd4b0", [:make, :mix, :rebar3], [], "hexpm", "bdb0d2471f453c88ff3908e7686f86f9be327d065cc1ec16fa4540197ea04680"}, + "telemetry": {:hex, :telemetry, "1.1.0", "a589817034a27eab11144ad24d5c0f9fab1f58173274b1e9bae7074af9cbee51", [:rebar3], [], "hexpm", "b727b2a1f75614774cff2d7565b64d0dfa5bd52ba517f16543e6fc7efcc0df48"}, "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.0", "bc84380c9ab48177092f43ac89e4dfa2c6d62b40b8bd132b1059ecc7232f9a78", [:rebar3], [], "hexpm", "25eee6d67df61960cf6a794239566599b09e17e668d3700247bc498638152521"}, } From 2ec626cab55c80ac508ac6e5d8117ca57afaad00 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 08:34:36 -0400 Subject: [PATCH 21/47] Minor --- lib/mllp/client.ex | 4 +++- test/client_test.exs | 6 ++++-- 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index df0e757..9d62cf7 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -264,7 +264,7 @@ defmodule MLLP.Client do Returns true if the connection is open and established, otherwise false. """ @spec is_connected?(pid :: pid()) :: boolean() - def is_connected?(pid) when is_pid(pid), do: :gen_statem.call(pid, :is_connected) + def is_connected?(pid), do: :gen_statem.call(pid, :is_connected) @doc """ Instructs the client to disconnect (if connected) and attempt a reconnect. @@ -353,7 +353,9 @@ defmodule MLLP.Client do @header MLLP.Envelope.sb() @trailer MLLP.Envelope.eb_cr() + ## ## :gen_statem callbacks + ## @impl true def callback_mode() do [:state_functions, :state_enter] diff --git a/test/client_test.exs b/test/client_test.exs index cd2c4a3..7ba4457 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -315,11 +315,13 @@ defmodule ClientTest do test "one send request at a time", ctx do test_message = "test_one_send_at_a_time" + num_requests = 4 + concurrent_requests = - Task.async_stream(1..2, fn _i -> Client.send(ctx.client, test_message) end) + Task.async_stream(1..num_requests, fn _i -> Client.send(ctx.client, test_message) end) |> Enum.map(fn {:ok, res} -> res end) - assert length(concurrent_requests) == 2 + assert length(concurrent_requests) == num_requests assert Enum.count(concurrent_requests, fn resp -> case resp do From d297c5ae3ea15317c113179d5c2f53246ba99047 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 08:57:29 -0400 Subject: [PATCH 22/47] Fix flaky test for concurrent sends --- test/client_test.exs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index 7ba4457..0aea262 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -481,7 +481,7 @@ defmodule ClientTest do |> MLLP.Ack.get_ack_for_message(:application_accept) |> to_string() |> Kernel.<>(message) - |> wrap_message() + |> handle_message() {:ok, %{state | reply_buffer: reply}} end @@ -490,7 +490,9 @@ defmodule ClientTest do {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message(message)}} end - defp wrap_message(message) do + defp handle_message(message) do + ## Slow down the handling on receiver side + Process.sleep(10) if String.contains?(message, "DONOTWRAP") do message else From 1d66ece0ea904a831bff72ca9e5b1cc16ca36d36 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 09:08:25 -0400 Subject: [PATCH 23/47] Fix comments to the test case --- test/client_test.exs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/client_test.exs b/test/client_test.exs index 0aea262..7f69d45 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -254,7 +254,7 @@ defmodule ClientTest do fragment_log = "Client #{inspect(ctx.client)} received a MLLP fragment" ## One fragment... assert count_occurences(log, fragment_log) == 1 - ## ..before the MLLP is fully received + ## ..but the MLLP has not been fully received received_log = "Client #{inspect(ctx.client)} received a full MLLP!" num_receives = count_occurences(log, received_log) From 726cbf7e4152965c4c414059532d7ba5a2ed54bb Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 09:08:25 -0400 Subject: [PATCH 24/47] Fix comments to the test case --- test/client_test.exs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/client_test.exs b/test/client_test.exs index 0aea262..8de0c70 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -254,7 +254,7 @@ defmodule ClientTest do fragment_log = "Client #{inspect(ctx.client)} received a MLLP fragment" ## One fragment... assert count_occurences(log, fragment_log) == 1 - ## ..before the MLLP is fully received + ## ..but the MLLP has not been fully received received_log = "Client #{inspect(ctx.client)} received a full MLLP!" num_receives = count_occurences(log, received_log) @@ -493,6 +493,7 @@ defmodule ClientTest do defp handle_message(message) do ## Slow down the handling on receiver side Process.sleep(10) + if String.contains?(message, "DONOTWRAP") do message else From cbb6c8b97863e06f5c83bc7c118367793386e882 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 09:21:12 -0400 Subject: [PATCH 25/47] Another attempt to fix flaky 'concurrent sends' test --- test/client_test.exs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/client_test.exs b/test/client_test.exs index 8de0c70..a70bd37 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -492,7 +492,7 @@ defmodule ClientTest do defp handle_message(message) do ## Slow down the handling on receiver side - Process.sleep(10) + Process.sleep(100) if String.contains?(message, "DONOTWRAP") do message From 9b47271eeea14f2279e292c2493ba0871d8ccb89 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 10:36:17 -0400 Subject: [PATCH 26/47] Add 'responses match requests' test for concurrent requests --- test/client_test.exs | 35 ++++++++++++++++++++++++++++++++--- 1 file changed, 32 insertions(+), 3 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index a70bd37..8711737 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -313,7 +313,7 @@ defmodule ClientTest do end test "one send request at a time", ctx do - test_message = "test_one_send_at_a_time" + test_message = "Test one send at a time (asking receiver to SLOWDOWN to prevent flakiness)" num_requests = 4 @@ -330,6 +330,33 @@ defmodule ClientTest do end end) == 1 end + + test "responses to concurrent requests don't get mixed", ctx do + test_message = "test_concurrent_" + + num_requests = 10 + + concurrent_requests = + Task.async_stream(1..num_requests, fn request_id -> + {request_id, Client.send(ctx.client, test_message <> "#{request_id}")} + end) + |> Enum.map(fn {:ok, res} -> res end) + + ## All successful responses match the requests + assert Enum.all?( + concurrent_requests, + fn + {request_id, {:ok, incoming}} -> + incoming == test_message <> "#{request_id}" + + {_request_id, {:error, %MLLP.Client.Error{reason: :busy_with_other_call}}} -> + true + + _unexpected -> + false + end + ) + end end describe "send_async/2" do @@ -491,8 +518,10 @@ defmodule ClientTest do end defp handle_message(message) do - ## Slow down the handling on receiver side - Process.sleep(100) + ## Slow down the handling on receiver side, if required + if String.contains?(message, "SLOWDOWN") do + Process.sleep(100) + end if String.contains?(message, "DONOTWRAP") do message From 1dda940b7dcd77563d89ee4d598df106abc1976c Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 10:45:16 -0400 Subject: [PATCH 27/47] Update lib/mllp/client.ex Co-authored-by: Bryan Paxton <39971740+starbelly@users.noreply.github.com> --- lib/mllp/client.ex | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 9d62cf7..300e8a8 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -605,7 +605,8 @@ defmodule MLLP.Client do defp handle_error(reason, state) do Logger.error("Error: #{inspect(reason)}, state: #{inspect(state)}") - reply_to_caller({:error, new_error(get_context(state), reason)}, state) + {:error, new_error(get_context(state), reason)} + |> reply_to_caller(state) |> stop_connection(reason, "closing connection to cleanup") |> tap(fn state -> telemetry( From f95ed7a3520c0a94e7aa67e95a76c4980585d4a0 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 10:59:15 -0400 Subject: [PATCH 28/47] Fix TestDispatcher (ask receiver to slow down, if we want it to) --- test/client_test.exs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/client_test.exs b/test/client_test.exs index 8711737..f42d1ba 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -514,7 +514,7 @@ defmodule ClientTest do end def dispatch(_non_hl7_type, message, state) do - {:ok, %{state | reply_buffer: MLLP.Envelope.wrap_message(message)}} + {:ok, %{state | reply_buffer: handle_message(message)}} end defp handle_message(message) do From 2c2c4004f4bcf2668eeea9dabd5991e30c9e8354 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Wed, 12 Jul 2023 11:50:21 -0400 Subject: [PATCH 29/47] Bring the naming in line with :gen_statem (i.e., 'state' refers to FSM state, 'data' refers to process state) --- lib/mllp/client.ex | 176 ++++++++++++++++++++++----------------------- 1 file changed, 88 insertions(+), 88 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 300e8a8..227a69f 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -379,17 +379,17 @@ defmodule MLLP.Client do #### Disconnected state #### ############################ - def disconnected(:enter, :disconnected, state) do - {:keep_state, state, reconnect_action(state)} + def disconnected(:enter, :disconnected, data) do + {:keep_state, data, reconnect_action(data)} end - def disconnected(:enter, current_state, state) when current_state in [:connected, :receiving] do + def disconnected(:enter, current_state, data) when current_state in [:connected, :receiving] do Logger.error("Connection closed") - {:keep_state, state, reconnect_action(state)} + {:keep_state, data, reconnect_action(data)} end - def disconnected(:internal, :connect, state) do - {result, new_state} = attempt_connection(state) + def disconnected(:internal, :connect, data) do + {result, new_state} = attempt_connection(data) case result do :error -> @@ -410,41 +410,41 @@ defmodule MLLP.Client do {:keep_state_and_data, [{:reply, from, :ok}, {:next_event, :internal, :connect}]} end - def disconnected({:call, from}, {:send, _message, _options}, state) do - actions = [{:reply, from, {:error, new_error(:send, state.tcp_error)}}] + def disconnected({:call, from}, {:send, _message, _options}, data) do + actions = [{:reply, from, {:error, new_error(:send, data.tcp_error)}}] {:keep_state_and_data, actions} end - def disconnected({:call, from}, :is_connected, _state) do + def disconnected({:call, from}, :is_connected, _data) do {:keep_state_and_data, [{:reply, from, false}]} end - def disconnected(event, unknown, _state) do + def disconnected(event, unknown, _data) do unexpected_message(:disconnected, event, unknown) end ######################### #### Connected state #### ######################### - def connected(:enter, :disconnected, _state) do + def connected(:enter, :disconnected, _data) do Logger.debug("Connection established") :keep_state_and_data end - def connected(:enter, :receiving, _state) do + def connected(:enter, :receiving, _data) do :keep_state_and_data end - def connected({:call, from}, {send_type, message, options}, state) + def connected({:call, from}, {send_type, message, options}, data) when send_type in [:send, :send_async] do payload = MLLP.Envelope.wrap_message(message) - case state.tcp.send(state.socket, payload) do + case data.tcp.send(data.socket, payload) do :ok -> {:next_state, :receiving, - state + data |> Map.put(:context, :recv) - |> Map.put(:caller, from), send_action(send_type, from, options, state)} + |> Map.put(:caller, from), send_action(send_type, from, options, data)} {:error, reason} -> telemetry( @@ -454,7 +454,7 @@ defmodule MLLP.Client do error: format_error(reason), context: "send message failure" }, - state + data ) error_reply = {:error, new_error(:send, reason)} @@ -462,25 +462,25 @@ defmodule MLLP.Client do end end - def connected({:call, from}, :is_connected, _state) do + def connected({:call, from}, :is_connected, _data) do {:keep_state_and_data, [{:reply, from, true}]} end - def connected({:call, from}, :reconnect, _state) do + def connected({:call, from}, :reconnect, _data) do {:keep_state_and_data, [{:reply, from, :ok}]} end - def connected(:info, {transport, socket, _data} = msg, %{socket: socket} = state) + def connected(:info, {transport, socket, _incoming} = msg, %{socket: socket} = data) when transport in [:tcp, :ssl] do - receiving(:info, msg, state) + receiving(:info, msg, data) end - def connected(:info, {transport_closed, _socket}, state) + def connected(:info, {transport_closed, _socket}, data) when transport_closed in [:tcp_closed, :ssl_closed] do - {:next_state, :disconnected, handle_closed(state)} + {:next_state, :disconnected, handle_closed(data)} end - def connected(event, unknown, _state) do + def connected(event, unknown, _data) do unexpected_message(:connected, event, unknown) end @@ -490,12 +490,12 @@ defmodule MLLP.Client do [{:state_timeout, reconnect_timeout(backoff, auto_reconnect_interval), :reconnect}] end - defp send_action(:send, _from, options, state) do - reply_timeout = Map.get(options, :reply_timeout, state.send_opts.reply_timeout) + defp send_action(:send, _from, options, data) do + reply_timeout = Map.get(options, :reply_timeout, data.send_opts.reply_timeout) [{:state_timeout, reply_timeout, :receive_timeout}] end - defp send_action(:send_async, from, _options, _state) do + defp send_action(:send_async, from, _options, _data) do [{:reply, from, {:ok, :sent}}] end @@ -512,37 +512,37 @@ defmodule MLLP.Client do ######################### #### Receiving state #### ######################### - def receiving(:enter, :connected, _state) do + def receiving(:enter, :connected, _data) do Logger.debug("Waiting for response...") :keep_state_and_data end - def receiving({:call, from}, {:send, _message, _options}, _state) do + def receiving({:call, from}, {:send, _message, _options}, _data) do {:keep_state_and_data, [{:reply, from, format_reply({:error, :busy_with_other_call}, :send)}]} end - def receiving(:state_timeout, :receive_timeout, state) do - {:next_state, :connected, reply_to_caller({:error, :timeout}, state)} + def receiving(:state_timeout, :receive_timeout, data) do + {:next_state, :connected, reply_to_caller({:error, :timeout}, data)} end - def receiving(:info, {transport, socket, data}, %{socket: socket} = state) + def receiving(:info, {transport, socket, incoming}, %{socket: socket} = data) when transport in [:tcp, :ssl] do - new_data = handle_received(data, state) + new_data = handle_received(incoming, data) next_state = (new_data.caller && :receiving) || :connected {:next_state, next_state, new_data} end - def receiving(:info, {transport_closed, socket}, %{socket: socket} = state) + def receiving(:info, {transport_closed, socket}, %{socket: socket} = data) when transport_closed in [:tcp_closed, :ssl_closed] do - {:next_state, :disconnected, handle_closed(state)} + {:next_state, :disconnected, handle_closed(data)} end - def receiving(:info, {transport_error, socket, reason}, %{socket: socket} = state) + 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, state))} + {:next_state, :disconnected, handle_error(reason, maybe_close(reason, data))} end - def receiving(event, unknown, _state) do + def receiving(event, unknown, _data) do unexpected_message(:receiving, event, unknown) end @@ -560,12 +560,12 @@ defmodule MLLP.Client do ## Handle the (fragmented) responses to `send` request from a caller - defp handle_received(_reply, %{caller: nil} = state) do + defp handle_received(_reply, %{caller: nil} = data) do ## No caller, ignore - state + data end - defp handle_received(reply, %{receive_buffer: buffer} = state) do + defp handle_received(reply, %{receive_buffer: buffer} = data) do new_buf = (buffer && buffer <> reply) || reply check = byte_size(new_buf) - 3 @@ -573,20 +573,20 @@ defmodule MLLP.Client do <<@header, _ack::binary-size(check), @trailer>> -> ## The response is completed, send back to caller Logger.debug("Client #{inspect(self())} received a full MLLP!") - reply_to_caller({:ok, new_buf}, state) + reply_to_caller({:ok, new_buf}, data) <<@header, _rest::binary>> -> Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") - Map.put(state, :receive_buffer, new_buf) + Map.put(data, :receive_buffer, new_buf) _ -> - reply_to_caller({:error, :invalid_reply}, state) + reply_to_caller({:error, :invalid_reply}, data) end end - defp reply_to_caller(reply, %{caller: caller, context: context} = state) do + defp reply_to_caller(reply, %{caller: caller, context: context} = data) do caller && :gen_statem.reply(caller, format_reply(reply, context)) - reply_cleanup(state) + reply_cleanup(data) end defp format_reply({:ok, result}, _context) do @@ -597,109 +597,109 @@ defmodule MLLP.Client do {:error, new_error(context, error)} end - defp handle_closed(state) do - handle_error(:closed, state) + defp handle_closed(data) do + handle_error(:closed, data) end ## Handle transport errors - defp handle_error(reason, state) do - Logger.error("Error: #{inspect(reason)}, state: #{inspect(state)}") + defp handle_error(reason, data) do + Logger.error("Error: #{inspect(reason)}, data: #{inspect(data)}") - {:error, new_error(get_context(state), reason)} - |> reply_to_caller(state) + {:error, new_error(get_context(data), reason)} + |> reply_to_caller(data) |> stop_connection(reason, "closing connection to cleanup") - |> tap(fn state -> + |> tap(fn data -> telemetry( :status, %{status: :disconnected, error: format_error(reason)}, - state + data ) end) end - defp reply_cleanup(%State{} = state) do - state + defp reply_cleanup(%State{} = data) do + data |> Map.put(:caller, nil) |> Map.put(:receive_buffer, nil) end @doc false - def terminate(reason = :normal, state) do - Logger.debug("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") - stop_connection(state, reason, "process terminated") + def terminate(reason = :normal, data) do + Logger.debug("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(data)}") + stop_connection(data, reason, "process terminated") end - def terminate(reason, state) do - Logger.error("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(state)}") - stop_connection(state, reason, "process terminated") + def terminate(reason, data) do + Logger.error("Client socket terminated. Reason: #{inspect(reason)} State #{inspect(data)}") + stop_connection(data, reason, "process terminated") end - defp maybe_close(reason, %{close_on_recv_error: true, context: context} = state) do - stop_connection(state, reason, context) + defp maybe_close(reason, %{close_on_recv_error: true, context: context} = data) do + stop_connection(data, reason, context) end - defp maybe_close(_reason, state), do: state + defp maybe_close(_reason, data), do: data - defp stop_connection(%State{} = state, error, context) do - if state.socket != nil do + defp stop_connection(%State{} = data, error, context) do + if data.socket != nil do telemetry( :status, %{status: :disconnected, error: format_error(error), context: context}, - state + data ) - state.tcp.close(state.socket) + data.tcp.close(data.socket) end - state + data |> Map.put(:socket, nil) |> Map.put(:tcp_error, error) end - defp backoff_succeed(%State{backoff: nil} = state), do: state + defp backoff_succeed(%State{backoff: nil} = data), do: data - defp backoff_succeed(%State{backoff: backoff} = state) do + defp backoff_succeed(%State{backoff: backoff} = data) do {_, new_backoff} = :backoff.succeed(backoff) - %{state | backoff: new_backoff} + %{data | backoff: new_backoff} end - defp attempt_connection(%State{} = state) do - telemetry(:status, %{status: :connecting}, state) - opts = [:binary, {:packet, 0}, {:active, true}] ++ state.socket_opts ++ state.tls_opts + defp attempt_connection(%State{} = data) do + telemetry(:status, %{status: :connecting}, data) + opts = [:binary, {:packet, 0}, {:active, true}] ++ data.socket_opts ++ data.tls_opts - case state.tcp.connect(state.address, state.port, opts, 2000) do + case data.tcp.connect(data.address, data.port, opts, 2000) do {:ok, socket} -> - state1 = - state + data1 = + data |> backoff_succeed() - telemetry(:status, %{status: :connected}, state1) - {:ok, %{state1 | socket: socket, tcp_error: nil}} + telemetry(:status, %{status: :connected}, data1) + {:ok, %{data1 | socket: socket, tcp_error: nil}} {:error, reason} -> message = format_error(reason) - Logger.error(fn -> "Error connecting to #{state.socket_address} => #{message}" end) + Logger.error(fn -> "Error connecting to #{data.socket_address} => #{message}" end) telemetry( :status, %{status: :disconnected, error: format_error(reason), context: "connect failure"}, - state + data ) {:error, - state + data |> maybe_update_reconnection_timeout() |> Map.put(:tcp_error, reason)} end end - defp maybe_update_reconnection_timeout(%State{backoff: nil} = state) do - state + defp maybe_update_reconnection_timeout(%State{backoff: nil} = data) do + data end - defp maybe_update_reconnection_timeout(%State{backoff: backoff} = state) do + defp maybe_update_reconnection_timeout(%State{backoff: backoff} = data) do {_, new_backoff} = :backoff.fail(backoff) - %{state | backoff: new_backoff} + %{data | backoff: new_backoff} end defp telemetry(_event_name, _measurements, %State{telemetry_module: nil} = _metadata) do From ac37525bdb6e83bd9189c3b34669aa42a6f123c4 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Thu, 13 Jul 2023 10:12:21 -0400 Subject: [PATCH 30/47] Use empty string for receive_buffer --- test/client_test.exs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index f42d1ba..49c98f3 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -123,7 +123,7 @@ defmodule ClientTest do expect(MLLP.TCPMock, :connect, fn ^address, ^port, opts, 2000 -> # Assert we received the default options assert opts[:send_timeout] == 60_000 - assert opts[:keepalive] == true + assert opts[:keepalive] {:ok, socket} end) @@ -132,7 +132,7 @@ defmodule ClientTest do # Assert we have the correct socket_opts in the state assert state.socket_opts[:send_timeout] == 60_000 - assert state.socket_opts[:keepalive] == true + assert state.socket_opts[:keepalive] end end From e2721d6a9540cb1b81ef648b4f796b0c61f77fee Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Thu, 13 Jul 2023 11:23:27 -0400 Subject: [PATCH 31/47] Changes to handle_receive/2 (remove byte_size/1 call; simplify the code) --- lib/mllp/client.ex | 27 ++++++++++++++------------- 1 file changed, 14 insertions(+), 13 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 227a69f..4cc93f2 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -150,7 +150,7 @@ defmodule MLLP.Client do close_on_recv_error: boolean(), backoff: any(), caller: pid() | nil, - receive_buffer: binary() | nil, + receive_buffer: binary(), context: atom() } @@ -170,7 +170,7 @@ defmodule MLLP.Client do close_on_recv_error: true, backoff: nil, caller: nil, - receive_buffer: nil, + receive_buffer: "", context: :connect alias __MODULE__, as: State @@ -352,6 +352,7 @@ defmodule MLLP.Client do @header MLLP.Envelope.sb() @trailer MLLP.Envelope.eb_cr() + @trailer_length byte_size(MLLP.Envelope.eb_cr()) ## ## :gen_statem callbacks @@ -566,18 +567,18 @@ defmodule MLLP.Client do end defp handle_received(reply, %{receive_buffer: buffer} = data) do - new_buf = (buffer && buffer <> reply) || reply - check = byte_size(new_buf) - 3 + new_buf = buffer <> reply case new_buf do - <<@header, _ack::binary-size(check), @trailer>> -> - ## The response is completed, send back to caller - Logger.debug("Client #{inspect(self())} received a full MLLP!") - reply_to_caller({:ok, new_buf}, data) - - <<@header, _rest::binary>> -> - Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") - Map.put(data, :receive_buffer, new_buf) + <<@header, rest::binary>> -> + if String.slice(rest, -@trailer_length, @trailer_length) == @trailer do + ## The response is completed, send back to caller + Logger.debug("Client #{inspect(self())} received a full MLLP!") + reply_to_caller({:ok, new_buf}, data) + else + Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") + Map.put(data, :receive_buffer, new_buf) + end _ -> reply_to_caller({:error, :invalid_reply}, data) @@ -620,7 +621,7 @@ defmodule MLLP.Client do defp reply_cleanup(%State{} = data) do data |> Map.put(:caller, nil) - |> Map.put(:receive_buffer, nil) + |> Map.put(:receive_buffer, "") end @doc false From 00b53bd297fe3115c084d8760702a39ad79dbde6 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Thu, 13 Jul 2023 14:56:59 -0400 Subject: [PATCH 32/47] Use iolist for 'receive_buffer' --- lib/mllp/client.ex | 61 ++++++++++++++++++++++++++++++++-------------- 1 file changed, 43 insertions(+), 18 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 4cc93f2..5402419 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -150,7 +150,7 @@ defmodule MLLP.Client do close_on_recv_error: boolean(), backoff: any(), caller: pid() | nil, - receive_buffer: binary(), + receive_buffer: iolist(), context: atom() } @@ -170,7 +170,7 @@ defmodule MLLP.Client do close_on_recv_error: true, backoff: nil, caller: nil, - receive_buffer: "", + receive_buffer: [], context: :connect alias __MODULE__, as: State @@ -566,25 +566,50 @@ defmodule MLLP.Client do data end + defp handle_received(<<@header, rest::binary>> = reply, %{receive_buffer: []} = data) do + if has_trailer?(rest) do + reply_to_caller({:ok, reply}, data) + else + Map.put(data, :receive_buffer, update_receive_buffer([], reply)) + end + end + + ## No header in the first packet + defp handle_received(_reply, %{receive_buffer: []} = data) do + reply_to_caller({:error, :invalid_reply}, data) + end + + ## The rest of MLLP (after the header was received) defp handle_received(reply, %{receive_buffer: buffer} = data) do - new_buf = buffer <> reply - - case new_buf do - <<@header, rest::binary>> -> - if String.slice(rest, -@trailer_length, @trailer_length) == @trailer do - ## The response is completed, send back to caller - Logger.debug("Client #{inspect(self())} received a full MLLP!") - reply_to_caller({:ok, new_buf}, data) - else - Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") - Map.put(data, :receive_buffer, new_buf) - end - - _ -> - reply_to_caller({:error, :invalid_reply}, data) + new_buf = update_receive_buffer(buffer, reply) + + if has_trailer?(reply) do + reply_to_caller({:ok, buffer_to_binary(new_buf)}, data) + else + Map.put(data, :receive_buffer, new_buf) end end + defp has_trailer?(packet) do + (String.slice(packet, -@trailer_length, @trailer_length) == @trailer) + |> tap(fn yes -> + (yes && Logger.debug("Client #{inspect(self())} received a full MLLP!")) || + Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{packet}") + end) + end + + defp update_receive_buffer(buffer, packet) do + [buffer | packet] + end + + defp buffer_to_binary(buffer) when is_list(buffer) do + IO.iodata_to_binary(buffer) + end + + defp buffer_to_binary(buffer) when is_binary(buffer) do + buffer + end + defp reply_to_caller(reply, %{caller: caller, context: context} = data) do caller && :gen_statem.reply(caller, format_reply(reply, context)) reply_cleanup(data) @@ -621,7 +646,7 @@ defmodule MLLP.Client do defp reply_cleanup(%State{} = data) do data |> Map.put(:caller, nil) - |> Map.put(:receive_buffer, "") + |> Map.put(:receive_buffer, []) end @doc false From 950d99f14d5765b95dc8214a9a542d8008b2564a Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Thu, 13 Jul 2023 17:45:52 -0400 Subject: [PATCH 33/47] Handle 'data after trailer' case --- lib/mllp/client.ex | 50 +++++++++++-------- test/client_and_receiver_integration_test.exs | 10 ++-- test/client_test.exs | 28 ++++++++++- 3 files changed, 60 insertions(+), 28 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 5402419..c0dab66 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -190,6 +190,10 @@ defmodule MLLP.Client do "Invalid header received in server acknowledgment" end + def format_error(:data_after_trailer) do + "Data received after trailer" + end + def format_error(posix) when is_atom(posix) do case :inet.format_error(posix) do 'unknown POSIX error' -> @@ -566,12 +570,8 @@ defmodule MLLP.Client do data end - defp handle_received(<<@header, rest::binary>> = reply, %{receive_buffer: []} = data) do - if has_trailer?(rest) do - reply_to_caller({:ok, reply}, data) - else - Map.put(data, :receive_buffer, update_receive_buffer([], reply)) - end + defp handle_received(<<@header, _rest::binary>> = reply, data) do + receive_impl(reply, data) end ## No header in the first packet @@ -580,22 +580,34 @@ defmodule MLLP.Client do end ## The rest of MLLP (after the header was received) - defp handle_received(reply, %{receive_buffer: buffer} = data) do + defp handle_received(reply, data) do + receive_impl(reply, data) + end + + defp receive_impl(reply, %{receive_buffer: buffer} = data) do new_buf = update_receive_buffer(buffer, reply) - if has_trailer?(reply) do - reply_to_caller({:ok, buffer_to_binary(new_buf)}, data) - else - Map.put(data, :receive_buffer, new_buf) + case trailer_check(reply) do + :data_after_trailer -> + Logger.error("Client #{inspect(self())} received data following the trailer") + reply_to_caller({:error, :data_after_trailer}, data) + + true -> + Logger.debug("Client #{inspect(self())} received a full MLLP!") + reply_to_caller({:ok, buffer_to_binary(new_buf)}, data) + + false -> + Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") + Map.put(data, :receive_buffer, new_buf) end end - defp has_trailer?(packet) do - (String.slice(packet, -@trailer_length, @trailer_length) == @trailer) - |> tap(fn yes -> - (yes && Logger.debug("Client #{inspect(self())} received a full MLLP!")) || - Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{packet}") - end) + defp trailer_check(packet) do + case :binary.match(packet, @trailer) do + :nomatch -> false + {pos, @trailer_length} when pos + @trailer_length == byte_size(packet) -> true + _ -> :data_after_trailer + end end defp update_receive_buffer(buffer, packet) do @@ -606,10 +618,6 @@ defmodule MLLP.Client do IO.iodata_to_binary(buffer) end - defp buffer_to_binary(buffer) when is_binary(buffer) do - buffer - end - defp reply_to_caller(reply, %{caller: caller, context: context} = data) do caller && :gen_statem.reply(caller, format_reply(reply, context)) reply_cleanup(data) diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 718986b..f7b68af 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -43,11 +43,11 @@ defmodule ClientAndReceiverIntegrationTest do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port) capture_log(fn -> - assert {:ok, _, _ack} = - MLLP.Client.send( - client_pid, - HL7.Message.new(HL7.Examples.wikipedia_sample_hl7()) - ) + {:ok, _, _ack} = + MLLP.Client.send( + client_pid, + HL7.Message.new(HL7.Examples.wikipedia_sample_hl7()) + ) end) end diff --git a/test/client_test.exs b/test/client_test.exs index 49c98f3..701967d 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -223,8 +223,8 @@ defmodule ClientTest do log = capture_log([level: :debug], fn -> - {:ok, :application_accept, expected_ack} == - Client.send(ctx.client, message) + assert {:ok, :application_accept, expected_ack} == + Client.send(ctx.client, message) end) fragment_log = "Client #{inspect(ctx.client)} received a MLLP fragment" @@ -278,6 +278,21 @@ defmodule ClientTest do ) end + test "when response contains data after the trailer", ctx do + message = "This message has a TRAILER_WITHIN - beware!" + + expected_err = %MLLP.Client.Error{ + context: :recv, + message: "Data received after trailer", + reason: :data_after_trailer + } + + assert( + {:error, expected_err} == + Client.send(ctx.client, message) + ) + end + test "when given non hl7", ctx do message = "NON HL7" @@ -535,6 +550,15 @@ defmodule ClientTest do end end) end + |> then(fn msg -> + if String.contains?(msg, "TRAILER_WITHIN") do + ## Insert trailer in the middle of the message + {part1, part2} = String.split_at(msg, div(String.length(msg), 2)) + part1 <> MLLP.Envelope.eb_cr() <> part2 + else + msg + end + end) end end end From d19e13c1da595a7636f398954ddd3360e4d1d5df Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Fri, 14 Jul 2023 08:22:12 -0400 Subject: [PATCH 34/47] Fix some assert statements --- test/client_test.exs | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index 701967d..05140f6 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -17,18 +17,18 @@ defmodule ClientTest do describe "host parameters" do test "accepts ipv4 / ipv6 tuples and binaries for host parameter" do - assert {:ok, _} = MLLP.Client.start_link({127, 0, 0, 1}, 9999) + assert match?({:ok, _}, MLLP.Client.start_link({127, 0, 0, 1}, 9999)) - assert {:ok, _} = MLLP.Client.start_link({0, 0, 0, 0, 0, 0, 0, 1}, 9999) + assert match?({:ok, _}, MLLP.Client.start_link({0, 0, 0, 0, 0, 0, 0, 1}, 9999)) - assert {:ok, _} = MLLP.Client.start_link("127.0.0.1", 9999) + assert match?({:ok, _}, MLLP.Client.start_link("127.0.0.1", 9999)) - assert {:ok, _} = MLLP.Client.start_link("::1", 9999) + assert match?({:ok, _}, MLLP.Client.start_link("::1", 9999)) - assert {:ok, _} = MLLP.Client.start_link(:localhost, 9999) - assert {:ok, _} = MLLP.Client.start_link("servera.app.net", 9999) - assert {:ok, _} = MLLP.Client.start_link('servera.unix.city.net', 9999) - assert {:ok, _} = MLLP.Client.start_link('127.0.0.1', 9999) + assert match?({:ok, _}, MLLP.Client.start_link(:localhost, 9999)) + assert match?({:ok, _}, MLLP.Client.start_link("servera.app.net", 9999)) + assert match?({:ok, _}, MLLP.Client.start_link('servera.unix.city.net', 9999)) + assert match?({:ok, _}, MLLP.Client.start_link('127.0.0.1', 9999)) end test "raises on invalid addresses" do @@ -158,7 +158,7 @@ defmodule ClientTest do {_fsm_state, state} = :sys.get_state(pid) - assert {:backoff, 1, 180, 1, :normal, _, _} = state.backoff + assert match?({:backoff, 1, 180, 1, :normal, _, _}, state.backoff) end test "after connection failure" do @@ -181,7 +181,7 @@ defmodule ClientTest do {_fsm_state, state} = :sys.get_state(pid) - assert {:backoff, 1, 180, 2, :normal, _, _} = state.backoff + assert match?({:backoff, 1, 180, 2, :normal, _, _}, state.backoff) end end @@ -247,7 +247,7 @@ defmodule ClientTest do log = capture_log([level: :debug], fn -> - {:error, expected_err} == + assert {:error, expected_err} == Client.send(ctx.client, message, %{reply_timeout: 1000}) end) From cb3ebb4e3335f296c5c3109fa22dca43233cca4e Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Fri, 14 Jul 2023 09:30:56 -0400 Subject: [PATCH 35/47] Switch backoff tests from mock to real --- test/client_test.exs | 61 +++++++++++++++----------------------------- 1 file changed, 21 insertions(+), 40 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index 05140f6..b43e30e 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -137,49 +137,25 @@ defmodule ClientTest do end describe "uses backoff to handle connection" do - test "with base state" do - address = {127, 0, 0, 1} - port = 4090 - socket = make_ref() - - expect(MLLP.TCPMock, :connect, fn ^address, - ^port, - [ - :binary, - {:packet, 0}, - {:active, true}, - {:send_timeout, 60_000} - ], - 2000 -> - {:ok, socket} - end) - - {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) + setup do + Logger.configure(level: :debug) + setup_client_receiver() + end - {_fsm_state, state} = :sys.get_state(pid) + test "with base state", ctx do + {_fsm_state, state} = :sys.get_state(ctx.client) assert match?({:backoff, 1, 180, 1, :normal, _, _}, state.backoff) end - test "after connection failure" do - address = {127, 0, 0, 1} - port = 4090 + test "after connection failure", ctx do + # Stop the receiver... + MLLP.Receiver.stop(ctx.port) - expect(MLLP.TCPMock, :connect, fn ^address, - ^port, - [ - :binary, - {:packet, 0}, - {:active, true}, - {:send_timeout, 60_000} - ], - 2000 -> - {:error, "error"} - end) + # ... and wait for backoff to change + Process.sleep(1000 + 100) - {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock, use_backoff: true) - - {_fsm_state, state} = :sys.get_state(pid) + {_fsm_state, state} = :sys.get_state(ctx.client) assert match?({:backoff, 1, 180, 2, :normal, _, _}, state.backoff) end @@ -248,7 +224,7 @@ defmodule ClientTest do log = capture_log([level: :debug], fn -> assert {:error, expected_err} == - Client.send(ctx.client, message, %{reply_timeout: 1000}) + Client.send(ctx.client, message, %{reply_timeout: 1000}) end) fragment_log = "Client #{inspect(ctx.client)} received a MLLP fragment" @@ -466,16 +442,21 @@ defmodule ClientTest do defp setup_client_receiver() do address = {127, 0, 0, 1} port = 4090 - {:ok, _receiver} = MLLP.Receiver.start(port: port, dispatcher: ClientTest.TestDispatcher) + {:ok, receiver} = MLLP.Receiver.start(port: port, dispatcher: ClientTest.TestDispatcher) {:ok, client} = Client.start_link(address, port, tcp: MLLP.TCP) on_exit(fn -> - MLLP.Receiver.stop(port) + try do + MLLP.Receiver.stop(port) + rescue + _err -> :ok + end + Process.sleep(100) Process.exit(client, :kill) end) - %{client: client} + %{client: client, receiver: receiver, port: port} end defp telemetry_event( From 62c9f1f24966c582629cb0b452c4c2aec2a5e95a Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Fri, 14 Jul 2023 15:54:42 -0400 Subject: [PATCH 36/47] Handle trailer being split between packets --- lib/mllp/client.ex | 34 +++++++++++++++++++++++++++++----- test/client_test.exs | 26 ++++++++++++++++++++++++++ 2 files changed, 55 insertions(+), 5 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index c0dab66..1f51c92 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -151,6 +151,7 @@ defmodule MLLP.Client do backoff: any(), caller: pid() | nil, receive_buffer: iolist(), + last_byte_received: byte(), context: atom() } @@ -171,6 +172,7 @@ defmodule MLLP.Client do backoff: nil, caller: nil, receive_buffer: [], + last_byte_received: nil, context: :connect alias __MODULE__, as: State @@ -357,6 +359,8 @@ defmodule MLLP.Client do @header MLLP.Envelope.sb() @trailer MLLP.Envelope.eb_cr() @trailer_length byte_size(MLLP.Envelope.eb_cr()) + @eb MLLP.Envelope.eb() + @cr MLLP.Envelope.cr() ## ## :gen_statem callbacks @@ -584,10 +588,10 @@ defmodule MLLP.Client do receive_impl(reply, data) end - defp receive_impl(reply, %{receive_buffer: buffer} = data) do + def receive_impl(reply, %{receive_buffer: buffer, last_byte_received: last_byte} = data) do new_buf = update_receive_buffer(buffer, reply) - case trailer_check(reply) do + case trailer_check(reply, last_byte) do :data_after_trailer -> Logger.error("Client #{inspect(self())} received data following the trailer") reply_to_caller({:error, :data_after_trailer}, data) @@ -598,11 +602,25 @@ defmodule MLLP.Client do false -> Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") - Map.put(data, :receive_buffer, new_buf) + + data + |> Map.put(:receive_buffer, new_buf) + |> Map.put(:last_byte_received, String.last(reply)) end end - defp trailer_check(packet) do + ## "Split trailer" case + ## + + defp trailer_check(<<@cr, rest::binary>>, @eb) do + if byte_size(rest) == 0 do + true + else + :data_after_trailer + end + end + + defp trailer_check(packet, _last_buffer_byte) do case :binary.match(packet, @trailer) do :nomatch -> false {pos, @trailer_length} when pos + @trailer_length == byte_size(packet) -> true @@ -611,7 +629,13 @@ defmodule MLLP.Client do end defp update_receive_buffer(buffer, packet) do - [buffer | packet] + case buffer do + [] -> + [packet] + + b -> + [b | packet] + end end defp buffer_to_binary(buffer) when is_list(buffer) do diff --git a/test/client_test.exs b/test/client_test.exs index b43e30e..f5368fd 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -237,6 +237,32 @@ defmodule ClientTest do assert num_receives == 0 end + test "when the trailer is split between fragments", ctx do + {_, data} = :sys.get_state(ctx.client) + frag1 = <<11, 121, 101, 115>> <> MLLP.Envelope.eb() + ## CR is a single byte coming in the last fragment + frag_cr = MLLP.Envelope.cr() + + log = + capture_log([level: :debug], fn -> + ## The buffer will be reset upon reception of full MLLP + assert "" == + MLLP.Client.receive_impl(frag1, data) + |> then(fn d -> + MLLP.Client.receive_impl(frag_cr, d) + |> Map.get(:receive_buffer) + |> IO.iodata_to_binary() + end) + end) + + first_fragment_log = "Client #{inspect(self())} received a MLLP fragment" + ## One fragment... + assert count_occurences(log, first_fragment_log) == 1 + cr_fragment_log = "Client #{inspect(self())} received a full MLLP!" + ## Trailer completed by second fragment + assert count_occurences(log, cr_fragment_log) == 1 + end + test "when reply header is invalid", ctx do ## This HL7 message triggers :invalid_reply due to TestDispatcher implementation (note DONOTWRAP!) message = From 74b735dfd087e7b0b142cbe649301393b46cb7e2 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sat, 15 Jul 2023 13:08:15 -0400 Subject: [PATCH 37/47] Address some review items --- lib/mllp/client.ex | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 1f51c92..560e1f0 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -551,6 +551,11 @@ defmodule MLLP.Client do {:next_state, :disconnected, handle_error(reason, maybe_close(reason, data))} end + def receiving({:call, _from} = event_kind, request, data) + when request in [:is_connected, :reconnect] do + connected(event_kind, request, data) + end + def receiving(event, unknown, _data) do unexpected_message(:receiving, event, unknown) end @@ -598,7 +603,7 @@ defmodule MLLP.Client do true -> Logger.debug("Client #{inspect(self())} received a full MLLP!") - reply_to_caller({:ok, buffer_to_binary(new_buf)}, data) + reply_to_caller({:ok, IO.iodata_to_binary(new_buf)}, data) false -> Logger.debug("Client #{inspect(self())} received a MLLP fragment: #{reply}") @@ -613,7 +618,7 @@ defmodule MLLP.Client do ## defp trailer_check(<<@cr, rest::binary>>, @eb) do - if byte_size(rest) == 0 do + if rest == "" do true else :data_after_trailer @@ -638,10 +643,6 @@ defmodule MLLP.Client do end end - defp buffer_to_binary(buffer) when is_list(buffer) do - IO.iodata_to_binary(buffer) - end - defp reply_to_caller(reply, %{caller: caller, context: context} = data) do caller && :gen_statem.reply(caller, format_reply(reply, context)) reply_cleanup(data) @@ -847,8 +848,12 @@ defmodule MLLP.Client do } end + defp get_context(%State{context: nil}) do + :unknown + end + defp get_context(%State{context: context}) do - (context && context) || :unknown + context end defp normalize_address!({_, _, _, _} = addr), do: addr From d8337bab63e49eb6627634474d82b6a4f7f5cff2 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sat, 15 Jul 2023 13:33:59 -0400 Subject: [PATCH 38/47] Test for the client accepting requests in 'receiving' state --- test/client_test.exs | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/test/client_test.exs b/test/client_test.exs index f5368fd..a84ee78 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -374,6 +374,18 @@ defmodule ClientTest do end ) end + + test "handles requests while processing 'send'", %{client: client} = _ctx do + slow_processing_msg = "Asking receiver to SLOWDOWN..." + ## One process sends a message, other 2 ask if the client is connected + send_task = Task.async(fn -> Client.send(client, slow_processing_msg) end) + Process.sleep(10) + ## The client is in receivng mode... + {:receiving, _state} = :sys.get_state(client) + ## ...and accepts other requests + assert Client.is_connected?(client) + assert Task.await(send_task) == {:ok, slow_processing_msg} + end end describe "send_async/2" do From 7280cba85ac84223d307c6d5b106726e343c1fc2 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sun, 16 Jul 2023 15:19:49 -0400 Subject: [PATCH 39/47] Pattern match for trailer_check Co-authored-by: Bryan Paxton <39971740+starbelly@users.noreply.github.com> --- lib/mllp/client.ex | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 560e1f0..f041594 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -617,12 +617,9 @@ defmodule MLLP.Client do ## "Split trailer" case ## - defp trailer_check(<<@cr, rest::binary>>, @eb) do - if rest == "" do - true - else - :data_after_trailer - end + defp trailer_check(@cr, @eb), do: true + + defp trailer_check(<<@cr, _::binary>>, @eb), do: :data_after_trailer end defp trailer_check(packet, _last_buffer_byte) do From 00b09768323760d2113abbbe3f3f87734a456077 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sun, 16 Jul 2023 15:22:30 -0400 Subject: [PATCH 40/47] Reset last_byte_received Co-authored-by: Bryan Paxton <39971740+starbelly@users.noreply.github.com> --- lib/mllp/client.ex | 1 + 1 file changed, 1 insertion(+) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index f041594..7c0ee81 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -677,6 +677,7 @@ defmodule MLLP.Client do data |> Map.put(:caller, nil) |> Map.put(:receive_buffer, []) + |> Map.put(:last_byte_received, nil) end @doc false From 19129836304965f870c093391d1893bda8ca6655 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sun, 16 Jul 2023 15:29:48 -0400 Subject: [PATCH 41/47] Simplify buffer update --- lib/mllp/client.ex | 11 ++--------- 1 file changed, 2 insertions(+), 9 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 7c0ee81..0e7d0e6 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -619,8 +619,7 @@ defmodule MLLP.Client do defp trailer_check(@cr, @eb), do: true - defp trailer_check(<<@cr, _::binary>>, @eb), do: :data_after_trailer - end + defp trailer_check(<<@cr, _::binary>>, @eb), do: :data_after_trailer defp trailer_check(packet, _last_buffer_byte) do case :binary.match(packet, @trailer) do @@ -631,13 +630,7 @@ defmodule MLLP.Client do end defp update_receive_buffer(buffer, packet) do - case buffer do - [] -> - [packet] - - b -> - [b | packet] - end + [buffer | packet] end defp reply_to_caller(reply, %{caller: caller, context: context} = data) do From a44cf72b0a5836c17c7566bc4b8c4cc5fbfe47f8 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Sun, 16 Jul 2023 16:20:09 -0400 Subject: [PATCH 42/47] Minor changes to test case --- test/client_test.exs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test/client_test.exs b/test/client_test.exs index a84ee78..b5c198c 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -380,10 +380,10 @@ defmodule ClientTest do ## One process sends a message, other 2 ask if the client is connected send_task = Task.async(fn -> Client.send(client, slow_processing_msg) end) Process.sleep(10) - ## The client is in receivng mode... + ## The client is in receiving mode... {:receiving, _state} = :sys.get_state(client) ## ...and accepts other requests - assert Client.is_connected?(client) + assert Enum.all?(1..2, fn _ -> Client.is_connected?(client) end) assert Task.await(send_task) == {:ok, slow_processing_msg} end end From 0f3ba0a62acc5a0522b65bb539e23c7109ec38c1 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Mon, 17 Jul 2023 09:33:28 -0400 Subject: [PATCH 43/47] Add 'send_timeout_close' to socket defaults --- lib/mllp/client.ex | 27 +++++++++++----- test/client_and_receiver_integration_test.exs | 2 +- test/client_test.exs | 32 ++++++------------- 3 files changed, 30 insertions(+), 31 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 0e7d0e6..6abb2c4 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -238,6 +238,7 @@ defmodule MLLP.Client do * `:socket_opts` - A list of socket options as supported by [`:gen_tcp`](`:gen_tcp`). Note that `:binary`, `:packet`, and `:active` can not be overridden. Default options are enumerated below. - send_timeout: Defaults to 60 seconds + - send_timeout_close: Defaults to true * `:close_on_recv_error` - A boolean value which dictates whether the client socket will be closed when an error in receiving a reply is encountered, this includes timeouts. @@ -715,7 +716,7 @@ defmodule MLLP.Client do defp attempt_connection(%State{} = data) do telemetry(:status, %{status: :connecting}, data) - opts = [:binary, {:packet, 0}, {:active, true}] ++ data.socket_opts ++ data.tls_opts + opts = fixed_socket_opts() ++ data.socket_opts ++ data.tls_opts case data.tcp.connect(data.address, data.port, opts, 2000) do {:ok, socket} -> @@ -772,11 +773,21 @@ defmodule MLLP.Client do opts end - @default_opts %{ - telemetry_module: MLLP.DefaultTelemetry, - tls_opts: [], - socket_opts: [send_timeout: 60_000] - } + def default_opts() do + %{ + telemetry_module: MLLP.DefaultTelemetry, + tls_opts: [], + socket_opts: default_socket_opts() + } + end + + def default_socket_opts() do + [send_timeout: 60_000, send_timeout_close: true] + end + + def fixed_socket_opts() do + [:binary, {:packet, 0}, {:active, true}] + end @default_send_opts %{ reply_timeout: 60_000 @@ -799,10 +810,10 @@ defmodule MLLP.Client do send_opts = Map.merge(@default_send_opts, send_opts) - socket_opts = Keyword.merge(@default_opts[:socket_opts], opts[:socket_opts] || []) + socket_opts = Keyword.merge(default_socket_opts(), opts[:socket_opts] || []) opts - |> Map.merge(@default_opts) + |> Map.merge(default_opts()) |> Map.put_new(:tcp, socket_module) |> Map.put(:pid, self()) |> Map.put(:tls_opts, opts.tls) diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index f7b68af..28bda5d 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -397,7 +397,7 @@ defmodule ClientAndReceiverIntegrationTest do ) assert error.context in [:send, :recv] - assert error.reason == :closed + assert error.reason in [:closed, :einval] end @tag allowed_clients: ["127.0.0.0", "localhost"] diff --git a/test/client_test.exs b/test/client_test.exs index b5c198c..fa85783 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -80,19 +80,12 @@ defmodule ClientTest do test "with default options" do address = {127, 0, 0, 1} port = 4090 - socket = make_ref() - - expect(MLLP.TCPMock, :connect, fn ^address, ^port, opts, 2000 -> - # Assert we received the default options - assert opts[:send_timeout] == 60_000 - {:ok, socket} - end) - {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCPMock) + {:ok, pid} = Client.start_link(address, port, tcp: MLLP.TCP) {_fsm_state, state} = :sys.get_state(pid) # Assert we have the correct socket_opts in the state - assert state.socket_opts == [send_timeout: 60_000] + assert Keyword.equal?(state.socket_opts, Client.default_socket_opts()) end test "with default options overridden" do @@ -111,7 +104,7 @@ defmodule ClientTest do {_fsm_state, state} = :sys.get_state(pid) # Assert we have the correct socket_opts in the state - assert state.socket_opts == [send_timeout: 10_000] + assert state.socket_opts[:send_timeout] == 10_000 end test "with additional options" do @@ -310,14 +303,12 @@ defmodule ClientTest do raw_hl7 = HL7.Examples.wikipedia_sample_hl7() message = HL7.Message.new(raw_hl7) packet = MLLP.Envelope.wrap_message(raw_hl7) + socket_opts = Client.fixed_socket_opts() ++ Client.default_socket_opts() MLLP.TCPMock |> expect( :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> + fn ^address, ^port, ^socket_opts, 2000 -> {:ok, socket} end ) @@ -410,14 +401,12 @@ defmodule ClientTest do socket = make_ref() message = "Hello, it's me" packet = MLLP.Envelope.wrap_message(message) + socket_opts = Client.fixed_socket_opts() ++ Client.default_socket_opts() MLLP.TCPMock |> expect( :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> + fn ^address, ^port, ^socket_opts, 2000 -> {:ok, socket} end ) @@ -436,13 +425,12 @@ defmodule ClientTest do message = HL7.Message.new(raw_hl7) packet = MLLP.Envelope.wrap_message(raw_hl7) + socket_opts = Client.fixed_socket_opts() ++ Client.default_socket_opts() + MLLP.TCPMock |> expect( :connect, - fn ^address, - ^port, - [:binary, {:packet, 0}, {:active, true}, {:send_timeout, 60_000}], - 2000 -> + fn ^address, ^port, ^socket_opts, 2000 -> {:ok, socket} end ) From 9c6cbf1334946f75f4b5c4ad52231359615fc57d Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Mon, 17 Jul 2023 12:00:10 -0400 Subject: [PATCH 44/47] Shutdown on unexpected packet --- lib/mllp/client.ex | 34 ++++++++++++++++++++++++---------- lib/mllp/tcp.ex | 1 + lib/mllp/tls.ex | 1 + test/client_test.exs | 25 ++++++++++++++++++++++--- 4 files changed, 48 insertions(+), 13 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 6abb2c4..a21aba0 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -196,6 +196,10 @@ defmodule MLLP.Client do "Data received after trailer" end + def format_error(:unexpected_packet_received) do + "Unexpected packet received" + end + def format_error(posix) when is_atom(posix) do case :inet.format_error(posix) do 'unknown POSIX error' -> @@ -576,8 +580,9 @@ defmodule MLLP.Client do ## Handle the (fragmented) responses to `send` request from a caller defp handle_received(_reply, %{caller: nil} = data) do - ## No caller, ignore - data + ## No caller, we must have received the full MLLP already, + ## or it could be a request from external process other than the receiver + maybe_close(:unexpected_packet_received, data) end defp handle_received(<<@header, _rest::binary>> = reply, data) do @@ -691,15 +696,24 @@ defmodule MLLP.Client do defp maybe_close(_reason, data), do: data - defp stop_connection(%State{} = data, error, context) do - if data.socket != nil do - telemetry( - :status, - %{status: :disconnected, error: format_error(error), context: context}, - data - ) + defp stop_connection(%State{socket: nil} = data, _error, _context) do + data + end + + defp stop_connection(%State{socket: socket, tcp: tcp} = data, error, context) do + telemetry( + :status, + %{status: :disconnected, error: format_error(error), context: context}, + data + ) + + Logger.debug("Stopping connection: #{format_error(error)}}") - data.tcp.close(data.socket) + if error == :unexpected_packet_received do + :ok = :inet.setopts(socket, linger: {true, 0}) + tcp.shutdown(socket, :read_write) + else + tcp.close(socket) end data diff --git a/lib/mllp/tcp.ex b/lib/mllp/tcp.ex index f1c5156..77377fc 100644 --- a/lib/mllp/tcp.ex +++ b/lib/mllp/tcp.ex @@ -22,4 +22,5 @@ defmodule MLLP.TCP do defdelegate recv(socket, length, timeout), to: :gen_tcp defdelegate connect(address, port, options, timeout), to: :gen_tcp defdelegate close(socket), to: :gen_tcp + defdelegate shutdown(socket, opts), to: :gen_tcp end diff --git a/lib/mllp/tls.ex b/lib/mllp/tls.ex index f9ce9ef..89b66df 100644 --- a/lib/mllp/tls.ex +++ b/lib/mllp/tls.ex @@ -22,4 +22,5 @@ defmodule MLLP.TLS do defdelegate recv(socket, length, timeout), to: :ssl defdelegate connect(address, port, options, timeout), to: :ssl defdelegate close(socket), to: :ssl + defdelegate shutdown(socket, opts), to: :ssl end diff --git a/test/client_test.exs b/test/client_test.exs index fa85783..5ba36e4 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -154,16 +154,35 @@ defmodule ClientTest do end end - describe "handle_info/2" do - test "handles unexpected info messages" do - assert {:ok, pid} = MLLP.Client.start_link({127, 0, 0, 1}, 9998, use_backoff: true) + describe "unexpected messages" do + setup do + Logger.configure(level: :debug) + setup_client_receiver() + end + test "handles unexpected info messages", %{client: pid} = _ctx do assert capture_log(fn -> Kernel.send(pid, :eh?) Process.sleep(100) assert Process.alive?(pid) end) =~ "Unknown message received => :eh?" end + + test "handles unexpected incoming packet", %{client: pid} = _ctx do + {_fsm_state, state} = :sys.get_state(pid) + socket = state.socket + + log = + capture_log([level: :debug], fn -> + Kernel.send(pid, {:tcp, socket, "what's up?"}) + Process.sleep(100) + end) + + assert String.contains?(log, Client.format_error(:unexpected_packet_received)) + assert String.contains?(log, "Connection closed") + + refute Client.is_connected?(pid) + end end describe "send/2" do From b5db1358c3a38c09990b0d7eaf06bceb861ed3d2 Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Mon, 17 Jul 2023 18:03:26 -0400 Subject: [PATCH 45/47] Bug fix: switch to :disconnected if conn has closed --- lib/mllp/client.ex | 16 ++++++++++++++-- test/client_test.exs | 13 ++++++++++--- 2 files changed, 24 insertions(+), 5 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index a21aba0..3eb4415 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -542,7 +542,7 @@ defmodule MLLP.Client do def receiving(:info, {transport, socket, incoming}, %{socket: socket} = data) when transport in [:tcp, :ssl] do new_data = handle_received(incoming, data) - next_state = (new_data.caller && :receiving) || :connected + next_state = next_after_receiving(new_data) {:next_state, next_state, new_data} end @@ -565,6 +565,18 @@ defmodule MLLP.Client do unexpected_message(:receiving, event, unknown) end + defp next_after_receiving(%State{socket: nil}) do + :disconnected + end + + defp next_after_receiving(%State{caller: nil}) do + :connected + end + + defp next_after_receiving(%State{} = _state) do + :receiving + end + ######################################## ### End of :gen_statem callbacks ### ######################################## @@ -707,7 +719,7 @@ defmodule MLLP.Client do data ) - Logger.debug("Stopping connection: #{format_error(error)}}") + Logger.debug("Stopping connection: #{format_error(error)}") if error == :unexpected_packet_received do :ok = :inet.setopts(socket, linger: {true, 0}) diff --git a/test/client_test.exs b/test/client_test.exs index 5ba36e4..806116b 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -175,13 +175,20 @@ defmodule ClientTest do log = capture_log([level: :debug], fn -> Kernel.send(pid, {:tcp, socket, "what's up?"}) - Process.sleep(100) + + {:error, _} = + Client.send( + pid, + "this should fail as the connection will be dropped on unexpected packet" + ) + + refute Client.is_connected?(pid) + Client.reconnect(pid) + {:ok, _} = Client.send(pid, "ok") end) assert String.contains?(log, Client.format_error(:unexpected_packet_received)) assert String.contains?(log, "Connection closed") - - refute Client.is_connected?(pid) end end From 411dae60f920a09572bd9426d6e19b4bafe4f37d Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 18 Jul 2023 10:08:55 -0400 Subject: [PATCH 46/47] Shutdown socket on receive timeout, if required --- lib/mllp/client.ex | 4 +- test/client_and_receiver_integration_test.exs | 56 +++++++++++++------ test/client_test.exs | 2 - 3 files changed, 41 insertions(+), 21 deletions(-) diff --git a/lib/mllp/client.ex b/lib/mllp/client.ex index 3eb4415..6830fb8 100644 --- a/lib/mllp/client.ex +++ b/lib/mllp/client.ex @@ -536,7 +536,7 @@ defmodule MLLP.Client do end def receiving(:state_timeout, :receive_timeout, data) do - {:next_state, :connected, reply_to_caller({:error, :timeout}, data)} + {:next_state, :connected, reply_to_caller({:error, :timeout}, maybe_close(:timeout, data))} end def receiving(:info, {transport, socket, incoming}, %{socket: socket} = data) @@ -721,7 +721,7 @@ defmodule MLLP.Client do Logger.debug("Stopping connection: #{format_error(error)}") - if error == :unexpected_packet_received do + if error in [:timeout, :unexpected_packet_received] do :ok = :inet.setopts(socket, linger: {true, 0}) tcp.shutdown(socket, :read_write) else diff --git a/test/client_and_receiver_integration_test.exs b/test/client_and_receiver_integration_test.exs index 28bda5d..9141166 100644 --- a/test/client_and_receiver_integration_test.exs +++ b/test/client_and_receiver_integration_test.exs @@ -261,15 +261,12 @@ defmodule ClientAndReceiverIntegrationTest do end describe "timeout behaviour" do - test "gen server call times out" do - port = 8153 - - {:ok, %{pid: _receiver_pid}} = - MLLP.Receiver.start( - port: port, - dispatcher: ClientAndReceiverIntegrationTest.TestDispatcher - ) + setup do + Logger.configure(level: :debug) + setup_receiver() + end + test "gen server call times out", %{port: port} = _ctx do {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port, auto_reconnect_interval: 3) assert catch_exit( @@ -281,17 +278,13 @@ defmodule ClientAndReceiverIntegrationTest do assert Process.alive?(client_pid) end - test "does not open additional sockets on reconnect" do - port = 8154 - - {:ok, %{pid: _receiver_pid}} = - MLLP.Receiver.start( - port: port, - dispatcher: ClientAndReceiverIntegrationTest.TestDispatcher + test "does not open additional sockets on reconnect", %{port: port} = _ctx do + {:ok, client_pid} = + MLLP.Client.start_link({127, 0, 0, 1}, port, + auto_reconnect_interval: 3, + close_on_recv_error: false ) - {:ok, client_pid} = MLLP.Client.start_link({127, 0, 0, 1}, port, auto_reconnect_interval: 3) - capture_log(fn -> {:error, _} = MLLP.Client.send(client_pid, "MSH|NOREPLY", %{reply_timeout: 1}) end) @@ -302,6 +295,18 @@ defmodule ClientAndReceiverIntegrationTest do assert Enum.count(open_ports_for_pid(client_pid)) == 1 end + + test "closes the socket, if close_on_recv_error set to true", %{port: port} = _ctx do + {:ok, client_pid} = + MLLP.Client.start_link({127, 0, 0, 1}, port, + auto_reconnect_interval: 3, + close_on_recv_error: true + ) + + {:error, _} = MLLP.Client.send(client_pid, "MSH|NOREPLY", %{reply_timeout: 1}) + Process.sleep(10) + assert Enum.count(open_ports_for_pid(client_pid)) == 0 + end end describe "tls support" do @@ -608,4 +613,21 @@ defmodule ClientAndReceiverIntegrationTest do Keyword.get(info, :name) == 'tcp_inet' and Keyword.get(info, :connected) == pid end) end + + defp setup_receiver() do + port = 4090 + + {:ok, receiver} = + MLLP.Receiver.start(port: port, dispatcher: ClientAndReceiverIntegrationTest.TestDispatcher) + + on_exit(fn -> + try do + MLLP.Receiver.stop(port) + rescue + _err -> :ok + end + end) + + %{receiver: receiver, port: port} + end end diff --git a/test/client_test.exs b/test/client_test.exs index 806116b..39eeb65 100755 --- a/test/client_test.exs +++ b/test/client_test.exs @@ -183,8 +183,6 @@ defmodule ClientTest do ) refute Client.is_connected?(pid) - Client.reconnect(pid) - {:ok, _} = Client.send(pid, "ok") end) assert String.contains?(log, Client.format_error(:unexpected_packet_received)) From 416f254dea39edce514d3dd1c197ed772be4a34d Mon Sep 17 00:00:00 2001 From: Boris Okner Date: Tue, 18 Jul 2023 10:18:57 -0400 Subject: [PATCH 47/47] Update cache version --- .github/workflows/main.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/main.yml b/.github/workflows/main.yml index 551e6dc..f66aa84 100644 --- a/.github/workflows/main.yml +++ b/.github/workflows/main.yml @@ -11,7 +11,7 @@ env: MIX_ENV: test otp-version: '24' elixir-version: '1.14' - cache-version: '2' + cache-version: '3' jobs: build: