chore: add debug logs when auth/acl ignored

This commit is contained in:
Shawn 2023-03-14 21:56:58 +08:00
parent 7baad16f23
commit a6cf261e66
23 changed files with 109 additions and 53 deletions

View File

@ -43,7 +43,9 @@ check_acl(ClientInfo, PubSub, Topic, _AclResult, #{acl := ACLParams = #{path :=
ClientInfo1 = ClientInfo#{access => access(PubSub), topic => Topic},
Username = maps:get(username, ClientInfo1, undefined),
case check_acl_request(ACLParams, ClientInfo1) of
{ok, 200, <<"ignore">>} -> ok;
{ok, 200, <<"ignore">>} ->
?LOG(debug, "ignored, ~s to topic ~ts, username: ~ts",
[PubSub, Topic, Username]);
{ok, 200, _Body} ->
?LOG(debug, "Allow ~s to topic ~ts, username: ~ts",
[PubSub, Topic, Username]),

View File

@ -1,7 +1,10 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.3.10",
[{"4.3.11",
[{load_module,emqx_auth_http,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_http,brutal_purge,soft_purge,[]}]},
{"4.3.10",
[{load_module,emqx_auth_http,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_http,brutal_purge,soft_purge,[]}]},
{"4.3.9",
@ -45,7 +48,10 @@
{load_module,emqx_auth_http_cli,brutal_purge,soft_purge,[]}]},
{<<"4.3.[0-1]">>,[{restart_application,emqx_auth_http}]},
{<<".*">>,[]}],
[{"4.3.10",
[{"4.3.11",
[{load_module,emqx_auth_http,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_http,brutal_purge,soft_purge,[]}]},
{"4.3.10",
[{load_module,emqx_auth_http,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_http,brutal_purge,soft_purge,[]}]},
{"4.3.9",

View File

@ -39,7 +39,7 @@ check(ClientInfo, AuthResult, #{auth := AuthParms = #{path := Path},
Username = maps:get(username, ClientInfo, undefined),
case authenticate(AuthParms, ClientInfo) of
{ok, 200, <<"ignore">>} ->
ok;
?LOG(debug, "Auth ignored, path: ~ts, username: ~ts", [Path, Username]);
{ok, 200, Body} ->
?LOG(debug, "Auth succeeded from path: ~ts, username: ~ts", [Path, Username]),
IsSuperuser = is_superuser(SuperParams, ClientInfo),

View File

@ -1,7 +1,8 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.4.8",
[{"4.4.9",[{load_module,emqx_auth_jwt,brutal_purge,soft_purge,[]}]},
{"4.4.8",
[{load_module,emqx_auth_jwt,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_jwt_svr,brutal_purge,soft_purge,[]}]},
{<<"4\\.4\\.[2-7]">>,
@ -9,7 +10,8 @@
{load_module,emqx_auth_jwt,brutal_purge,soft_purge,[]}]},
{<<"4\\.4\\.[0-1]">>,[{restart_application,emqx_auth_jwt}]},
{<<".*">>,[]}],
[{"4.4.8",
[{"4.4.9",[{load_module,emqx_auth_jwt,brutal_purge,soft_purge,[]}]},
{"4.4.8",
[{load_module,emqx_auth_jwt,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_jwt_svr,brutal_purge,soft_purge,[]}]},
{<<"4\\.4\\.[2-7]">>,

View File

@ -41,15 +41,15 @@ check(ClientInfo, AuthResult, State) ->
check_auth(ClientInfo, AuthResult, #{from := From, checklists := Checklists}) ->
case maps:find(From, ClientInfo) of
error ->
ok;
?LOG(debug, "Auth ignored, ~p not found in Client: ~p", [From, ClientInfo]);
{ok, undefined} ->
ok;
?LOG(debug, "Auth ignored, ~p undefined, Client: ~p", [From, ClientInfo]);
{ok, Token} ->
case emqx_auth_jwt_svr:verify(Token) of
{error, not_found} ->
ok;
?LOG_SENSITIVE(debug, "Auth ignored, ~p not_found, Client: ~p", [Token, ClientInfo]);
{error, not_token} ->
ok;
?LOG_SENSITIVE(debug, "Auth ignored, ~p not_token, Client: ~p", [Token, ClientInfo]);
{error, Reason} ->
?LOG_SENSITIVE(debug,
"Auth from JWT failed, Client: ~p, Reason: ~p",

View File

@ -28,7 +28,9 @@
check_acl(ClientInfo, PubSub, Topic, NoMatchAction, State) ->
case do_check_acl(ClientInfo, PubSub, Topic, NoMatchAction, State) of
ok -> ok;
ok -> ?LOG_SENSITIVE(debug,
"[LDAP] ACL ignored, Topic: ~p, Action: ~p for Client: ~p",
[Topic, PubSub, ClientInfo]);
{stop, allow} ->
?LOG_SENSITIVE(debug,
"[LDAP] Allow Topic: ~p, Action: ~p for Client: ~p",

View File

@ -1,7 +1,10 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.3.6",
[{"4.3.7",
[{load_module,emqx_auth_ldap,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_ldap,brutal_purge,soft_purge,[]}]},
{"4.3.6",
[{load_module,emqx_acl_ldap,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_ldap,brutal_purge,soft_purge,[]}]},
{"4.3.5",
@ -24,7 +27,10 @@
{load_module,emqx_acl_ldap,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_ldap_cli,brutal_purge,soft_purge,[]}]},
{<<".*">>,[]}],
[{"4.3.6",
[{"4.3.7",
[{load_module,emqx_auth_ldap,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_ldap,brutal_purge,soft_purge,[]}]},
{"4.3.6",
[{load_module,emqx_acl_ldap,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_ldap,brutal_purge,soft_purge,[]}]},
{"4.3.5",

View File

@ -59,13 +59,15 @@ check(ClientInfo = #{username := Username, password := Password}, AuthResult,
case CheckResult of
ok ->
?LOG_SENSITIVE(debug,
"[LDAP] Auth from ldap succeeded, Client: ~p",
"[LDAP] Auth succeeded, Client: ~p",
[ClientInfo]),
{stop, AuthResult#{auth_result => success, anonymous => false}};
{error, not_found} ->
ok;
?LOG_SENSITIVE(debug,
"[LDAP] Auth ignored, Client: ~p",
[ClientInfo]);
{error, ResultCode} ->
?LOG_SENSITIVE(error, "[LDAP] Auth from ldap failed: ~p", [ResultCode]),
?LOG_SENSITIVE(error, "[LDAP] Auth failed: ~p", [ResultCode]),
{stop, AuthResult#{auth_result => ResultCode, anonymous => false}}
end.

View File

@ -54,7 +54,9 @@ check_acl(ClientInfo = #{ clientid := Clientid }, PubSub, Topic, _NoMatchAction,
[Topic, PubSub, ClientInfo]),
{stop, deny};
_ ->
ok
?LOG_SENSITIVE(debug,
"[Mnesia] ACL ignored, Topic: ~p, Action: ~p for Client: ~p",
[Topic, PubSub, ClientInfo])
end.
description() -> "Acl with Mnesia".

View File

@ -1,7 +1,10 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.3.10",
[{"4.3.11",
[{load_module,emqx_auth_mnesia,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mnesia,brutal_purge,soft_purge,[]}]},
{"4.3.10",
[{load_module,emqx_auth_mnesia,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mnesia,brutal_purge,soft_purge,[]}]},
{"4.3.9",
@ -47,7 +50,10 @@
{load_module,emqx_acl_mnesia_cli,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_mnesia_app,brutal_purge,soft_purge,[]}]},
{<<".*">>,[]}],
[{"4.3.10",
[{"4.3.11",
[{load_module,emqx_auth_mnesia,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mnesia,brutal_purge,soft_purge,[]}]},
{"4.3.10",
[{load_module,emqx_auth_mnesia,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mnesia,brutal_purge,soft_purge,[]}]},
{"4.3.9",

View File

@ -60,19 +60,17 @@ check(ClientInfo = #{ clientid := Clientid
MatchSpec = ets:fun2ms(fun({?TABLE, {clientid, X}, Password, InterTime}) when X =:= Clientid-> Password;
({?TABLE, {username, X}, Password, InterTime}) when X =:= Username andalso X =/= undefined -> Password
end),
Info = maps:without([password], ClientInfo),
case ets:select(?TABLE, MatchSpec) of
[] ->
ok;
?LOG(debug, "[Mnesia] Auth ignored, Client: ~p", [Info]);
List ->
case match_password(NPassword, HashType, List) of
false ->
Info = maps:without([password], ClientInfo),
?LOG(info, "[Mnesia] Auth from mnesia failed: ~p", [Info]),
{stop, AuthResult#{anonymous => false, auth_result => password_error}};
_ ->
?LOG_SENSITIVE(debug,
"[Mnesia] Auth from mnesia succeeded, Client: ~p",
[ClientInfo]),
?LOG(debug,"[Mnesia] Auth from mnesia succeeded, Client: ~p", [Info]),
{stop, AuthResult#{anonymous => false, auth_result => success}}
end
end.

View File

@ -35,7 +35,9 @@ check_acl(ClientInfo, PubSub, Topic, _AclResult, Env = #{aclquery := AclQuery})
maps:from_list(emqx_auth_mongo:replvars(Selector, ClientInfo))
end, SelectorList),
case emqx_auth_mongo:query_multi(Pool, Coll, SelectorMapList) of
[] -> ok;
[] -> ?LOG_SENSITIVE(debug,
"[MongoDB] ACL ignored, Topic: ~p, Action: ~p for Client: ~p",
[Topic, PubSub, ClientInfo]);
Rows ->
try match(ClientInfo, Topic, topics(PubSub, Rows)) of
matched ->
@ -50,7 +52,7 @@ check_acl(ClientInfo, PubSub, Topic, _AclResult, Env = #{aclquery := AclQuery})
{stop, deny}
catch
_Err:Reason->
?LOG(error, "[MongoDB] Check mongo ~p ACL failed, got ACL config: ~p, error: :~p",
?LOG(error, "[MongoDB] ACL ignored, check mongo ~p ACL failed, got ACL config: ~p, error: ~p",
[PubSub, Rows, Reason]),
ignore
end

View File

@ -1,7 +1,10 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.4.5",
[{"4.4.6",
[{load_module,emqx_auth_mongo,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mongo,brutal_purge,soft_purge,[]}]},
{"4.4.5",
[{load_module,emqx_acl_mongo,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_mongo,brutal_purge,soft_purge,[]}]},
{"4.4.4",
@ -22,7 +25,10 @@
{load_module,emqx_auth_mongo,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mongo,brutal_purge,soft_purge,[]}]},
{<<".*">>,[]}],
[{"4.4.5",
[{"4.4.6",
[{load_module,emqx_auth_mongo,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mongo,brutal_purge,soft_purge,[]}]},
{"4.4.5",
[{load_module,emqx_acl_mongo,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_mongo,brutal_purge,soft_purge,[]}]},
{"4.4.4",

View File

@ -52,10 +52,11 @@ check(ClientInfo = #{password := Password}, AuthResult,
hash = HashType, selector = Selector} = AuthQuery,
Pool = maps:get(pool, Env, ?APP),
case query(Pool, Collection, maps:from_list(replvars(Selector, ClientInfo))) of
undefined -> ok;
undefined ->
?LOG_SENSITIVE(debug, "[MongoDB] Auth ignored, Client: ~p", [ClientInfo]);
{error, Reason} ->
?tp(emqx_auth_mongo_check_authn_error, #{error => Reason}),
?LOG_SENSITIVE(error, "[MongoDB] Can't connect to MongoDB server: ~0p", [Reason]),
?LOG_SENSITIVE(error, "[MongoDB] Auth failed, Can't connect to MongoDB server: ~0p", [Reason]),
{stop, AuthResult#{auth_result => not_authorized, anonymous => false}};
UserMap ->
Result = case [maps:get(Field, UserMap, undefined) || Field <- Fields] of
@ -69,7 +70,7 @@ check(ClientInfo = #{password := Password}, AuthResult,
ok ->
?tp(emqx_auth_mongo_superuser_check_authn_ok, #{}),
?LOG_SENSITIVE(debug,
"[MongoDB] Auth from mongo succeeded, Client: ~p",
"[MongoDB] Auth succeeded, Client: ~p",
[ClientInfo]),
{stop, AuthResult#{is_superuser => is_superuser(Pool, SuperQuery, ClientInfo),
anonymous => false,

View File

@ -28,7 +28,10 @@
check_acl(ClientInfo, PubSub, Topic, NoMatchAction, #{pool := Pool} = State) ->
case do_check_acl(Pool, ClientInfo, PubSub, Topic, NoMatchAction, State) of
ok -> ok;
ok ->
?LOG_SENSITIVE(debug,
"[MySQL] ACL ignored, Topic: ~p, Action: ~p for Client: ~p",
[Topic, PubSub, ClientInfo]);
{stop, allow} ->
?LOG_SENSITIVE(debug,
"[MySQL] Allow Topic: ~p, Action: ~p for Client: ~p",

View File

@ -1,7 +1,10 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.3.4",
[{"4.3.5",
[{load_module,emqx_auth_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mysql,brutal_purge,soft_purge,[]}]},
{"4.3.4",
[{load_module,emqx_auth_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_mysql_cli,brutal_purge,soft_purge,[]}]},
@ -20,7 +23,10 @@
{load_module,emqx_auth_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mysql,brutal_purge,soft_purge,[]}]},
{<<".*">>,[]}],
[{"4.3.4",
[{"4.3.5",
[{load_module,emqx_auth_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mysql,brutal_purge,soft_purge,[]}]},
{"4.3.4",
[{load_module,emqx_auth_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_mysql,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_mysql_cli,brutal_purge,soft_purge,[]}]},

View File

@ -46,16 +46,14 @@ check(ClientInfo = #{password := Password}, AuthResult,
end,
case CheckPass of
ok ->
?LOG_SENSITIVE(debug,
"[MySQL] Auth from mysql succeeded, Client: ~p",
[ClientInfo]),
?LOG_SENSITIVE(debug, "[MySQL] Auth succeeded, Client: ~p", [ClientInfo]),
{stop, AuthResult#{is_superuser => is_superuser(Pool, SuperQuery, ClientInfo),
anonymous => false,
auth_result => success}};
{error, not_found} ->
ok;
?LOG_SENSITIVE(debug, "[MySQL] Auth ignored, Client: ~p", [ClientInfo]);
{error, ResultCode} ->
?LOG_SENSITIVE(error, "[MySQL] Auth from mysql failed: ~p", [ResultCode]),
?LOG_SENSITIVE(error, "[MySQL] Auth failed: ~p", [ResultCode]),
{stop, AuthResult#{auth_result => ResultCode, anonymous => false}}
end.

View File

@ -32,7 +32,10 @@ do_check_acl(_Pool, #{username := <<$$, _/binary>>}, _PubSub, _Topic, _NoMatchAc
ok;
do_check_acl(Pool, ClientInfo, PubSub, Topic, _NoMatchAction, #{acl_query := {AclSql, AclParams}}) ->
case emqx_auth_pgsql_cli:equery(Pool, AclSql, AclParams, ClientInfo) of
{ok, _, []} -> ok;
{ok, _, []} ->
?LOG_SENSITIVE(debug,
"[Postgres] ACL ignored, Topic: ~p, Action: ~p for Client: ~p",
[Topic, PubSub, ClientInfo]);
{ok, _, Rows} ->
Rules = filter(PubSub, compile(Rows)),
case match(ClientInfo, Topic, Rules) of

View File

@ -1,7 +1,10 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.4.4",
[{"4.4.5",
[{load_module,emqx_auth_pgsql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_pgsql,brutal_purge,soft_purge,[]}]},
{"4.4.4",
[{load_module,emqx_acl_pgsql,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_pgsql,brutal_purge,soft_purge,[]}]},
{"4.4.3",
@ -14,7 +17,10 @@
{load_module,emqx_auth_pgsql,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_pgsql_app,brutal_purge,soft_purge,[]}]},
{<<".*">>,[]}],
[{"4.4.4",
[{"4.4.5",
[{load_module,emqx_auth_pgsql,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_pgsql,brutal_purge,soft_purge,[]}]},
{"4.4.4",
[{load_module,emqx_acl_pgsql,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_pgsql,brutal_purge,soft_purge,[]}]},
{"4.4.3",

View File

@ -45,16 +45,14 @@ check(ClientInfo = #{password := Password}, AuthResult,
end,
case CheckPass of
ok ->
?LOG_SENSITIVE(debug,
"[Postgres] Auth from pgsql succeeded, Client: ~p",
[ClientInfo]),
?LOG_SENSITIVE(debug, "[Postgres] Auth succeeded, Client: ~p", [ClientInfo]),
{stop, AuthResult#{is_superuser => is_superuser(Pool, SuperQuery, ClientInfo),
anonymous => false,
auth_result => success}};
{error, not_found} ->
ok;
?LOG_SENSITIVE(debug, "[Postgres] Auth ignored, Client: ~p", [ClientInfo]);
{error, ResultCode} ->
?LOG_SENSITIVE(error, "[Postgres] Auth from pgsql failed: ~p", [ResultCode]),
?LOG_SENSITIVE(error, "[Postgres] Auth failed: ~p", [ResultCode]),
{stop, AuthResult#{auth_result => ResultCode, anonymous => false}}
end.

View File

@ -30,7 +30,10 @@ check_acl(#{username := <<$$, _/binary>>}, _PubSub, _Topic, _AclResult, _Config)
check_acl(ClientInfo, PubSub, Topic, _AclResult,
#{acl_cmd := AclCmd, timeout := Timeout, type := Type, pool := Pool}) ->
case emqx_auth_redis_cli:q(Pool, Type, AclCmd, ClientInfo, Timeout) of
{ok, []} -> ok;
{ok, []} ->
?LOG_SENSITIVE(debug,
"[Redis] ACL ignored, Topic: ~p, Action: ~p for Client: ~p",
[Topic, PubSub, ClientInfo]);
{ok, Rules} ->
case match(ClientInfo, PubSub, Topic, Rules) of
allow ->

View File

@ -1,7 +1,9 @@
%% -*- mode: erlang -*-
%% Unless you know what you are doing, DO NOT edit manually!!
{VSN,
[{"4.3.5",[{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]}]},
[{"4.3.5",
[{load_module,emqx_acl_redis,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]}]},
{"4.3.4",
[{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_redis,brutal_purge,soft_purge,[]}]},
@ -20,7 +22,9 @@
{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_redis,brutal_purge,soft_purge,[]}]},
{<<".*">>,[]}],
[{"4.3.5",[{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]}]},
[{"4.3.5",
[{load_module,emqx_acl_redis,brutal_purge,soft_purge,[]},
{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]}]},
{"4.3.4",
[{load_module,emqx_auth_redis,brutal_purge,soft_purge,[]},
{load_module,emqx_acl_redis,brutal_purge,soft_purge,[]}]},

View File

@ -47,15 +47,15 @@ check(ClientInfo = #{password := Password}, AuthResult,
end,
case CheckPass of
ok ->
?LOG_SENSITIVE(debug, "[Redis] Auth from redis succeeded, Client: ~p", [ClientInfo]),
?LOG_SENSITIVE(debug, "[Redis] Auth succeeded, Client: ~p", [ClientInfo]),
IsSuperuser = is_superuser(Pool, Type, SuperCmd, ClientInfo, Timeout),
{stop, AuthResult#{is_superuser => IsSuperuser,
anonymous => false,
auth_result => success}};
{error, not_found} ->
ok;
?LOG_SENSITIVE(debug, "[Redis] Auth ignored, Client: ~p", [ClientInfo]);
{error, ResultCode} ->
?LOG_SENSITIVE(error, "[Redis] Auth from redis failed: ~p", [ResultCode]),
?LOG_SENSITIVE(error, "[Redis] Auth failed: ~p", [ResultCode]),
{stop, AuthResult#{auth_result => ResultCode, anonymous => false}}
end.