fix(emqx_channel): do not log stale sock_close event as error

In some cases, EMQX may decide to close socket and mark connection
at 'disconnected' state, for example, when DISCONNECTE packet is
received, or, when failed to write data to socket.
However, by the time EMQX decided to close the socket, the socket
might have already been closed by peer, and the `tcp_closed` envet
is already delivered to the process mailbox -- causing EMQX to
handle sock_close event at 'disconnected' state.
This commit is contained in:
Zaiming (Stone) Shi 2023-11-19 22:08:42 +01:00
parent 034d4dcdcf
commit e73bf716ae
2 changed files with 8 additions and 7 deletions

View File

@ -1246,8 +1246,10 @@ handle_info(
{ok, Channel3} -> {ok, ?REPLY_EVENT(disconnected), Channel3};
Shutdown -> Shutdown
end;
handle_info({sock_closed, Reason}, Channel = #channel{conn_state = disconnected}) ->
?SLOG(error, #{msg => "unexpected_sock_close", reason => Reason}),
handle_info({sock_closed, _Reason}, Channel = #channel{conn_state = disconnected}) ->
%% This can happen as a race:
%% EMQX closes socket and marks 'disconnected' but 'tcp_closed' or 'ssl_closed'
%% is already in process mailbox
{ok, Channel};
handle_info(clean_authz_cache, Channel) ->
ok = emqx_authz_cache:empty_authz_cache(),

View File

@ -963,13 +963,12 @@ handle_info(
NChannel = ensure_disconnected(Reason, Channel),
shutdown(Reason, NChannel);
handle_info(
{sock_closed, Reason},
{sock_closed, _Reason},
Channel = #channel{conn_state = disconnected}
) ->
?SLOG(error, #{
msg => "unexpected_sock_closed",
reason => Reason
}),
%% This can happen as a race:
%% EMQX closes socket and marks 'disconnected' but 'tcp_closed' or 'ssl_closed'
%% is already in process mailbox
{ok, Channel};
handle_info(clean_authz_cache, Channel) ->
ok = emqx_authz_cache:empty_authz_cache(),