diff --git a/channel-sender/config/config-local2.yaml b/channel-sender/config/config-local2.yaml new file mode 100644 index 00000000..6e735588 --- /dev/null +++ b/channel-sender/config/config-local2.yaml @@ -0,0 +1,85 @@ +channel_sender_ex: + rest_port: 8071 + socket_port: 8072 + prometheus_port: 7568 + secret_generator: + base: "aV4ZPOf7T7HX6GvbhwyBlDM8B9jfeiwi+9qkBnjXxUZXqAeTrehojWKHkV3U0kGc" + salt: "socket auth" + # Max time (in seconds) for a token to be valid + # this parameter is also used to hold the channel genstatemachine in wainting state + # before it is closed + max_age: 900 + + # initial time in seconds to wait before re-send a message not acked to a channel + initial_redelivery_time: 900 + + # max time in milliseconds to wait the client to send the auth token + # before closing the channel + socket_idle_timeout: 90000 + + # Specifies the maximum time (in milliseconds) that the Elixir supervisor waits + # for child channel processes to terminate after sending it an exit signal + # (:shutdown). This time is used by all gen_statem processes to perform clean up + # operations before shutting down. + channel_shutdown_tolerance: 10000 + + # Specifies the maximum drift time (in seconds) the channel process + # will consider for emiting a new secret token before the current one expires. + # Time to generate will be the greater value between (max_age / 2) and + # (max_age - min_disconnection_tolerance) + min_disconnection_tolerance: 50 + + on_connected_channel_reply_timeout: 2000 + + # max time a channel process will wait to perform the send operation before times out + accept_channel_reply_timeout: 1000 + + # Allowed max number of unacknowledged messages per client connection + # after this limit is reached, oldes unacknowledged messages will be dropped + max_unacknowledged_queue: 100 + + # Allowed max number of retries to re-send unack'ed message to a channel + max_unacknowledged_retries: 10 + + # Allowed max number of messages pending to be sent to a channel + # received by sender while on waiting state (no socket connection) + max_pending_queue: 100 + + # channel_shutdown_socket_disconnect: Defines the waiting time of the channel process + # after a socket disconnection, in case the client re-connects. The disconection can be + # clean or unclean. The channel process will wait for the client to re-connect before + # + # on_clean_close: time in seconds to wait before shutting down the channel process when a + # client explicitlly ends the socket connection (clean close). A value of 0, will + # terminate the channel process immediately. This value should never be greater than max_age. + # + # on_disconnection: time in seconds to wait before shutting down the channel process when the + # connectin between the client and server accidentally or unintendedlly is interrupted. + # A value of 0, will terminate the channel process immediately. This value should never + # be greater than max_age. + channel_shutdown_socket_disconnect: + on_clean_close: 300 + on_disconnection: 900 + + no_start: false + topology: + strategy: Elixir.Cluster.Strategy.Gossip # for local development + + # strategy: Elixir.Cluster.Strategy.Kubernetes # topology for kubernetes + # config: + # mode: :hostname + # kubernetes_ip_lookup_mode: :pods + # kubernetes_service_name: "adfsender-headless" + # kubernetes_node_basename: "channel_sender_ex" + # kubernetes_selector: "cluster=beam" + # namespace: "sendernm" + # polling_interval: 5000 + + # see https://github.com/bancolombia/async-dataflow/tree/master/channel-sender/deploy_samples/k8s + # for more information about the kubernetes configuration with libcluser + +logger: + level: debug + + + diff --git a/channel-sender/lib/channel_sender_ex/application.ex b/channel-sender/lib/channel_sender_ex/application.ex index 59194a5a..2faa2d92 100644 --- a/channel-sender/lib/channel_sender_ex/application.ex +++ b/channel-sender/lib/channel_sender_ex/application.ex @@ -2,6 +2,7 @@ defmodule ChannelSenderEx.Application do # See https://hexdocs.pm/elixir/Application.html # for more information on OTP Applications @moduledoc false + #import Cachex.Spec alias ChannelSenderEx.ApplicationConfig alias ChannelSenderEx.Core.RulesProvider.Helper @@ -15,13 +16,13 @@ defmodule ChannelSenderEx.Application do require Logger def start(_type, _args) do - _config = ApplicationConfig.load() Helper.compile(:channel_sender_ex) CustomTelemetry.custom_telemetry_events() no_start_param = Application.get_env(:channel_sender_ex, :no_start) + if !no_start_param do EntryPoint.start() end @@ -38,19 +39,38 @@ defmodule ChannelSenderEx.Application do false -> [ {Cluster.Supervisor, [topologies(), [name: ChannelSenderEx.ClusterSupervisor]]}, - ChannelSenderEx.Core.ChannelSupervisor, - {Plug.Cowboy, scheme: :http, plug: RestController, options: [ - port: Application.get_env(:channel_sender_ex, :rest_port), - protocol_options: Application.get_env(:channel_sender_ex, :cowboy_protocol_options), - transport_options: Application.get_env(:channel_sender_ex, :cowboy_transport_options), - ]}, + pg_spec(), + # {Cachex, + # [ + # :channels, + # [ + # router: + # router( + # module: Cachex.Router.Ring, + # options: [ + # monitor: true + # ] + # ) + # ] + # ]}, + # ChannelSenderEx.Core.ChannelSupervisor, + ChannelSenderEx.Core.ChannelSupervisorPg, + {Plug.Cowboy, + scheme: :http, + plug: RestController, + options: [ + port: Application.get_env(:channel_sender_ex, :rest_port), + protocol_options: Application.get_env(:channel_sender_ex, :cowboy_protocol_options), + transport_options: Application.get_env(:channel_sender_ex, :cowboy_transport_options) + ]}, {TelemetryMetricsPrometheus, - [ - metrics: CustomTelemetry.metrics(), - port: prometheus_port - ]}, + [ + metrics: CustomTelemetry.metrics(), + port: prometheus_port + ]} # {Telemetry.Metrics.ConsoleReporter, metrics: CustomTelemetry.metrics()} ] + true -> [] end @@ -60,7 +80,15 @@ defmodule ChannelSenderEx.Application do topology = [ k8s: Application.get_env(:channel_sender_ex, :topology) ] + Logger.debug("Topology selected: #{inspect(topology)}") topology end + + defp pg_spec do + %{ + id: :pg, + start: {:pg, :start_link, []} + } + end end diff --git a/channel-sender/lib/channel_sender_ex/core/channel.ex b/channel-sender/lib/channel_sender_ex/core/channel.ex index da7327ef..bdcdceff 100644 --- a/channel-sender/lib/channel_sender_ex/core/channel.ex +++ b/channel-sender/lib/channel_sender_ex/core/channel.ex @@ -1,4 +1,6 @@ defmodule ChannelSenderEx.Core.Channel do + # credo:disable-for-this-file Credo.Check.Readability.PreferImplicitTry + @moduledoc """ Main abstraction for modeling and active or temporarily idle async communication channel with an user. """ @@ -6,7 +8,7 @@ defmodule ChannelSenderEx.Core.Channel do require Logger alias ChannelSenderEx.Core.BoundedMap alias ChannelSenderEx.Core.ChannelIDGenerator - alias ChannelSenderEx.Core.ChannelSupervisor + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor alias ChannelSenderEx.Core.ProtocolMessage alias ChannelSenderEx.Core.RulesProvider alias ChannelSenderEx.Utils.CustomTelemetry @@ -29,7 +31,7 @@ defmodule ChannelSenderEx.Core.Channel do @type t() :: %ChannelSenderEx.Core.Channel.Data{ channel: String.t(), application: String.t(), - socket: {pid(), reference()}, + socket: {pid(), reference(), integer()}, pending_ack: ChannelSenderEx.Core.Channel.pending_ack(), pending_sending: ChannelSenderEx.Core.Channel.pending_sending(), stop_cause: atom(), @@ -66,11 +68,16 @@ defmodule ChannelSenderEx.Core.Channel do end end + @spec alive?(atom() | pid() | {atom(), any()} | {:via, atom(), any()}) :: boolean() + def alive?(server) do + safe_alive?(server, self()) + end + @doc """ operation to notify this server that the socket is connected """ - def socket_connected(server, socket_pid, timeout \\ @on_connected_channel_reply_timeout) do - GenStateMachine.call(server, {:socket_connected, socket_pid}, timeout) + def socket_connected(server, socket_pid, time, timeout \\ @on_connected_channel_reply_timeout) do + GenStateMachine.call(server, {:socket_connected, socket_pid, time}, timeout) end @doc """ @@ -111,9 +118,11 @@ defmodule ChannelSenderEx.Core.Channel do Data.new(channel, application, user_ref, meta) |> Map.put(:token_expiry, calculate_token_expiration_time()) - Logger.debug(fn -> "Channel #{channel} created. Data: #{inspect(data)}" end) + # Logger.debug(fn -> "Channel #{channel} created. Data: #{inspect(data)}" end) + Process.flag(:trap_exit, true) - CustomTelemetry.execute_custom_event([:adf, :channel], %{count: 1}) + + # CustomTelemetry.execute_custom_event([:adf, :channel], %{count: 1}) {:ok, :waiting, data} end @@ -138,63 +147,34 @@ defmodule ChannelSenderEx.Core.Channel do case ChannelSupervisor.register_channel_if_not_exists({channel, application, user_ref, meta}) do {:ok, ^current_pid} -> Logger.debug(fn -> - "Channel #{channel} is swarm registered with self() pid #{inspect(current_pid)}" + "Channel #{channel} is registered with self() pid #{inspect(current_pid)}" end) :existing {:error, reason} -> Logger.error(fn -> - "Channel #{channel} failed to register in swarm: #{inspect(reason)}" + "Channel #{channel} failed to register in registry: #{inspect(reason)}" end) :error {:ok, pid} -> Logger.debug(fn -> - "Channel #{channel} swarm re-registration or exists with another pid #{inspect(pid)} stoping self #{inspect(self())}" + "Channel #{channel} re-registration or exists with another pid #{inspect(pid)} stoping self #{inspect(self())}" end) :registered end end - def waiting(:cast, {:swarm, :resolve_conflict, data}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :resolve_conflict in pid #{inspect(self())} at #{Node.self()}. state: waiting." - end) - {:keep_state, data} - end - - def waiting(:cast, {:swarm, :end_handoff, _data}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :end_handoff in pid #{inspect(self())} at #{Node.self()}. state: waiting." - end) - {:next_state, :waiting, state} - end - - def waiting({:call, from}, {:swarm, :begin_handoff}, state) do - # Return the state so the new node can take over - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :begin_handoff in pid #{inspect(self())} at #{Node.self()}. state: waiting." - end) - {:keep_state_and_data, [{:reply, from, {:resume, state}}]} - end - - def waiting(:info, {:swarm, :die}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :die in pid #{inspect(self())} at #{Node.self()}. state: waiting." - end) - {:stop, :shutdown, state} - end - def waiting(:enter, _old_state, data) do # time to wait for the socket to be open (or re-opened) and authenticated waiting_timeout = round(estimate_process_wait_time(data) * 1000) case check_process(waiting_timeout, data) do :timeout -> - ChannelSupervisor.unregister_channel(data.channel) + # ChannelSupervisor.unregister_channel(data.channel) {:stop, :normal, data} :registered -> @@ -210,6 +190,10 @@ defmodule ChannelSenderEx.Core.Channel do end end + def waiting({:call, from}, :alive?, _data) do + {:keep_state_and_data, [{:reply, from, true}]} + end + def waiting({:call, from}, :stop, data) do actions = [ _reply = {:reply, from, :ok} @@ -226,17 +210,18 @@ defmodule ChannelSenderEx.Core.Channel do "Channel #{data.channel} timed-out on waiting state for a socket connection and/or authentication" ) - ChannelSupervisor.unregister_channel(data.channel) + ChannelSupervisor.unregister_channel(data.channel, self()) + {:stop, :normal, %{data | stop_cause: :waiting_timeout}} end - def waiting({:call, from}, {:socket_connected, socket_pid}, data) do + def waiting({:call, from}, {:socket_connected, socket_pid, time}, data) do Logger.debug( "Channel #{data.channel} received socket connected notification. Socket pid: #{inspect(socket_pid)}" ) socket_ref = Process.monitor(socket_pid) - new_data = %{data | socket: {socket_pid, socket_ref}, socket_stop_cause: nil} + new_data = %{data | socket: {socket_pid, socket_ref, time}, socket_stop_cause: nil} actions = [ _reply = {:reply, from, :ok} @@ -314,45 +299,50 @@ defmodule ChannelSenderEx.Core.Channel do @type call() :: {:call, GenServer.from()} @type state_return() :: :gen_statem.event_handler_result(Data.t()) - def connected(:cast, {:swarm, :resolve_conflict, data}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :resolve_conflict in pid #{inspect(self())} at #{Node.self()}. state: connected." - end) - {:keep_state, data} + def connected(:enter, _old_state, data) do + refresh_timeout = calculate_refresh_token_timeout() + Logger.info(fn -> "Channel #{data.channel} entering connected state" end) + {:keep_state_and_data, [{:state_timeout, refresh_timeout, :refresh_token_timeout}]} end - def connected(:info, {:swarm, :die}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :die in pid #{inspect(self())} at #{Node.self()}. state: connected." - end) - {:stop, :shutdown, state} + def connected({:call, from}, :alive?, _data) do + {:keep_state_and_data, [{:reply, from, true}]} end - def connected({:call, from}, {:swarm, :begin_handoff}, state) do - # Return the state so the new node can take over - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :begin_handoff in pid #{inspect(self())} at #{Node.self()}. state: connected." - end) - {:keep_state_and_data, [{:reply, from, {:resume, state}}]} - end + def connected( + {:call, from}, + {:socket_connected, socket_pid, _time}, + data = %{socket: {old_socket_pid, _old_socket_ref, _old_time}} + ) + when socket_pid == old_socket_pid do + # socket already connected + actions = [ + _reply = {:reply, from, :ok} + ] - def connected(:cast, {:swarm, :end_handoff, _data}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :end_handoff in pid #{inspect(self())} at #{Node.self()}. state: connected." - end) - {:next_state, :connected, state} + Logger.debug(fn -> "Channel #{data.channel} socket pid already connected." end) + {:keep_state_and_data, actions} end - def connected(:enter, _old_state, data) do - refresh_timeout = calculate_refresh_token_timeout() - Logger.info(fn -> "Channel #{data.channel} entering connected state" end) - {:keep_state_and_data, [{:state_timeout, refresh_timeout, :refresh_token_timeout}]} + def connected( + {:call, from}, + {:socket_connected, socket_pid, time}, + data = %{socket: {old_socket_pid, _old_socket_ref, old_time}} + ) + when old_time > time do + # socket already connected + actions = [ + _reply = {:reply, from, :ok} + ] + + Logger.debug(fn -> "Channel #{data.channel} socket pid #{inspect(old_socket_pid)} is newest than #{inspect(socket_pid)} by #{old_time - time}ms." end) + {:keep_state_and_data, actions} end def connected( {:call, from}, - {:socket_connected, socket_pid}, - data = %{socket: {old_socket_pid, old_socket_ref}} + {:socket_connected, socket_pid, _time}, + data = %{socket: {old_socket_pid, old_socket_ref, _old_time}} ) do Process.demonitor(old_socket_ref) send(old_socket_pid, :terminate_socket) @@ -363,7 +353,10 @@ defmodule ChannelSenderEx.Core.Channel do _reply = {:reply, from, :ok} ] - Logger.debug(fn -> "Channel #{data.channel} overwritting socket pid." end) + Logger.debug(fn -> + "Channel #{data.channel} overwritting socket pid from #{inspect(old_socket_pid)} to #{inspect(socket_pid)}" + end) + {:keep_state, new_data, actions} end @@ -448,7 +441,7 @@ defmodule ChannelSenderEx.Core.Channel do ## This is basically a message re-delivery timer. It is triggered when a message is requested to be delivered. ## And it will continue to be executed until the message is acknowledged by the client. - def connected({:timeout, {:redelivery, ref}}, retries, data = %{socket: {socket_pid, _}}) do + def connected({:timeout, {:redelivery, ref}}, retries, data = %{socket: {socket_pid, _, _}}) do {message, new_data} = retrieve_pending_ack(data, ref) max_unacknowledged_retries = get_param(:max_unacknowledged_retries, 20) @@ -551,49 +544,13 @@ defmodule ChannelSenderEx.Core.Channel do ### CLOSED STATE #### ############################################ - def closed(:cast, {:swarm, :resolve_conflict, data}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :resolve_conflict in pid #{inspect(self())} at #{Node.self()}. state: closed." - end) - {:keep_state, data} - end - - def closed({:call, from}, {:swarm, :begin_handoff}, state) do - # Return the state so the new node can take over - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :begin_handoff in pid #{inspect(self())} at #{Node.self()}. state: closed." - end) - {:keep_state_and_data, [{:reply, from, :ignore}]} - end - - def closed(:cast, {:swarm, :end_handoff, _data}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :end_handoff in pid #{inspect(self())} at #{Node.self()}. state: closed." - end) - {:next_state, :closed, state} - end - - def closed({:cast, _from}, {:swarm, :end_handoff}, state) do - # Return the state so the new node can take over - Logger.debug(fn -> - "Channel #{state.channel} end handoff in pid #{inspect(self())} at #{Node.self()}" - end) - - {:next_state, :closed, state} - end - - def closed(:info, {:swarm, :die}, state) do - Logger.debug(fn -> - "Channel #{state.channel} :swarm, :die in pid #{inspect(self())} at #{Node.self()}. state: closed." - end) - {:stop, :shutdown, state} - end - def closed(:enter, _old_state, data) do Logger.debug(fn -> "Channel #{data.channel} enter state closed." end) - ChannelSupervisor.unregister_channel(data.channel) + + ChannelSupervisor.unregister_channel(data.channel, self()) + {:stop, :normal, data} end @@ -617,7 +574,7 @@ defmodule ChannelSenderEx.Core.Channel do ######################################### @compile {:inline, send_message: 2} - defp send_message(%{socket: {socket_pid, _}}, message) do + defp send_message(%{socket: {socket_pid, _, _}}, message) do # creates message to the expected format output = create_output_message(message) # sends to socket pid @@ -736,4 +693,16 @@ defmodule ChannelSenderEx.Core.Channel do rescue _e -> def end + + defp safe_alive?(pid, self_pid) when pid == self_pid do + true + end + + defp safe_alive?(pid, _self_pid) do + try do + GenServer.call(pid, :alive?) + catch + :exit, _ -> false + end + end end diff --git a/channel-sender/lib/channel_sender_ex/core/channel_id_generator.ex b/channel-sender/lib/channel_sender_ex/core/channel_id_generator.ex index be30ac35..e09f6e32 100644 --- a/channel-sender/lib/channel_sender_ex/core/channel_id_generator.ex +++ b/channel-sender/lib/channel_sender_ex/core/channel_id_generator.ex @@ -4,7 +4,7 @@ defmodule ChannelSenderEx.Core.ChannelIDGenerator do """ import Application, only: [get_env: 2] - import Plug.Crypto, only: [verify: 4, sign: 3] + import Plug.Crypto, only: [verify: 4, sign: 4] alias ChannelSenderEx.Core.RulesProvider @type application() :: String.t() @@ -12,13 +12,17 @@ defmodule ChannelSenderEx.Core.ChannelIDGenerator do @type channel_ref() :: String.t() @type channel_secret() :: String.t() + @seconds_to_millis 1_000 + def generate_channel_id(app_id, user_id) do - "#{UUID.uuid3(:dns, "#{app_id}.#{user_id}", :hex)}.#{UUID.uuid4(:hex)}" + UUID.uuid5(UUID.uuid4(:default), "#{app_id}.#{user_id}", :hex) end def generate_token(channel_ref, app_id, user_id) do {secret, salt} = get_secret_and_salt!() - sign(secret, salt, {channel_ref, app_id, user_id}) + valid_until = System.os_time(:millisecond) + max_age() * @seconds_to_millis + token = sign(secret, salt, {channel_ref, app_id, user_id}, max_age: max_age()) # max age is expected in seconds + "#{valid_until}:#{token}" end @type token_error_reason() :: @@ -26,6 +30,16 @@ defmodule ChannelSenderEx.Core.ChannelIDGenerator do @spec verify_token(channel_ref(), channel_secret()) :: {:ok, application(), user_ref()} | {:error, token_error_reason()} def verify_token(channel_ref, channel_secret) do + case String.split(channel_secret, ":") do + [_valid_until, token] -> + verify_token_secret(channel_ref, token) + + [token] -> + verify_token_secret(channel_ref, token) + end + end + + defp verify_token_secret(channel_ref, channel_secret) do {secret, salt} = get_secret_and_salt!() case verify(secret, salt, channel_secret, max_age: max_age()) do diff --git a/channel-sender/lib/channel_sender_ex/core/channel_supervisor_cachex.ex b/channel-sender/lib/channel_sender_ex/core/channel_supervisor_cachex.ex new file mode 100644 index 00000000..9b51792f --- /dev/null +++ b/channel-sender/lib/channel_sender_ex/core/channel_supervisor_cachex.ex @@ -0,0 +1,189 @@ +defmodule ChannelSenderEx.Core.ChannelSupervisor do + use DynamicSupervisor + + @moduledoc """ + Module to start supervised channels in a distributed way + """ + require Logger + + alias ChannelSenderEx.Core.Channel + alias ChannelSenderEx.Utils.CustomTelemetry + import ChannelSenderEx.Core.Retry.ExponentialBackoff, only: [execute: 5] + @max_retries 5 + @min_backoff 50 + @max_backoff 200 + + def start_link(_) do + res = DynamicSupervisor.start_link(__MODULE__, [], name: __MODULE__) + Logger.info("Channel Supervisor started") + res + end + + def init(_) do + DynamicSupervisor.init(strategy: :one_for_one) + end + + @type channel_ref :: String.t() + @type application :: String.t() + @type user_ref :: String.t() + @type meta :: list() + @type channel_init_args :: {channel_ref(), application(), user_ref(), meta()} + + @spec start_channel(channel_init_args()) :: any() + def start_channel(args) do + Logger.debug(fn -> "Channel Supervisor, starting channel with args: #{inspect(args)}" end) + + case DynamicSupervisor.start_child(__MODULE__, {Channel, args}) do + {:ok, pid} -> + {:ok, pid} + + {:error, {:already_registered, pid}} -> + {:ok, pid} + + {:error, reason} -> + Logger.error(fn -> + "Channel Supervisor, failed to register channel with args: #{inspect(args)}, reason: #{inspect(reason)}" + end) + + {:error, reason} + end + end + + @spec register_channel(channel_init_args()) :: any() + def register_channel(args = {channel_ref, _application, _user_ref, _meta}) do + with {:ok, pid} <- start_channel(args), + {:ok, true} <- put_retried(channel_ref, pid) do + {:ok, pid} + else + {:error, reason} -> + Logger.error(fn -> + "Channel Supervisor, failed to register channel with args: #{inspect(args)}, reason: #{inspect(reason)}" + end) + + {:error, reason} + end + end + + @spec start_channel_if_not_exists(channel_init_args()) :: any() + def start_channel_if_not_exists(args = {channel_ref, _application, _user_ref, _meta}) do + pid = whereis_channel(channel_ref) + + if pid == :undefined or not Channel.alive?(pid) do + CustomTelemetry.execute_custom_event([:adf, :channel, :created_on_socket], %{count: 1}) + register_channel(args) + else + {:ok, pid} + end + end + + @spec register_channel_if_not_exists(channel_init_args()) :: any() + def register_channel_if_not_exists(_args = {channel_ref, _application, _user_ref, _meta}) do + case Cachex.get(:channels, channel_ref) do + {:ok, pid} when is_pid(pid) -> + register_if_not_running(channel_ref, pid, self()) + + {:ok, nil} -> + pid = self() + + Logger.debug(fn -> + "Channel Supervisor, channel #{channel_ref} not exists : nil self #{inspect(pid)}" + end) + + put_retried(channel_ref, pid) + {:ok, pid} + + {:error, reason} -> + Logger.error(fn -> + "Channel Supervisor, failed to register channel #{channel_ref}, reason: #{inspect(reason)}" + end) + + {:error, reason} + end + end + + @spec unregister_channel(channel_ref()) :: any() + def unregister_channel(channel_ref) do + Cachex.del(:channels, channel_ref) + end + + @spec whereis_channel(channel_ref()) :: pid() | :undefined + def whereis_channel(channel_ref) do + case Cachex.get(:channels, channel_ref) do + {:ok, pid} when is_pid(pid) -> + Logger.debug(fn -> "Channel Supervisor, channel exists : #{inspect(pid)}" end) + pid + + {:ok, nil} -> + :undefined + end + end + + @spec app_members(application()) :: list() + def app_members(_application) do + [] + end + + defp register_if_not_running(channel_ref, pid, self_pid) do + if Channel.alive?(pid) do + Logger.debug(fn -> + "Channel Supervisor, channel #{channel_ref} exists : #{inspect(pid)} self #{inspect(self_pid)}" + end) + + {:ok, pid} + else + Logger.debug(fn -> + "Channel Supervisor, channel #{channel_ref} not alive : #{inspect(pid)} self #{inspect(self_pid)}" + end) + + put_retried(channel_ref, self_pid) + {:ok, self_pid} + end + end + + defp put_retried(channel_ref, channel_pid) do + action_fn = put_action(channel_ref, channel_pid) + + execute(@min_backoff, @max_backoff, @max_retries, action_fn, fn -> + Logger.warning(fn -> + "Channel Supervisor, could not save channel #{channel_ref} after #{@max_retries} retries" + end) + + {:ok, true} + end) + end + + defp put_action(channel_ref, channel_pid) do + fn delay -> + case Cachex.put(:channels, channel_ref, channel_pid) do + {:ok, true} -> + Logger.debug(fn -> + "Channel Supervisor, channel #{channel_ref} saved in #{delay}" + end) + + verify_or_retry(channel_ref) + + other -> + Logger.debug(fn -> + "Channel Supervisor, channel #{channel_ref} could not be saved in delay #{delay} -> #{inspect(other)}" + end) + + :retry + end + end + end + + defp verify_or_retry(channel_ref) do + case Cachex.get(:channels, channel_ref) do + {:ok, pid} when is_pid(pid) -> + Logger.debug(fn -> "Channel Supervisor, channel #{channel_ref} checked save ok" end) + {:ok, true} + + other -> + Logger.debug(fn -> + "Channel Supervisor, channel #{channel_ref} checked save fail inspect #{other}" + end) + + :retry + end + end +end diff --git a/channel-sender/lib/channel_sender_ex/core/channel_supervisor_pg.ex b/channel-sender/lib/channel_sender_ex/core/channel_supervisor_pg.ex new file mode 100644 index 00000000..0040c422 --- /dev/null +++ b/channel-sender/lib/channel_sender_ex/core/channel_supervisor_pg.ex @@ -0,0 +1,116 @@ +defmodule ChannelSenderEx.Core.ChannelSupervisorPg do + use DynamicSupervisor + + @moduledoc """ + Module to start supervised channels in a distributed way using :pg module + """ + require Logger + + alias ChannelSenderEx.Core.Channel + alias ChannelSenderEx.Utils.CustomTelemetry + + def start_link(_) do + res = DynamicSupervisor.start_link(__MODULE__, [], name: __MODULE__) + Logger.info("Channel Supervisor started") + res + end + + def init(_) do + DynamicSupervisor.init(strategy: :one_for_one) + end + + @type channel_ref :: String.t() + @type application :: String.t() + @type user_ref :: String.t() + @type meta :: list() + @type channel_init_args :: {channel_ref(), application(), user_ref(), meta()} + + @spec start_channel(channel_init_args()) :: any() + def start_channel(args) do + Logger.debug(fn -> "Channel Supervisor, starting channel with args: #{inspect(args)}" end) + + case DynamicSupervisor.start_child(__MODULE__, {Channel, args}) do + {:ok, pid} -> + {:ok, pid} + + {:error, {:already_registered, pid}} -> + {:ok, pid} + + {:error, reason} -> + Logger.error(fn -> + "Channel Supervisor, failed to register channel with args: #{inspect(args)}, reason: #{inspect(reason)}" + end) + + {:error, reason} + end + end + + @spec register_channel(channel_init_args()) :: any() + def register_channel(args = {channel_ref, _application, _user_ref, _meta}) do + case start_channel(args) do + {:ok, pid} -> + register_pid(channel_ref, pid) + + {:error, reason} -> + Logger.error(fn -> + "Channel Supervisor, failed to register channel with args: #{inspect(args)}, reason: #{inspect(reason)}" + end) + + {:error, reason} + end + end + + @spec whereis_channel(channel_ref()) :: pid() | :undefined + def whereis_channel(channel_ref) do + case :pg.get_members(channel_ref) do + [] -> + :undefined + + [pid | _tail] -> + pid + end + end + + @spec start_channel_if_not_exists(channel_init_args()) :: any() + def start_channel_if_not_exists(args = {channel_ref, _application, _user_ref, _meta}) do + pid = whereis_channel(channel_ref) + + if pid == :undefined or not Channel.alive?(pid) do + CustomTelemetry.execute_custom_event([:adf, :channel, :created_on_socket], %{count: 1}) + register_channel(args) + else + {:ok, pid} + end + end + + def register_channel_if_not_exists(_args = {channel_ref, _application, _user_ref, _meta}) do + pid = whereis_channel(channel_ref) + + cond do + pid == :undefined -> + register_pid(channel_ref, self()) + + Channel.alive?(pid) -> + {:ok, pid} + + true -> + unregister_channel(channel_ref, pid) + register_pid(channel_ref, self()) + end + end + + def register_pid(channel_ref, pid) do + :pg.join(channel_ref, pid) + {:ok, pid} + end + + def unregister_channel(channel_ref, pid) do + :pg.leave(channel_ref, pid) + end + + @spec app_members(application()) :: list() + def app_members(_application) do + # :pg.get_members(application) + [] + end +end diff --git a/channel-sender/lib/channel_sender_ex/core/channel_supervisor_swarm.ex b/channel-sender/lib/channel_sender_ex/core/channel_supervisor_swarm.ex deleted file mode 100644 index aafcbf93..00000000 --- a/channel-sender/lib/channel_sender_ex/core/channel_supervisor_swarm.ex +++ /dev/null @@ -1,79 +0,0 @@ -defmodule ChannelSenderEx.Core.ChannelSupervisor do - use DynamicSupervisor - - @moduledoc """ - Module to start supervised channels in a distributed way - """ - require Logger - - alias ChannelSenderEx.Core.Channel - - def start_link(_) do - res = DynamicSupervisor.start_link(__MODULE__, [], name: __MODULE__) - Logger.info("Channel Supervisor started") - res - end - - def init(_) do - DynamicSupervisor.init(strategy: :one_for_one) - end - - @type channel_ref :: String.t() - @type application :: String.t() - @type user_ref :: String.t() - @type meta :: list() - @type channel_init_args :: {channel_ref(), application(), user_ref(), meta()} - - @spec start_channel(channel_init_args()) :: any() - def start_channel(args) do - Logger.debug(fn -> "Channel Supervisor, starting channel with args: #{inspect(args)}" end) - DynamicSupervisor.start_child(__MODULE__, {Channel, args}) - end - - @spec register_channel(channel_init_args()) :: any() - def register_channel(args = {channel_ref, _application, _user_ref, _meta}) do - case Swarm.register_name(channel_ref, __MODULE__, :start_channel, [args]) do - {:ok, pid} -> - # Swarm.join(application, pid) - {:ok, pid} - - {:error, {:already_registered, pid}} -> - # Swarm.join(application, pid) - {:ok, pid} - - {:error, reason} -> - Logger.error(fn -> - "Channel Supervisor, failed to register channel with args: #{inspect(args)}, reason: #{inspect(reason)}" - end) - - {:error, reason} - end - end - - @spec register_channel_if_not_exists(channel_init_args()) :: any() - def register_channel_if_not_exists(args = {channel_ref, _application, _user_ref, _meta}) do - case Swarm.whereis_name(channel_ref) do - pid when is_pid(pid) -> - Logger.debug(fn -> "Channel Supervisor, channel exists : #{inspect(pid)}" end) - {:ok, pid} - - :undefined -> - register_channel(args) - end - end - - @spec unregister_channel(channel_ref()) :: any() - def unregister_channel(channel_ref) do - Swarm.unregister_name(channel_ref) - end - - @spec whereis_channel(channel_ref()) :: pid() | :undefined - def whereis_channel(channel_ref) do - Swarm.whereis_name(channel_ref) - end - - @spec app_members(application()) :: list() - def app_members(application) do - Swarm.members(application) - end -end diff --git a/channel-sender/lib/channel_sender_ex/core/pubsub/pub_sub_core.ex b/channel-sender/lib/channel_sender_ex/core/pubsub/pub_sub_core.ex index 04a43e90..02b952a0 100644 --- a/channel-sender/lib/channel_sender_ex/core/pubsub/pub_sub_core.ex +++ b/channel-sender/lib/channel_sender_ex/core/pubsub/pub_sub_core.ex @@ -5,7 +5,7 @@ defmodule ChannelSenderEx.Core.PubSub.PubSubCore do require Logger alias ChannelSenderEx.Core.Channel - alias ChannelSenderEx.Core.ChannelSupervisor + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor alias ChannelSenderEx.Core.ProtocolMessage alias ChannelSenderEx.Utils.CustomTelemetry import ChannelSenderEx.Core.Retry.ExponentialBackoff, only: [execute: 5] diff --git a/channel-sender/lib/channel_sender_ex/core/pubsub/re_connect_process.ex b/channel-sender/lib/channel_sender_ex/core/pubsub/re_connect_process.ex index 968b4f86..defdac87 100644 --- a/channel-sender/lib/channel_sender_ex/core/pubsub/re_connect_process.ex +++ b/channel-sender/lib/channel_sender_ex/core/pubsub/re_connect_process.ex @@ -2,7 +2,7 @@ defmodule ChannelSenderEx.Core.PubSub.ReConnectProcess do @moduledoc false alias ChannelSenderEx.Core.Channel - alias ChannelSenderEx.Core.ChannelSupervisor + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor import ChannelSenderEx.Core.Retry.ExponentialBackoff, only: [execute: 5] require Logger @@ -12,33 +12,49 @@ defmodule ChannelSenderEx.Core.PubSub.ReConnectProcess do @max_backoff 3000 def start(socket_pid, channel_ref) do + Task.start_link(fn -> + new_pid = start_internal(socket_pid, channel_ref) + send(socket_pid, {:monitor_channel, channel_ref, new_pid}) + end) + end + + def start_internal(socket_pid, channel_ref) do Logger.debug("Starting re-connection process for channel #{channel_ref}") - action_function = create_action(channel_ref, socket_pid, Process.monitor(socket_pid)) - execute(@min_backoff, @max_backoff, @max_retries, action_function, :no_channel) + now = System.system_time(:millisecond) + action_function = create_action(channel_ref, socket_pid, now, Process.monitor(socket_pid)) + + execute( + @min_backoff, + @max_backoff, + @max_retries, + action_function, + fn -> start_channel(channel_ref, socket_pid, now) end + ) end - def create_action(channel_ref, socket_pid, socket_mon_ref) do + def create_action(channel_ref, socket_pid, time, socket_mon_ref) do fn actual_delay -> - case connect_socket_to_channel(channel_ref, socket_pid) do + case connect_socket_to_channel(channel_ref, socket_pid, time) do :noproc -> receive do {:DOWN, ^socket_mon_ref, _, _pid, :noproc} -> :void after actual_delay -> :retry end - result -> result + + result -> + result end end end - def connect_socket_to_channel(channel_ref, socket_pid) do - case ChannelSupervisor.whereis_channel(channel_ref) do + def connect_socket_to_channel(channel_ref, socket_pid, time) do + case ChannelSupervisor.whereis_channel(channel_ref) do :undefined -> :noproc + pid when is_pid(pid) -> - Logger.debug(fn -> "Connecting socket #{inspect(pid)} to channel #{channel_ref}" end) - timeout = Application.get_env(:channel_sender_ex, :on_connected_channel_reply_timeout) - Channel.socket_connected(pid, socket_pid, timeout) + connect_socket_to_pid(channel_ref, socket_pid, time, pid) pid end catch @@ -47,4 +63,29 @@ defmodule ChannelSenderEx.Core.PubSub.ReConnectProcess do :noproc end + def start_channel(channel_ref, socket_pid, time) do + case ChannelSupervisor.register_channel({channel_ref, "", "", []}) do + {:ok, pid} -> + Logger.debug( + "Re-connection process for channel #{channel_ref} solved with new channel pid: #{inspect(pid)}" + ) + + connect_socket_to_pid(channel_ref, socket_pid, time, pid) + pid + + other -> + Logger.error("Re-connection process for channel #{channel_ref} failed: #{inspect(other)}") + + other + end + end + + defp connect_socket_to_pid(channel_ref, socket_pid, time, pid) do + Logger.debug(fn -> + "Connecting socket with pid #{inspect(socket_pid)} to channel #{channel_ref} with pid #{inspect(pid)}" + end) + + timeout = Application.get_env(:channel_sender_ex, :on_connected_channel_reply_timeout) + Channel.socket_connected(pid, socket_pid, time, timeout) + end end diff --git a/channel-sender/lib/channel_sender_ex/core/pubsub/socket_event_bus.ex b/channel-sender/lib/channel_sender_ex/core/pubsub/socket_event_bus.ex index ecba0397..3bccdae7 100644 --- a/channel-sender/lib/channel_sender_ex/core/pubsub/socket_event_bus.ex +++ b/channel-sender/lib/channel_sender_ex/core/pubsub/socket_event_bus.ex @@ -4,7 +4,7 @@ defmodule ChannelSenderEx.Core.PubSub.SocketEventBus do association. """ alias ChannelSenderEx.Core.Channel - alias ChannelSenderEx.Core.ChannelSupervisor + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor # Notify the event of a socket connection. Receiving part is the channel process. def notify_event({:connected, channel}, socket_pid) when is_binary(channel) do @@ -13,7 +13,8 @@ defmodule ChannelSenderEx.Core.PubSub.SocketEventBus do def notify_event({:connected, channel_pid}, socket_pid) when is_pid(channel_pid) do timeout = Application.get_env(:channel_sender_ex, :on_connected_channel_reply_timeout) - :ok = Channel.socket_connected(channel_pid, socket_pid, timeout) + now = System.system_time(:millisecond) + :ok = Channel.socket_connected(channel_pid, socket_pid, now, timeout) channel_pid end @@ -21,16 +22,16 @@ defmodule ChannelSenderEx.Core.PubSub.SocketEventBus do def connect_channel(_, _, 7), do: raise("No channel found") def connect_channel(channel, socket_pid, count) do - case ChannelSupervisor.whereis_channel(channel) do + case ChannelSupervisor.whereis_channel(channel) do :undefined -> Process.sleep(350) connect_channel(channel, socket_pid, count + 1) + pid when is_pid(pid) -> - timeout = Application.get_env(:channel_sender_ex, - :on_connected_channel_reply_timeout) - :ok = Channel.socket_connected(pid, socket_pid, timeout) + timeout = Application.get_env(:channel_sender_ex, :on_connected_channel_reply_timeout) + now = System.system_time(:millisecond) + :ok = Channel.socket_connected(pid, socket_pid, now, timeout) pid end end - end diff --git a/channel-sender/lib/channel_sender_ex/core/security/channel_authenticator.ex b/channel-sender/lib/channel_sender_ex/core/security/channel_authenticator.ex index 30b240c4..24300160 100644 --- a/channel-sender/lib/channel_sender_ex/core/security/channel_authenticator.ex +++ b/channel-sender/lib/channel_sender_ex/core/security/channel_authenticator.ex @@ -3,7 +3,7 @@ defmodule ChannelSenderEx.Core.Security.ChannelAuthenticator do Channel Authentication logic """ alias ChannelSenderEx.Core.ChannelIDGenerator - alias ChannelSenderEx.Core.ChannelSupervisor + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor @type application() :: String.t() @type user_ref() :: String.t() diff --git a/channel-sender/lib/channel_sender_ex/transport/socket.ex b/channel-sender/lib/channel_sender_ex/transport/socket.ex index b43cbf6a..0751fb4e 100644 --- a/channel-sender/lib/channel_sender_ex/transport/socket.ex +++ b/channel-sender/lib/channel_sender_ex/transport/socket.ex @@ -6,6 +6,7 @@ defmodule ChannelSenderEx.Transport.Socket do require Logger + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor alias ChannelSenderEx.Core.ProtocolMessage alias ChannelSenderEx.Core.PubSub.ReConnectProcess alias ChannelSenderEx.Core.RulesProvider @@ -24,11 +25,14 @@ defmodule ChannelSenderEx.Transport.Socket do @impl :cowboy_websocket def init(req = %{method: "GET"}, opts) do - init_result = get_relevant_request_info(req) + init_result = + get_relevant_request_info(req) |> process_subprotocol_selection(req) + case init_result do {:cowboy_websocket, _, _, _} = res -> res + {:error, desc} -> :cowboy_req.reply(400, %{<<"x-error-code">> => desc}, req) {:ok, req, opts} @@ -36,37 +40,34 @@ defmodule ChannelSenderEx.Transport.Socket do end @impl :cowboy_websocket - def websocket_init(state = {ref, _, _}) do - Logger.debug("Socket init with pid: #{inspect(self())} starting... #{inspect(state)}") - case lookup_channel_addr(ref) do - {:ok, _pid} -> - {_commands = [], state} - {:error, desc} -> - {_commands = [{:close, 1001, desc}], state} - end + def websocket_init(state = {_ref, _, _}) do + Logger.debug(fn -> + "Socket init with pid: #{inspect(self())} starting... #{inspect(state)}" + end) + + {_commands = [], state} end @impl :cowboy_websocket def websocket_handle({:text, "Auth::" <> secret}, {channel, :pre_auth, encoder}) do - Logger.debug(fn -> "Socket for channel #{channel} received auth" end) + Logger.debug(fn -> "Socket #{inspect(self())} for channel #{channel} received auth" end) + case ChannelAuthenticator.authorize_channel(channel, secret) do {:ok, application, user_ref} -> - monitor_ref = notify_connected(channel) - - CustomTelemetry.execute_custom_event([:adf, :socket, :connection], %{count: 1}) - - {_commands = [auth_ok_frame(encoder)], - {channel, :connected, encoder, {application, user_ref, monitor_ref}, %{}}} + ensure_channel_exists_and_notify_socket(channel, application, user_ref, encoder) :unauthorized -> + CustomTelemetry.execute_custom_event( + [:adf, :socket, :badrequest], + %{count: 1}, + %{request_path: "/ext/socket", status: 101, code: @invalid_secret_code} + ) - CustomTelemetry.execute_custom_event([:adf, :socket, :badrequest], - %{count: 1}, - %{request_path: "/ext/socket", status: 101, code: @invalid_secret_code}) + Logger.error(fn -> + "Socket #{inspect(self())} unable to authorize connection. Error: #{@invalid_secret_code}-invalid token for channel #{channel}" + end) - Logger.error("Socket unable to authorize connection. Error: #{@invalid_secret_code}-invalid token for channel #{channel}") - {_commands = [{:close, 1001, <<@invalid_secret_code>>}], - {channel, :unauthorized}} + {_commands = [{:close, 1001, <<@invalid_secret_code>>}], {channel, :unauthorized}} end end @@ -82,6 +83,15 @@ defmodule ChannelSenderEx.Transport.Socket do end end + @impl :cowboy_websocket + def websocket_handle({:text, "Info::" <> message}, state = {channel_ref, _, _, _, _}) do + Logger.debug(fn -> + "Socket #{inspect(self())} for channel #{channel_ref} received info message: #{inspect(message)}" + end) + + {[], state} + end + @impl :cowboy_websocket def websocket_handle({:text, "hb::" <> hb_seq}, state = {_, :connected, encoder, _, _}) do {_commands = [encoder.heartbeat_frame(hb_seq)], state} @@ -119,7 +129,10 @@ defmodule ChannelSenderEx.Transport.Socket do @impl :cowboy_websocket def websocket_info(:terminate_socket, state = {channel_ref, _, _, _, _}) do # ! check if we need to do something with the new_socket_pid - Logger.info("Socket for channel #{channel_ref} : received terminate_socket message") + Logger.info(fn -> + "Socket #{inspect(self())} for channel #{channel_ref} : received terminate_socket message" + end) + {_commands = [{:close, 1001, <<@socket_replaced>>}], state} end @@ -127,38 +140,63 @@ defmodule ChannelSenderEx.Transport.Socket do def websocket_info({:DOWN, ref, proc, pid, cause}, state = {channel_ref, _, _, _, _}) do case cause do :normal -> - Logger.info("Socket for channel #{channel_ref}. Related process #{inspect(ref)} down normally.") + Logger.info(fn -> + "Socket #{inspect(self())} for channel #{channel_ref}. Related process #{inspect(ref)} down normally." + end) + {_commands = [{:close, 1000, <<@normal_close_code>>}], state} + _ -> Logger.warning(""" - Socket for channel #{channel_ref}. Related Process #{inspect(ref)} + Socket #{inspect(self())} for channel #{channel_ref}. Related Process #{inspect(ref)} received DOWN message: #{inspect({ref, proc, pid, cause})}. Spawning process for re-conection """) - new_pid = ReConnectProcess.start(self(), channel_ref) - Logger.debug("Socket for channel #{channel_ref} : channel process found for re-conection: #{inspect(new_pid)}") - Process.monitor(new_pid) + ReConnectProcess.start(self(), channel_ref) {_commands = [], state} end end @impl :cowboy_websocket - def websocket_info({:DOWN, _ref, :process, _pid, :no_channel}, state = {channel_ref, :connected, _, {_, _, _}, _}) do - Logger.warning("Socket for channel #{channel_ref} : spawning process for re-conection") - spawn_monitor(ReConnectProcess, :start, [self(), channel_ref]) + def websocket_info( + {:DOWN, _ref, :process, _pid, :no_channel}, + state = {channel_ref, :connected, _, {_, _, _}, _} + ) do + Logger.warning(fn -> + "Socket #{inspect(self())} for channel #{channel_ref} : spawning process for re-conection" + end) + + ReConnectProcess.start(self(), channel_ref) + + {_commands = [], state} + end + + @impl :cowboy_websocket + def websocket_info({:monitor_channel, channel_ref, new_pid}, state) do + Logger.debug(fn -> + "Socket #{inspect(self())} for channel #{channel_ref} : channel process found for re-conection: #{inspect(new_pid)}" + end) + + Process.monitor(new_pid) + {_commands = [], state} end @impl :cowboy_websocket def websocket_info(message, state) do - Logger.warning("Socket received socket info message: #{inspect(message)}, state: #{inspect(state)}") + Logger.warning(fn -> + "Socket #{inspect(self())} received socket info message: #{inspect(message)}, state: #{inspect(state)}" + end) + {_commands = [], state} end @impl :cowboy_websocket def terminate(reason, partial_req, state) do - Logger.debug("Socket terminate with pid: #{inspect(self())}. REASON: #{inspect(reason)}. REQ: #{inspect(partial_req)}, STATE: #{inspect(state)}") + Logger.debug(fn -> + "Socket terminate with pid: #{inspect(self())}. REASON: #{inspect(reason)}. REQ: #{inspect(partial_req)}, STATE: #{inspect(state)}" + end) CustomTelemetry.execute_custom_event([:adf, :socket, :disconnection], %{count: 1}) @@ -174,18 +212,21 @@ defmodule ChannelSenderEx.Transport.Socket do defp get_relevant_request_info(req) do # extracts the channel key from the request query string rs = get_channel_from_qs(req) - Logger.debug(fn -> "Socket starting with parameter: #{inspect(rs)}" end) + Logger.debug(fn -> "Socket #{inspect(self())} starting with parameter: #{inspect(rs)}" end) rs end defp process_subprotocol_selection({@channel_key, channel}, req) do case :cowboy_req.parse_header("sec-websocket-protocol", req) do :undefined -> - {:cowboy_websocket, req, _state = {channel, :pre_auth, Application.get_env( - :channel_sender_ex, - :message_encoder, - ChannelSenderEx.Transport.Encoders.JsonEncoder - )}, ws_opts()} + {:cowboy_websocket, req, + _state = + {channel, :pre_auth, + Application.get_env( + :channel_sender_ex, + :message_encoder, + ChannelSenderEx.Transport.Encoders.JsonEncoder + )}, ws_opts()} sub_protocols -> {encoder, req} = @@ -204,7 +245,10 @@ defmodule ChannelSenderEx.Transport.Socket do end defp process_subprotocol_selection(err = {:error, _}, req) do - Logger.error("Socket unable to start. Error: #{inspect(err)}. Request: #{inspect(req)}") + Logger.error(fn -> + "Socket #{inspect(self())} unable to start. Error: #{inspect(err)}. Request: #{inspect(req)}" + end) + err end @@ -220,36 +264,58 @@ defmodule ChannelSenderEx.Transport.Socket do end defp handle_terminate(:normal, _req, state) do - Logger.info("Socket with pid: #{inspect(self())} terminated with cause :normal. STATE: #{inspect(state)}") + Logger.info(fn -> + "Socket with pid: #{inspect(self())} terminated with cause :normal. STATE: #{inspect(state)}" + end) + :ok end defp handle_terminate(:remote, _req, state) do - Logger.info("Socket with pid: #{inspect(self())} terminated with cause :remote. STATE: #{inspect(state)}") + Logger.info(fn -> + "Socket with pid: #{inspect(self())} terminated with cause :remote. STATE: #{inspect(state)}" + end) + :ok end defp handle_terminate(cause = {:remote, _code, _}, _req, state) do channel_ref = extract_ref(state) - Logger.info("Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} terminated. CAUSE: #{inspect(cause)}") + + Logger.info(fn -> + "Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} terminated. CAUSE: #{inspect(cause)}" + end) + :ok end defp handle_terminate(:stop, _req, state) do channel_ref = extract_ref(state) - Logger.info("Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} terminated with :stop. STATE: #{inspect(state)}") + + Logger.info(fn -> + "Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} terminated with :stop. STATE: #{inspect(state)}" + end) + :ok end defp handle_terminate(:timeout, _req, state) do channel_ref = extract_ref(state) - Logger.info("Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} terminated with :timeout. STATE: #{inspect(state)}") + + Logger.info(fn -> + "Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} terminated with :timeout. STATE: #{inspect(state)}" + end) + :ok end defp handle_terminate({:error, :closed}, _req, state) do channel_ref = extract_ref(state) - Logger.warning("Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} was closed without receiving closing frame first") + + Logger.warning(fn -> + "Socket with pid: #{inspect(self())}, for ref #{inspect(channel_ref)} was closed without receiving closing frame first" + end) + :ok end @@ -257,13 +323,17 @@ defmodule ChannelSenderEx.Transport.Socket do # {:crash, Class, Reason} # {:error, :badencoding | :badframe | :closed | Reason} defp handle_terminate(reason, _req, state) do - Logger.info("Socket with pid: #{inspect(self())}, terminated with reason: #{inspect(reason)}. STATE: #{inspect(state)}") + Logger.info(fn -> + "Socket with pid: #{inspect(self())}, terminated with reason: #{inspect(reason)}. STATE: #{inspect(state)}" + end) + :ok end defp extract_ref(state) when is_tuple(state) do elem(state, 0) end + defp extract_ref(state), do: state @compile {:inline, auth_ok_frame: 1} @@ -271,12 +341,16 @@ defmodule ChannelSenderEx.Transport.Socket do encoder.simple_frame("AuthOk") rescue e -> - Logger.error("Socket unable to send auth ok frame: #{inspect(e)}") + Logger.error(fn -> + "Socket #{inspect(self())} unable to send auth ok frame: #{inspect(e)}" + end) + {:close, @invalid_secret_code, "Invalid token for channel"} end defp ws_opts do timeout = get_param(:socket_idle_timeout, 90_000) + %{ idle_timeout: timeout, # active_n: 5, @@ -290,4 +364,24 @@ defmodule ChannelSenderEx.Transport.Socket do } end + defp ensure_channel_exists_and_notify_socket(channel, application, user_ref, encoder) do + args = {channel, application, user_ref, []} + + case ChannelSupervisor.start_channel_if_not_exists(args) do + {:ok, pid} -> + monitor_ref = notify_connected(pid) + + CustomTelemetry.execute_custom_event([:adf, :socket, :connection], %{count: 1}) + + state = {channel, :connected, encoder, {application, user_ref, monitor_ref}, %{}} + {_commands = [auth_ok_frame(encoder)], state} + + {:error, reason} -> + Logger.error(fn -> + "Channel #{channel} not exists and unable to start. Reason: #{inspect(reason)}" + end) + + {_commands = [{:close, 1001, <<@invalid_channel_code>>}], {channel, :unauthorized}} + end + end end diff --git a/channel-sender/lib/channel_sender_ex/transport/transport_spec.ex b/channel-sender/lib/channel_sender_ex/transport/transport_spec.ex index 84223640..06ef74f8 100644 --- a/channel-sender/lib/channel_sender_ex/transport/transport_spec.ex +++ b/channel-sender/lib/channel_sender_ex/transport/transport_spec.ex @@ -16,7 +16,7 @@ defmodule ChannelSenderEx.Transport.TransportSpec do @after_compile unquote(__MODULE__) import ChannelSenderEx.Core.Retry.ExponentialBackoff, only: [execute: 5] - alias ChannelSenderEx.Core.ChannelSupervisor + alias ChannelSenderEx.Core.ChannelSupervisorPg, as: ChannelSupervisor alias ChannelSenderEx.Core.RulesProvider require Logger @@ -68,6 +68,8 @@ defmodule ChannelSenderEx.Transport.TransportSpec do # extracts the channel key from the request query string case :lists.keyfind(@channel_key, 1, :cowboy_req.parse_qs(req)) do {@channel_key, channel} = resp when byte_size(channel) > 10 -> + socket_id = Map.get(:cowboy_req.headers(req), "sec-websocket-key") + Logger.debug("Socket #{socket_id} connecting to channel #{channel}") resp _ -> {:error, @invalid_request_code} diff --git a/channel-sender/lib/channel_sender_ex/utils/custom_telemetry.ex b/channel-sender/lib/channel_sender_ex/utils/custom_telemetry.ex index 95acc34e..c043cc79 100644 --- a/channel-sender/lib/channel_sender_ex/utils/custom_telemetry.ex +++ b/channel-sender/lib/channel_sender_ex/utils/custom_telemetry.ex @@ -68,6 +68,7 @@ defmodule ChannelSenderEx.Utils.CustomTelemetry do sum("elixir.adf.channel.count", tags: [:service], reporter_options: [report_as: :counter]), sum("elixir.adf.channel.waiting.count", tags: [:service], reporter_options: [report_as: :counter]), sum("elixir.adf.channel.connected.count", tags: [:service], reporter_options: [report_as: :counter]), + sum("elixir.adf.channel.created_on_socket.count", tags: [:service], reporter_options: [report_as: :counter]), sum("elixir.adf.channel.pending.send.count", tags: [:service], reporter_options: [report_as: :counter]), sum("elixir.adf.channel.pending.ack.count", tags: [:service], reporter_options: [report_as: :counter]), diff --git a/channel-sender/mix.exs b/channel-sender/mix.exs index 739676be..458186e6 100644 --- a/channel-sender/mix.exs +++ b/channel-sender/mix.exs @@ -4,7 +4,7 @@ defmodule ChannelSenderEx.MixProject do def project do [ app: :channel_sender_ex, - version: "0.2.3", + version: "0.2.4", elixir: "~> 1.16", start_permanent: Mix.env() == :prod, deps: deps(), @@ -44,7 +44,7 @@ defmodule ChannelSenderEx.MixProject do {:gen_state_machine, "~> 2.0"}, {:jason, "~> 1.2"}, {:cors_plug, "~> 3.0"}, - {:swarm, "~> 3.4"}, + {:cachex, "~> 4.0"}, {:hackney, "~> 1.20.1", only: :test}, {:plug_crypto, "~> 2.1"}, {:stream_data, "~> 0.4", only: [:test]}, @@ -58,7 +58,9 @@ defmodule ChannelSenderEx.MixProject do {:telemetry_metrics_prometheus, "~> 1.1"}, {:telemetry_poller, "~> 1.1"}, {:cowboy_telemetry, "~> 0.4.0"}, - {:telemetry, "~> 1.3"} + {:telemetry, "~> 1.3"}, + {:eflambe, "~> 0.3.0"}, + {:observer_cli, "~> 1.8"} # {:dep_from_git, git: "https://github.com/elixir-lang/my_dep.git", tag: "0.1.0"} ] end diff --git a/channel-sender/mix.lock b/channel-sender/mix.lock index 1e4ae852..291d3a14 100644 --- a/channel-sender/mix.lock +++ b/channel-sender/mix.lock @@ -1,6 +1,7 @@ %{ "benchee": {:hex, :benchee, "0.99.0", "0efbfc31045ad2f75a48673bd1befa8a6a5855e93b8c3117aed7d7da8de65b71", [:mix], [{:deep_merge, "~> 1.0", [hex: :deep_merge, repo: "hexpm", optional: false]}], "hexpm", "672d8e9436471b7d5b77ca5be3ad69d065553e7ed8c5db29bb3d662378104618"}, "bunt": {:hex, :bunt, "1.0.0", "081c2c665f086849e6d57900292b3a161727ab40431219529f13c4ddcf3e7a44", [:mix], [], "hexpm", "dc5f86aa08a5f6fa6b8096f0735c4e76d54ae5c9fa2c143e5a1fc7c1cd9bb6b5"}, + "cachex": {:hex, :cachex, "4.1.0", "f9a9123feac30df2b75260c9a74903c0bd7ec54f345f5f6f60c7830b81ead43a", [:mix], [{:eternal, "~> 1.2", [hex: :eternal, repo: "hexpm", optional: false]}, {:ex_hash_ring, "~> 6.0", [hex: :ex_hash_ring, repo: "hexpm", optional: false]}, {:jumper, "~> 1.0", [hex: :jumper, repo: "hexpm", optional: false]}, {:sleeplocks, "~> 1.1", [hex: :sleeplocks, repo: "hexpm", optional: false]}, {:unsafe, "~> 1.0", [hex: :unsafe, repo: "hexpm", optional: false]}], "hexpm", "77f9417a5549e424bdbfeea3f8060841384c39c0b5f563a8f62f1f2c2b6d2345"}, "certifi": {:hex, :certifi, "2.12.0", "2d1cca2ec95f59643862af91f001478c9863c2ac9cb6e2f89780bfd8de987329", [:rebar3], [], "hexpm", "ee68d85df22e554040cdb4be100f33873ac6051387baf6a8f6ce82272340ff1c"}, "cors_plug": {:hex, :cors_plug, "3.0.3", "7c3ac52b39624bc616db2e937c282f3f623f25f8d550068b6710e58d04a0e330", [:mix], [{:plug, "~> 1.13", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm", "3f2d759e8c272ed3835fab2ef11b46bddab8c1ab9528167bd463b6452edf830d"}, "cowboy": {:hex, :cowboy, "2.13.0", "09d770dd5f6a22cc60c071f432cd7cb87776164527f205c5a6b0f24ff6b38990", [:make, :rebar3], [{:cowlib, ">= 2.14.0 and < 3.0.0", [hex: :cowlib, repo: "hexpm", optional: false]}, {:ranch, ">= 1.8.0 and < 3.0.0", [hex: :ranch, repo: "hexpm", optional: false]}], "hexpm", "e724d3a70995025d654c1992c7b11dbfea95205c047d86ff9bf1cda92ddc5614"}, @@ -9,14 +10,18 @@ "credo": {:hex, :credo, "1.7.12", "9e3c20463de4b5f3f23721527fcaf16722ec815e70ff6c60b86412c695d426c1", [:mix], [{:bunt, "~> 0.2.1 or ~> 1.0", [hex: :bunt, repo: "hexpm", optional: false]}, {:file_system, "~> 0.2 or ~> 1.0", [hex: :file_system, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm", "8493d45c656c5427d9c729235b99d498bd133421f3e0a683e5c1b561471291e5"}, "deep_merge": {:hex, :deep_merge, "1.0.0", "b4aa1a0d1acac393bdf38b2291af38cb1d4a52806cf7a4906f718e1feb5ee961", [:mix], [], "hexpm", "ce708e5f094b9cd4e8f2be4f00d2f4250c4095be93f8cd6d018c753894885430"}, "dialyxir": {:hex, :dialyxir, "1.4.5", "ca1571ac18e0f88d4ab245f0b60fa31ff1b12cbae2b11bd25d207f865e8ae78a", [:mix], [{:erlex, ">= 0.2.7", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "b0fb08bb8107c750db5c0b324fa2df5ceaa0f9307690ee3c1f6ba5b9eb5d35c3"}, + "eflambe": {:hex, :eflambe, "0.3.1", "ef0a35084fad1f50744496730a9662782c0a9ebf449d3e03143e23295c5926ea", [:rebar3], [{:meck, "0.9.2", [hex: :meck, repo: "hexpm", optional: false]}], "hexpm", "58d5997be606d4e269e9e9705338e055281fdf3e4935cc902c8908e9e4516c5f"}, "elixir_uuid": {:hex, :elixir_uuid, "1.2.1", "dce506597acb7e6b0daeaff52ff6a9043f5919a4c3315abb4143f0b00378c097", [:mix], [], "hexpm", "f7eba2ea6c3555cea09706492716b0d87397b88946e6380898c2889d68585752"}, "erlex": {:hex, :erlex, "0.2.7", "810e8725f96ab74d17aac676e748627a07bc87eb950d2b83acd29dc047a30595", [:mix], [], "hexpm", "3ed95f79d1a844c3f6bf0cea61e0d5612a42ce56da9c03f01df538685365efb0"}, + "eternal": {:hex, :eternal, "1.2.2", "d1641c86368de99375b98d183042dd6c2b234262b8d08dfd72b9eeaafc2a1abd", [:mix], [], "hexpm", "2c9fe32b9c3726703ba5e1d43a1d255a4f3f2d8f8f9bc19f094c7cb1a7a9e782"}, + "ex_hash_ring": {:hex, :ex_hash_ring, "6.0.4", "bef9d2d796afbbe25ab5b5a7ed746e06b99c76604f558113c273466d52fa6d6b", [:mix], [], "hexpm", "89adabf31f7d3dfaa36802ce598ce918e9b5b33bae8909ac1a4d052e1e567d18"}, "file_system": {:hex, :file_system, "1.1.0", "08d232062284546c6c34426997dd7ef6ec9f8bbd090eb91780283c9016840e8f", [:mix], [], "hexpm", "bfcf81244f416871f2a2e15c1b515287faa5db9c6bcf290222206d120b3d43f6"}, "gen_state_machine": {:hex, :gen_state_machine, "2.1.0", "a38b0e53fad812d29ec149f0d354da5d1bc0d7222c3711f3a0bd5aa608b42992", [:mix], [], "hexpm", "ae367038808db25cee2f2c4b8d0531522ea587c4995eb6f96ee73410a60fa06b"}, "gun": {:hex, :gun, "1.3.3", "cf8b51beb36c22b9c8df1921e3f2bc4d2b1f68b49ad4fbc64e91875aa14e16b4", [:rebar3], [{:cowlib, "~> 2.7.0", [hex: :cowlib, repo: "hexpm", optional: false]}], "hexpm", "3106ce167f9c9723f849e4fb54ea4a4d814e3996ae243a1c828b256e749041e0"}, "hackney": {:hex, :hackney, "1.20.1", "8d97aec62ddddd757d128bfd1df6c5861093419f8f7a4223823537bad5d064e2", [:rebar3], [{:certifi, "~> 2.12.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.4.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", "fe9094e5f1a2a2c0a7d10918fee36bfec0ec2a979994cff8cfe8058cd9af38e3"}, "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.4", "b9226785a9aa77b6857ca22832cffa5d5011a667207eb2a0ad56adb5db443b8a", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "c5eb0cab91f094599f94d55bc63409236a8ec69a21a67814529e8d5f6cc90b3b"}, + "jumper": {:hex, :jumper, "1.0.2", "68cdcd84472a00ac596b4e6459a41b3062d4427cbd4f1e8c8793c5b54f1406a7", [:mix], [], "hexpm", "9b7782409021e01ab3c08270e26f36eb62976a38c1aa64b2eaf6348422f165e1"}, "libcluster": {:hex, :libcluster, "3.4.1", "271d2da892763bbef53c2872036c936fe8b80111eb1feefb2d30a3bb15c9b4f6", [:mix], [{:jason, "~> 1.1", [hex: :jason, repo: "hexpm", optional: false]}, {:telemetry, "~> 1.3", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "1d568157f069c6afa70ec0d736704cf799734bdbb6343f0322af4a980301c853"}, "libring": {:hex, :libring, "1.7.0", "4f245d2f1476cd7ed8f03740f6431acba815401e40299208c7f5c640e1883bda", [:mix], [], "hexpm", "070e3593cb572e04f2c8470dd0c119bc1817a7a0a7f88229f43cf0345268ec42"}, "meck": {:hex, :meck, "0.9.2", "85ccbab053f1db86c7ca240e9fc718170ee5bda03810a6292b5306bf31bae5f5", [:rebar3], [], "hexpm", "81344f561357dc40a8344afa53767c32669153355b626ea9fcbc8da6b3045826"}, @@ -25,11 +30,14 @@ "mimerl": {:hex, :mimerl, "1.3.0", "d0cd9fc04b9061f82490f6581e0128379830e78535e017f7780f37fea7545726", [:rebar3], [], "hexpm", "a1e15a50d1887217de95f0b9b0793e32853f7c258a5cd227650889b38839fe9d"}, "mock": {:hex, :mock, "0.3.9", "10e44ad1f5962480c5c9b9fa779c6c63de9bd31997c8e04a853ec990a9d841af", [:mix], [{:meck, "~> 0.9.2", [hex: :meck, repo: "hexpm", optional: false]}], "hexpm", "9e1b244c4ca2551bb17bb8415eed89e40ee1308e0fbaed0a4fdfe3ec8a4adbd3"}, "norm": {:hex, :norm, "0.13.1", "f4c7effe3926e7a27cbf835470e13941916c49209d65c2f3035d05ac21c948b2", [:mix], [{:stream_data, "~> 0.6 or ~> 1.0", [hex: :stream_data, repo: "hexpm", optional: true]}], "hexpm", "b29f4b2f0a2dae13b4793300dd1a08bbacb0d66e2c665e42b364b1be8e3233f3"}, + "observer_cli": {:hex, :observer_cli, "1.8.3", "866ee083eb3482d5f40d301c2ac7e1df0b6061d02ae771e164d71931d3c687c4", [:mix, :rebar3], [{:recon, "~> 2.5.6", [hex: :recon, repo: "hexpm", optional: false]}], "hexpm", "041c638d54cc8265e6e0472aec7c17a83bb2c4a02628ddedd9138747d9d0b8bf"}, "parse_trans": {:hex, :parse_trans, "3.4.1", "6e6aa8167cb44cc8f39441d05193be6e6f4e7c2946cb2759f015f8c56b76e5ff", [:rebar3], [], "hexpm", "620a406ce75dada827b82e453c19cf06776be266f5a67cff34e1ef2cbb60e49a"}, "plug": {:hex, :plug, "1.17.0", "a0832e7af4ae0f4819e0c08dd2e7482364937aea6a8a997a679f2cbb7e026b2e", [:mix], [{:mime, "~> 1.0 or ~> 2.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.1.1 or ~> 1.2 or ~> 2.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.3 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "f6692046652a69a00a5a21d0b7e11fcf401064839d59d6b8787f23af55b1e6bc"}, "plug_cowboy": {:hex, :plug_cowboy, "2.7.3", "1304d36752e8bdde213cea59ef424ca932910a91a07ef9f3874be709c4ddb94b", [:mix], [{:cowboy, "~> 2.7", [hex: :cowboy, repo: "hexpm", optional: false]}, {:cowboy_telemetry, "~> 0.3", [hex: :cowboy_telemetry, repo: "hexpm", optional: false]}, {:plug, "~> 1.14", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm", "77c95524b2aa5364b247fa17089029e73b951ebc1adeef429361eab0bb55819d"}, "plug_crypto": {:hex, :plug_crypto, "2.1.1", "19bda8184399cb24afa10be734f84a16ea0a2bc65054e23a62bb10f06bc89491", [:mix], [], "hexpm", "6470bce6ffe41c8bd497612ffde1a7e4af67f36a15eea5f921af71cf3e11247c"}, "ranch": {:hex, :ranch, "2.2.0", "25528f82bc8d7c6152c57666ca99ec716510fe0925cb188172f41ce93117b1b0", [:make, :rebar3], [], "hexpm", "fa0b99a1780c80218a4197a59ea8d3bdae32fbff7e88527d7d8a4787eff4f8e7"}, + "recon": {:hex, :recon, "2.5.6", "9052588e83bfedfd9b72e1034532aee2a5369d9d9343b61aeb7fbce761010741", [:mix, :rebar3], [], "hexpm", "96c6799792d735cc0f0fd0f86267e9d351e63339cbe03df9d162010cefc26bb0"}, + "sleeplocks": {:hex, :sleeplocks, "1.1.3", "96a86460cc33b435c7310dbd27ec82ca2c1f24ae38e34f8edde97f756503441a", [:rebar3], [], "hexpm", "d3b3958552e6eb16f463921e70ae7c767519ef8f5be46d7696cc1ed649421321"}, "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.7", "354c321cf377240c7b8716899e182ce4890c5938111a1296add3ec74cf1715df", [:make, :mix, :rebar3], [], "hexpm", "fe4c190e8f37401d30167c8c405eda19469f34577987c76dde613e838bbc67f8"}, "stream_data": {:hex, :stream_data, "0.6.0", "e87a9a79d7ec23d10ff83eb025141ef4915eeb09d4491f79e52f2562b73e5f47", [:mix], [], "hexpm", "b92b5031b650ca480ced047578f1d57ea6dd563f5b57464ad274718c9c29501c"}, "swarm": {:hex, :swarm, "3.4.0", "64f8b30055d74640d2186c66354b33b999438692a91be275bb89cdc7e401f448", [:mix], [{:gen_state_machine, "~> 2.0", [hex: :gen_state_machine, repo: "hexpm", optional: false]}, {:libring, "~> 1.0", [hex: :libring, repo: "hexpm", optional: false]}], "hexpm", "94884f84783fc1ba027aba8fe8a7dae4aad78c98e9f9c76667ec3471585c08c6"}, @@ -40,6 +48,7 @@ "telemetry_poller": {:hex, :telemetry_poller, "1.2.0", "ba82e333215aed9dd2096f93bd1d13ae89d249f82760fcada0850ba33bac154b", [:rebar3], [{:telemetry, "~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "7216e21a6c326eb9aa44328028c34e9fd348fb53667ca837be59d0aa2a0156e8"}, "toml": {:hex, :toml, "0.7.0", "fbcd773caa937d0c7a02c301a1feea25612720ac3fa1ccb8bfd9d30d822911de", [:mix], [], "hexpm", "0690246a2478c1defd100b0c9b89b4ea280a22be9a7b313a8a058a2408a2fa70"}, "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.0", "bc84380c9ab48177092f43ac89e4dfa2c6d62b40b8bd132b1059ecc7232f9a78", [:rebar3], [], "hexpm", "25eee6d67df61960cf6a794239566599b09e17e668d3700247bc498638152521"}, + "unsafe": {:hex, :unsafe, "1.0.2", "23c6be12f6c1605364801f4b47007c0c159497d0446ad378b5cf05f1855c0581", [:mix], [], "hexpm", "b485231683c3ab01a9cd44cb4a79f152c6f3bb87358439c6f68791b85c2df675"}, "vapor": {:hex, :vapor, "0.10.0", "547a94b381093dea61a4ca2200109385b6e44b86d72d1ebf93e5ac1a8873bc3c", [:mix], [{:jason, "~> 1.1", [hex: :jason, repo: "hexpm", optional: false]}, {:norm, "~> 0.9", [hex: :norm, repo: "hexpm", optional: false]}, {:toml, "~> 0.3", [hex: :toml, repo: "hexpm", optional: false]}, {:yaml_elixir, "~> 2.1", [hex: :yaml_elixir, repo: "hexpm", optional: false]}], "hexpm", "ee6d089a71309647a0a2a2ae6cf3bea61739a983e8c1310d53ff04b1493afbc1"}, "yamerl": {:hex, :yamerl, "0.10.0", "4ff81fee2f1f6a46f1700c0d880b24d193ddb74bd14ef42cb0bcf46e81ef2f8e", [:rebar3], [], "hexpm", "346adb2963f1051dc837a2364e4acf6eb7d80097c0f53cbdc3046ec8ec4b4e6e"}, "yaml_elixir": {:hex, :yaml_elixir, "2.11.0", "9e9ccd134e861c66b84825a3542a1c22ba33f338d82c07282f4f1f52d847bd50", [:mix], [{:yamerl, "~> 0.10", [hex: :yamerl, repo: "hexpm", optional: false]}], "hexpm", "53cc28357ee7eb952344995787f4bb8cc3cecbf189652236e9b163e8ce1bc242"}, diff --git a/channel-sender/test/channel_sender_ex/core/channel_integration_test.exs b/channel-sender/test/channel_sender_ex/core/channel_integration_test.exs index a7dfe576..8b021463 100644 --- a/channel-sender/test/channel_sender_ex/core/channel_integration_test.exs +++ b/channel-sender/test/channel_sender_ex/core/channel_integration_test.exs @@ -26,12 +26,12 @@ defmodule ChannelSenderEx.Core.ChannelIntegrationTest do "socket auth" }) - {:ok, _} = Application.ensure_all_started(:swarm) {:ok, _} = Application.ensure_all_started(:libcluster) {:ok, _} = Application.ensure_all_started(:cowboy) {:ok, _} = Application.ensure_all_started(:gun) {:ok, _} = Application.ensure_all_started(:plug_crypto) {:ok, _} = Application.ensure_all_started(:telemetry) + {:ok, _} = Application.ensure_all_started(:cachex) Helper.compile(:channel_sender_ex) @@ -43,7 +43,8 @@ defmodule ChannelSenderEx.Core.ChannelIntegrationTest do } children = [ - ChannelSupervisor + ChannelSupervisor, + {Cachex, [:channels]} ] opts = [strategy: :one_for_one, name: ChannelSenderEx.Supervisor] Supervisor.start_link(children, opts) diff --git a/channel-sender/test/channel_sender_ex/core/channel_test.exs b/channel-sender/test/channel_sender_ex/core/channel_test.exs index 61c79776..fc65d3ae 100644 --- a/channel-sender/test/channel_sender_ex/core/channel_test.exs +++ b/channel-sender/test/channel_sender_ex/core/channel_test.exs @@ -10,6 +10,7 @@ defmodule ChannelSenderEx.Core.ChannelTest do alias ChannelSenderEx.Core.ProtocolMessage alias ChannelSenderEx.Core.RulesProvider alias ChannelSenderEx.Core.RulesProvider.Helper + alias Hex.Netrc.Cache @moduletag :capture_log @@ -28,9 +29,8 @@ defmodule ChannelSenderEx.Core.ChannelTest do "aV4ZPOf7T7HX6GvbhwyBlDM8B9jfeiwi+9qkBnjXxUZXqAeTrehojWKHkV3U0kGc", "socket auth" }) - + {:ok, _} = Application.ensure_all_started(:cachex) {:ok, _} = Application.ensure_all_started(:plug_crypto) - {:ok, _} = Application.ensure_all_started(:swarm) Helper.compile(:channel_sender_ex) :ok end diff --git a/channel-sender/test/channel_sender_ex/core/pubsub/pub_sub_core_test.exs b/channel-sender/test/channel_sender_ex/core/pubsub/pub_sub_core_test.exs index f619ab40..8a8db2f5 100644 --- a/channel-sender/test/channel_sender_ex/core/pubsub/pub_sub_core_test.exs +++ b/channel-sender/test/channel_sender_ex/core/pubsub/pub_sub_core_test.exs @@ -8,37 +8,38 @@ defmodule ChannelSenderEx.Core.PubSub.PubSubCoreTest do test "should deliver to channel" do with_mocks([ - {Swarm, [], [ - whereis_name: fn(_) -> :c.pid(0, 255, 0) end + {Cachex, [], [ + get: fn(_, _) -> {:ok, :c.pid(0, 255, 0)} end ]}, {Channel, [], [deliver_message: fn(_, _) -> :accepted_connected end]} ]) do assert :accepted_connected == PubSubCore.deliver_to_channel("channel_ref", %{}) - assert_called_exactly Swarm.whereis_name("channel_ref"), 1 + assert_called_exactly Cachex.get(:channels, "channel_ref"), 1 end end test "should retry when channel not found" do with_mock( - Swarm, [whereis_name: fn(_) -> :undefined end] + Cachex, [get: fn(_, _) -> {:ok, nil} end] ) do assert :error == PubSubCore.deliver_to_channel("channel_ref", %{}) - assert_called_exactly Swarm.whereis_name("channel_ref"), 10 + assert_called_exactly Cachex.get(:channels, "channel_ref"), 10 end end - test "should deliver to all channels associated with the given application reference" do - with_mocks([ - {Swarm, [], [ - members: fn(_) -> [:c.pid(0, 255, 0), :c.pid(0, 254, 0)] end - ]}, - {Channel, [], [deliver_message: fn(_, _) -> :accepted_connected end]} - ]) do - assert %{accepted_connected: 2} == PubSubCore.deliver_to_app_channels("app_ref", %{}) - assert_called_exactly Swarm.members("app_ref"), 1 - assert_called_exactly Channel.deliver_message(:_, :_), 2 - end - end + # No implementado con Cachex + # test "should deliver to all channels associated with the given application reference" do + # with_mocks([ + # {Swarm, [], [ + # members: fn(_) -> [:c.pid(0, 255, 0), :c.pid(0, 254, 0)] end + # ]}, + # {Channel, [], [deliver_message: fn(_, _) -> :accepted_connected end]} + # ]) do + # assert %{accepted_connected: 2} == PubSubCore.deliver_to_app_channels("app_ref", %{}) + # assert_called_exactly Swarm.members("app_ref"), 1 + # assert_called_exactly Channel.deliver_message(:_, :_), 2 + # end + # end test "should deliver to all channels associated with the given user reference" do with_mocks([ @@ -51,7 +52,7 @@ defmodule ChannelSenderEx.Core.PubSub.PubSubCoreTest do test "should handle call to delete (end) non-existent channel" do with_mock( - Swarm, [whereis_name: fn(_) -> :undefined end] + Cachex, [get: fn(_, _) -> {:ok, nil} end] ) do assert :ok == PubSubCore.delete_channel("channel_ref") end @@ -59,7 +60,7 @@ defmodule ChannelSenderEx.Core.PubSub.PubSubCoreTest do test "should handle call to delete (end) existent channel" do with_mocks([ - {Swarm, [], [whereis_name: fn(_) -> :c.pid(0, 255, 0) end]}, + {Cachex, [], [get: fn(_, _) -> {:ok, :c.pid(0, 255, 0)} end]}, {Channel, [], [stop: fn(_) -> :ok end]} ]) do assert :ok == PubSubCore.delete_channel("channel_ref") diff --git a/channel-sender/test/channel_sender_ex/core/pubsub/re_connect_process_test.exs b/channel-sender/test/channel_sender_ex/core/pubsub/re_connect_process_test.exs index caaf53f6..8b4139cf 100644 --- a/channel-sender/test/channel_sender_ex/core/pubsub/re_connect_process_test.exs +++ b/channel-sender/test/channel_sender_ex/core/pubsub/re_connect_process_test.exs @@ -15,7 +15,7 @@ defmodule ChannelSenderEx.Core.PubSub.ReConnectProcessTest do test "should not connect processes, due to process not registered" do with_mock( - Swarm, [whereis_name: fn(_) -> :undefined end] + Cachex, [get: fn(_, _) -> {:ok, nil} end] ) do assert ReConnectProcess.connect_socket_to_channel("channel_ref", :c.pid(0, 250, 0)) == :noproc end @@ -23,7 +23,7 @@ defmodule ChannelSenderEx.Core.PubSub.ReConnectProcessTest do test "should not connect processes, handle error" do with_mock( - Swarm, [whereis_name: fn(_) -> raise("dummy") end] + Cachex, [get: fn(_, _) -> raise("dummy") end] ) do assert ReConnectProcess.connect_socket_to_channel("channel_ref", :c.pid(0, 250, 0)) == :noproc end @@ -31,7 +31,7 @@ defmodule ChannelSenderEx.Core.PubSub.ReConnectProcessTest do test "should query and connect processes" do with_mocks([ - {Swarm, [], [whereis_name: fn(_) -> :c.pid(0, 200, 0) end]}, + {Cachex, [], [get: fn(_, _) -> {:ok, :c.pid(0, 200, 0)} end]}, {Channel, [], [socket_connected: fn(_, _, _) -> :ok end]}, ]) do assert is_pid(ReConnectProcess.connect_socket_to_channel("channel_ref", :c.pid(0, 250, 0))) diff --git a/channel-sender/test/channel_sender_ex/core/pubsub/socket_event_bus_test.exs b/channel-sender/test/channel_sender_ex/core/pubsub/socket_event_bus_test.exs index 67a1ff08..793edfd9 100644 --- a/channel-sender/test/channel_sender_ex/core/pubsub/socket_event_bus_test.exs +++ b/channel-sender/test/channel_sender_ex/core/pubsub/socket_event_bus_test.exs @@ -10,7 +10,7 @@ defmodule ChannelSenderEx.Core.PubSub.SocketEventBusTest do channel = "some_channel" socket_pid = self() - with_mock Swarm, [whereis_name: fn(_) -> :undefined end] do + with_mock Cachex, [get: fn(_, _) -> {:ok, nil} end] do assert_raise RuntimeError, "No channel found", fn -> SocketEventBus.notify_event({:connected, channel}, socket_pid) end end end @@ -21,7 +21,7 @@ defmodule ChannelSenderEx.Core.PubSub.SocketEventBusTest do socket_pid = self() with_mocks([ - {Swarm, [], [whereis_name: fn(_) -> pid end]}, + {Cachex, [], [get: fn(_, _) -> {:ok, pid} end]}, {Channel, [], [socket_connected: fn(_, _, _) -> :ok end]} ]) do assert SocketEventBus.notify_event({:connected, channel}, socket_pid) == pid diff --git a/channel-sender/test/channel_sender_ex/core/security/channel_authenticator_test.exs b/channel-sender/test/channel_sender_ex/core/security/channel_authenticator_test.exs index 7167293f..1ed5e6ff 100644 --- a/channel-sender/test/channel_sender_ex/core/security/channel_authenticator_test.exs +++ b/channel-sender/test/channel_sender_ex/core/security/channel_authenticator_test.exs @@ -23,10 +23,6 @@ defmodule ChannelSenderEx.Core.Security.ChannelAuthenticatorTest do test "Should create channel" do with_mocks([ - {Swarm, [], [ - register_name: fn(_, _, _, _) -> {:ok, :c.pid(0, 255, 0)} end, - join: fn(_, _) -> :ok end - ]}, {ChannelSupervisor, [], [ start_channel: fn(_) -> {:ok, :c.pid(0, 255, 0)} end, register_channel: fn(_) -> {:ok, :c.pid(0, 255, 0)} end @@ -38,10 +34,6 @@ defmodule ChannelSenderEx.Core.Security.ChannelAuthenticatorTest do test "Should verify creds" do with_mocks([ - {Swarm, [], [ - register_name: fn(_, _, _, _) -> {:ok, :c.pid(0, 255, 0)} end, - join: fn(_, _) -> :ok end - ]}, {ChannelSupervisor, [], [ start_channel: fn(_) -> {:ok, :c.pid(0, 255, 0)} end, register_channel: fn(_) -> {:ok, :c.pid(0, 255, 0)} end diff --git a/channel-sender/test/channel_sender_ex/transport/longpoll_integration_test.exs b/channel-sender/test/channel_sender_ex/transport/longpoll_integration_test.exs index 1ac6d2f8..bb154a98 100644 --- a/channel-sender/test/channel_sender_ex/transport/longpoll_integration_test.exs +++ b/channel-sender/test/channel_sender_ex/transport/longpoll_integration_test.exs @@ -26,11 +26,11 @@ defmodule ChannelSenderEx.Transport.LongPollIntegrationTest do "socket auth" }) - {:ok, _} = Application.ensure_all_started(:swarm) {:ok, _} = Application.ensure_all_started(:libcluster) {:ok, _} = Application.ensure_all_started(:cowboy) {:ok, _} = Application.ensure_all_started(:gun) {:ok, _} = Application.ensure_all_started(:plug_crypto) + {:ok, _} = Application.ensure_all_started(:cachex) Helper.compile(:channel_sender_ex) ext_message = %{ @@ -41,7 +41,8 @@ defmodule ChannelSenderEx.Transport.LongPollIntegrationTest do } children = [ - ChannelSupervisor + ChannelSupervisor, + {Cachex, [:channels]} ] opts = [strategy: :one_for_one, name: ChannelSenderEx.Supervisor] {:ok, pid_supervisor} = Supervisor.start_link(children, opts) diff --git a/channel-sender/test/channel_sender_ex/transport/socket_integration_test.exs b/channel-sender/test/channel_sender_ex/transport/socket_integration_test.exs index fe7b4def..b41a1cf9 100644 --- a/channel-sender/test/channel_sender_ex/transport/socket_integration_test.exs +++ b/channel-sender/test/channel_sender_ex/transport/socket_integration_test.exs @@ -32,11 +32,11 @@ defmodule ChannelSenderEx.Transport.SocketIntegrationTest do "socket auth" }) - {:ok, _} = Application.ensure_all_started(:swarm) {:ok, _} = Application.ensure_all_started(:libcluster) {:ok, _} = Application.ensure_all_started(:cowboy) {:ok, _} = Application.ensure_all_started(:gun) {:ok, _} = Application.ensure_all_started(:plug_crypto) + {:ok, _} = Application.ensure_all_started(:cachex) Helper.compile(:channel_sender_ex) ext_message = %{ @@ -47,7 +47,8 @@ defmodule ChannelSenderEx.Transport.SocketIntegrationTest do } children = [ - ChannelSupervisor + ChannelSupervisor, + {Cachex, [:channels]}, ] opts = [strategy: :one_for_one, name: ChannelSenderEx.Supervisor] {:ok, pid_supervisor} = Supervisor.start_link(children, opts) @@ -200,11 +201,11 @@ defmodule ChannelSenderEx.Transport.SocketIntegrationTest do assert {:binary, _} = assert_receive_and_close(channel, conn_stream) end - test "Should not connect to channel when not previoulsy registered", %{port: port} do + test "Should allow to connect socket when channel not previoulsy registered", %{port: port} do {app_id, user_ref} = {"App1", "User1234"} channel_ref = ChannelIDGenerator.generate_channel_id(app_id, user_ref) channel_secret = ChannelIDGenerator.generate_token(channel_ref, app_id, user_ref) - {_conn, _stream} = assert_reject(port, channel_ref, channel_secret) + assert_connect_and_authenticate(port, channel_ref, channel_secret) end test "Should reestablish Channel link when Channel gets restarted", %{ diff --git a/channel-sender/test/channel_sender_ex/transport/sse_integration_test.exs b/channel-sender/test/channel_sender_ex/transport/sse_integration_test.exs index 8e6fad84..8e6a639f 100644 --- a/channel-sender/test/channel_sender_ex/transport/sse_integration_test.exs +++ b/channel-sender/test/channel_sender_ex/transport/sse_integration_test.exs @@ -26,11 +26,11 @@ defmodule ChannelSenderEx.Transport.SseIntegrationTest do "socket auth" }) - {:ok, _} = Application.ensure_all_started(:swarm) {:ok, _} = Application.ensure_all_started(:libcluster) {:ok, _} = Application.ensure_all_started(:cowboy) {:ok, _} = Application.ensure_all_started(:gun) {:ok, _} = Application.ensure_all_started(:plug_crypto) + {:ok, _} = Application.ensure_all_started(:cachex) Helper.compile(:channel_sender_ex) ext_message = %{ @@ -41,7 +41,8 @@ defmodule ChannelSenderEx.Transport.SseIntegrationTest do } children = [ - ChannelSupervisor + ChannelSupervisor, + {Cachex, [:channels]} ] opts = [strategy: :one_for_one, name: ChannelSenderEx.Supervisor] {:ok, pid_supervisor} = Supervisor.start_link(children, opts) diff --git a/clients/client-dart/lib/src/async_client.dart b/clients/client-dart/lib/src/async_client.dart index 40194cb9..e63ed017 100644 --- a/clients/client-dart/lib/src/async_client.dart +++ b/clients/client-dart/lib/src/async_client.dart @@ -101,12 +101,20 @@ class AsyncClient { (message) { if (eventFilters.contains(message.event)) { onData(message); + } else { + _log.warning( + '[async-client][Main] received event name "${message.event}" does not match event filters: "$eventFilters" ', + ); + _transportStrategy.sendInfo('not-subscribed-to[${message.event}]'); } }, onError: (error, stacktrace) { + _log.warning( + '[async-client][Main] Event stream signaled an error', + ); if (onError != null) { onError(error); - } + } }, onDone: () { _log.warning( diff --git a/clients/client-dart/lib/src/transport/default_transport_strategy.dart b/clients/client-dart/lib/src/transport/default_transport_strategy.dart index 1047a0ca..8d6870ab 100644 --- a/clients/client-dart/lib/src/transport/default_transport_strategy.dart +++ b/clients/client-dart/lib/src/transport/default_transport_strategy.dart @@ -77,6 +77,10 @@ class DefaultTransportStrategy { _currentTransport = NoopTransport(); } + Future sendInfo(String message) async { + _currentTransport.send('Info::$message'); + } + Transport getTransport() { return _currentTransport; } diff --git a/clients/client-dart/lib/src/transport/noop_transport.dart b/clients/client-dart/lib/src/transport/noop_transport.dart index 1e138e80..51a525de 100644 --- a/clients/client-dart/lib/src/transport/noop_transport.dart +++ b/clients/client-dart/lib/src/transport/noop_transport.dart @@ -13,6 +13,11 @@ class NoopTransport implements Transport { return Future.value(null); } + @override + void send(String message) { + // No operation + } + @override bool isOpen() { return false; diff --git a/clients/client-dart/lib/src/transport/sse_transport.dart b/clients/client-dart/lib/src/transport/sse_transport.dart index a07b8dc5..9c9b2646 100644 --- a/clients/client-dart/lib/src/transport/sse_transport.dart +++ b/clients/client-dart/lib/src/transport/sse_transport.dart @@ -105,6 +105,10 @@ class SSETransport implements Transport { return true; } + void send(String message) { + _log.warning('[async-client][SSETransport] method Send not supported'); + } + void _handleNewToken(ChannelMessage message) { _log.finest('[async-client][SSETransport] new token received'); currentToken = message.payload; diff --git a/clients/client-dart/lib/src/transport/transport.dart b/clients/client-dart/lib/src/transport/transport.dart index 4a5b3777..73f94767 100644 --- a/clients/client-dart/lib/src/transport/transport.dart +++ b/clients/client-dart/lib/src/transport/transport.dart @@ -5,6 +5,7 @@ abstract class Transport { Future connect(); Future disconnect(); bool isOpen(); + void send(String message); Stream get stream; } diff --git a/clients/client-dart/lib/src/transport/ws_transport.dart b/clients/client-dart/lib/src/transport/ws_transport.dart index db6db4a8..d9930a50 100644 --- a/clients/client-dart/lib/src/transport/ws_transport.dart +++ b/clients/client-dart/lib/src/transport/ws_transport.dart @@ -17,6 +17,7 @@ import 'transport.dart'; class WSTransport implements Transport { MessageDecoder msgDecoder = JsonDecoder(); String? pendingHeartbeatRef; + int pendingHeartbeatCount = 0; late String currentToken; static const String JSON_FLOW = 'json_flow'; @@ -30,6 +31,7 @@ class WSTransport implements Transport { static const int SOCKET_NORMAL_CLOSE = 1000; static const int SOCKET_GOING_AWAY = 1001; static const int SENDER_INVALID_REF = 3050; + static const int MAX_LOST_HEARTBEATS = 3; // TODO: make this configurable static const int RETRY_DEFAULT_MAX_RETRIES = 5; @@ -70,10 +72,12 @@ class WSTransport implements Transport { ChannelMessage>.broadcast(); // subscribers stream of data _connectRetryTimer = RetryTimer( - () async { // action callback + () async { + // action callback return await connect(); }, - () async { // limit reached callback + () async { + // limit reached callback _onSocketError( MaxRetriesException( 'Max retries reached', @@ -124,7 +128,7 @@ class WSTransport implements Transport { await Future.delayed(Duration(milliseconds: wait)); } } - + if (connected && _connectRetryTimer.isActive()) { _log.finer('[async-client][WSTransport] connect() resetting timer.'); _connectRetryTimer.reset(); @@ -199,6 +203,12 @@ class WSTransport implements Transport { '[async-client][WSTransport] Creating stream from socket, with cancelOnErrorFlag=$cancelOnErrorFlag', ); + try { + _socketStreamSub?.cancel(); + } catch (e) { + _log.info( + '[async-client][WSTransport] Error cancelling stream before subscription: $e'); + } try { _socketStreamSub = _webSocketCh.listen( (data) { @@ -208,7 +218,10 @@ class WSTransport implements Transport { }, onError: (error, stackTrace) { _log.severe('[async-client][WSTransport] signaling on error...'); - _onSocketError(error, stackTrace); + _onSocketError( + error, + stackTrace, + ); }, onDone: () { _streamDone = true; @@ -248,8 +261,7 @@ class WSTransport implements Transport { var kind = EVENT_KIND_SYSTEM; if (message.event == RESPONSE_AUTH_OK) { _handleAuthResponse(); - } else if (message.event == RESPONSE_HB && - message.correlationId == pendingHeartbeatRef) { + } else if (message.event == RESPONSE_HB) { _handleCleanHeartBeat(); } else if (message.event == RESPONSE_NEW_TOKEN) { _handleNewToken(message); @@ -276,14 +288,15 @@ class WSTransport implements Transport { } void _onSocketError(Exception error, StackTrace stackTrace) { - _log.severe('[async-client][WSTransport] onSocketError: ${error.toString()}'); + _log.severe( + '[async-client][WSTransport] onSocketError: ${error.toString()}'); if (error is MaxRetriesException) { _log.severe('[async-client][WSTransport] Max retries reached'); _signalSocketError(error); - return; - } + return; + } var heartbeatTimer = _heartbeatTimer; if (heartbeatTimer != null) { @@ -336,6 +349,7 @@ class WSTransport implements Transport { void resetHeartbeat() { pendingHeartbeatRef = null; + pendingHeartbeatCount = 0; if (_heartbeatTimer != null) { _heartbeatTimer?.cancel(); } @@ -349,8 +363,9 @@ class WSTransport implements Transport { if (!isOpen()) { return; } - if (pendingHeartbeatRef != null) { + if (pendingHeartbeatCount >= MAX_LOST_HEARTBEATS) { pendingHeartbeatRef = null; + pendingHeartbeatCount = 0; String reason = 'heartbeat timeout. Attempting to re-establish connection heartbeat interval ${_config.hbInterval} ms'; _log.warning('[async-client][WSTransport] transport: $reason'); @@ -359,6 +374,7 @@ class WSTransport implements Transport { return; } pendingHeartbeatRef = _makeRef(); + pendingHeartbeatCount++; send('hb::$pendingHeartbeatRef'); } @@ -393,6 +409,7 @@ class WSTransport implements Transport { void _handleCleanHeartBeat() { pendingHeartbeatRef = null; + pendingHeartbeatCount--; } // Function to handle the refreshed channel secret sent by the server diff --git a/clients/client-dart/lib/src/utils/retry_timer.dart b/clients/client-dart/lib/src/utils/retry_timer.dart index f737b5ff..80ae8c04 100644 --- a/clients/client-dart/lib/src/utils/retry_timer.dart +++ b/clients/client-dart/lib/src/utils/retry_timer.dart @@ -51,6 +51,11 @@ class RetryTimer { } void schedule() { + if (_timer?.isActive ?? false) { + _log.finest('[async-client][RetyTimer] Timer already active, skipping scheduling'); + + return; + } var delay = _delay(); _log.info('[async-client][RetyTimer] scheduling retry in $delay ms'); _timer = Timer(Duration(milliseconds: delay), () async {