Merge pull request #9189 from lafirest/1003-add-a-sensitive-logger

fix(logger): add new macro `?LOG_SENSITIVE` and use it to replace some `?LOG`  for security reason

apps/emqx_bridge_mqtt/src/emqx_bridge_connect.erl

@@ -56,19 +56,7 @@ start(Module, Config) ->
         {ok, Conn} ->
             {ok, Conn};
         {error, Reason} ->
-            Config1 = obfuscate(Config),
+            ?LOG_SENSITIVE(error, "Failed to connect with module=~p\n"
-            ?LOG(error, "Failed to connect with module=~p\n"
+                           "config=~p\nreason:~p", [Module, Config, Reason]),
-                 "config=~p\nreason:~p", [Module, Config1, Reason]),
             {error, Reason}
     end.
-
-obfuscate(Map) ->
-    maps:fold(fun(K, V, Acc) ->
-                      case is_sensitive(K) of
-                          true -> [{K, '***'} | Acc];
-                          false -> [{K, V} | Acc]
-                      end
-              end, [], Map).
-
-is_sensitive(password) -> true;
-is_sensitive(_) -> false.

apps/emqx_bridge_mqtt/src/emqx_bridge_mqtt.app.src

@@ -1,6 +1,6 @@
 {application, emqx_bridge_mqtt,
  [{description, "EMQ X Bridge to MQTT Broker"},
-  {vsn, "4.3.6"}, % strict semver, bump manually!
+  {vsn, "4.3.7"}, % strict semver, bump manually!
   {modules, []},
   {registered, []},
   {applications, [kernel,stdlib,replayq,emqtt]},

apps/emqx_bridge_mqtt/src/emqx_bridge_mqtt.appup.src

@@ -1,29 +1,43 @@
 %% -*- mode: erlang -*-
 %% Unless you know what you are doing, DO NOT edit manually!!
 {VSN,
-  [{<<"4\\.3\\.[4-5]">>,
+  [{"4.3.6",
-    [{load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
+   {<<"4\\.3\\.[4-5]">>,
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
    {"4.3.3",
-    [{load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]}]},
    {<<"4\\.3\\.[1-2]">>,
-    [{load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
    {"4.3.0",
-    [{load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_worker,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
    {<<".*">>,[]}],
-  [{<<"4\\.3\\.[4-5]">>,
+  [{"4.3.6",
-    [{load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
+   {<<"4\\.3\\.[4-5]">>,
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
    {"4.3.3",
-    [{load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]}]},
    {<<"4\\.3\\.[1-2]">>,
-    [{load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
    {"4.3.0",
-    [{load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_bridge_connect,brutal_purge,soft_purge,[]},
+     {load_module,emqx_bridge_mqtt,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_worker,brutal_purge,soft_purge,[]},
      {load_module,emqx_bridge_mqtt_actions,brutal_purge,soft_purge,[]}]},
    {<<".*">>,[]}]}.

apps/emqx_bridge_mqtt/src/emqx_bridge_mqtt_actions.erl

@@ -421,7 +421,7 @@ start_resource(ResId, PoolName, Options) ->
             on_resource_destroy(ResId, #{<<"pool">> => PoolName}),
             start_resource(ResId, PoolName, Options);
         {error, Reason} ->
-            ?LOG(error, "Initiate Resource ~p failed, ResId: ~p, ~p", [?RESOURCE_TYPE_MQTT, ResId, Reason]),
+            ?LOG_SENSITIVE(error, "Initiate Resource ~p failed, ResId: ~p, ~p", [?RESOURCE_TYPE_MQTT, ResId, Reason]),
             on_resource_destroy(ResId, #{<<"pool">> => PoolName}),
             error({{?RESOURCE_TYPE_MQTT, ResId}, create_failed})
     end.

apps/emqx_rule_engine/src/emqx_rule_engine.erl

@@ -309,7 +309,7 @@ check_and_update_resource(Id, NewParams) ->
                 do_check_and_update_resource(#{id => Id, config => Conifg, type => Type,
                     description => Descr})
             catch Error:Reason:ST ->
-                ?LOG(error, "check_and_update_resource failed: ~0p", [{Error, Reason, ST}]),
+                ?LOG_SENSITIVE(error, "check_and_update_resource failed: ~0p", [{Error, Reason, ST}]),
                 {error, Reason}
             end;
         _Other ->
@@ -377,7 +377,7 @@ test_resource(#{type := Type} = Params) ->
                         {error, Reason}
                 end
             catch E:R:S ->
-                ?LOG(warning, "test resource failed, ~0p:~0p ~0p", [E, R, S]),
+                ?LOG_SENSITIVE(warning, "test resource failed, ~0p:~0p ~0p", [E, R, S]),
                 {error, R}
             after
                 _ = ?CLUSTER_CALL(ensure_resource_deleted, [ResId]),

apps/emqx_web_hook/src/emqx_web_hook.app.src

@@ -1,6 +1,6 @@
 {application, emqx_web_hook,
  [{description, "EMQ X WebHook Plugin"},
-  {vsn, "4.3.14"}, % strict semver, bump manually!
+  {vsn, "4.3.15"}, % strict semver, bump manually!
   {modules, []},
   {registered, [emqx_web_hook_sup]},
   {applications, [kernel,stdlib,ehttpc]},

apps/emqx_web_hook/src/emqx_web_hook.appup.src

@@ -1,7 +1,8 @@
 %% -*- mode: erlang -*-
 %% Unless you know what you are doing, DO NOT edit manually!!
 {VSN,
-  [{<<"4\\.3\\.[0-7]">>,
+  [{"4.3.14",[{load_module,emqx_web_hook_actions,brutal_purge,soft_purge,[]}]},
+   {<<"4\\.3\\.[0-7]">>,
     [{apply,{application,stop,[emqx_web_hook]}},
      {load_module,emqx_web_hook_app,brutal_purge,soft_purge,[]},
      {load_module,emqx_web_hook,brutal_purge,soft_purge,[]},
@@ -24,7 +25,8 @@
    {<<"4\\.3\\.1[2-3]">>,
     [{load_module,emqx_web_hook_actions,brutal_purge,soft_purge,[]}]},
    {<<".*">>,[]}],
-  [{<<"4\\.3\\.[0-7]">>,
+  [{"4.3.14",[{load_module,emqx_web_hook_actions,brutal_purge,soft_purge,[]}]},
+   {<<"4\\.3\\.[0-7]">>,
     [{apply,{application,stop,[emqx_web_hook]}},
      {load_module,emqx_web_hook_app,brutal_purge,soft_purge,[]},
      {load_module,emqx_web_hook,brutal_purge,soft_purge,[]},

apps/emqx_web_hook/src/emqx_web_hook_actions.erl

@@ -384,7 +384,7 @@ test_http_connect(Conf) ->
            false
     catch
         Err:Reason:ST ->
-           ?LOG(error, "check http_connectivity failed: ~p, ~0p", [Conf, {Err, Reason, ST}]),
+           ?LOG_SENSITIVE(error, "check http_connectivity failed: ~p, ~0p", [Conf, {Err, Reason, ST}]),
            false
     end.
 l2b(L) when is_list(L) -> iolist_to_binary(L);

changes/v4.3.22-en.md

@@ -10,6 +10,9 @@
 
 - JWT ACL claim supports `all` action to imply the rules applie to both `pub` and `sub` [#9044](https://github.com/emqx/emqx/pull/9044).
 
+- Added a log censor to avoid logging sensitive data [#9189](https://github.com/emqx/emqx/pull/9189).
+  If the data to be logged is a map or key-value list which contains sensitive key words such as `password`, the value is obfuscated as `******`.
+
 ## Bug fixes
 
 - Fix that after uploading a backup file with an UTF8 filename, HTTP API `GET /data/export` fails with status code 500 [#9224](https://github.com/emqx/emqx/pull/9224).

changes/v4.3.22-zh.md

@@ -10,6 +10,9 @@
 
 - 基于 JWT 的 ACL 支持 `all` 动作，指定同时适用于 `pub` 和 `sub` 两个动作的规则列表 [#9044](https://github.com/emqx/emqx/pull/9044)。
 
+- 增强包含敏感数据的日志的安全性 [#9189](https://github.com/emqx/emqx/pull/9189)。
+  如果日志中包含敏感关键词，例如 `password`，那么关联的数据回被模糊化处理，替换成 `******`。
+
 ## 修复
 
 - 修复若上传的备份文件名中包含 UTF8 字符，`GET /data/export` HTTP 接口返回 500 错误 [#9224](https://github.com/emqx/emqx/pull/9224)。

include/logger.hrl

@@ -48,3 +48,13 @@
                                   line => ?LINE}))
         end).
 
+%% Copy-paste to avoid changing the old macro which may cause beam md5 changes in a lot of modules
+%% i.e. hot-upgrade hell
+-define(LOG_SENSITIVE(Level, Format, Args),
+        begin
+          (logger:log(Level,#{},#{report_cb => fun(_) -> {'$logger_header'()++(Format), emqx_misc:redact(Args)} end,
+                                  mfa => {?MODULE, ?FUNCTION_NAME, ?FUNCTION_ARITY},
+                                  line => ?LINE,
+                                  is_sensitive => true
+                                 }))
+        end).

src/emqx.appup.src

@@ -2,7 +2,8 @@
 %% Unless you know what you are doing, DO NOT edit manually!!
 {VSN,
   [{"4.3.22",
-    [{load_module,emqx_cm,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_misc,brutal_purge,soft_purge,[]},
+     {load_module,emqx_cm,brutal_purge,soft_purge,[]},
      {load_module,emqx_ws_connection,brutal_purge,soft_purge,[]},
      {load_module,emqx_connection,brutal_purge,soft_purge,[]},
      {load_module,emqx_channel,brutal_purge,soft_purge,[]},
@@ -869,7 +870,8 @@
      {load_module,emqx_limiter,brutal_purge,soft_purge,[]}]},
    {<<".*">>,[]}],
   [{"4.3.22",
-    [{load_module,emqx_cm,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_misc,brutal_purge,soft_purge,[]},
+     {load_module,emqx_cm,brutal_purge,soft_purge,[]},
      {load_module,emqx_ws_connection,brutal_purge,soft_purge,[]},
      {load_module,emqx_connection,brutal_purge,soft_purge,[]},
      {load_module,emqx_channel,brutal_purge,soft_purge,[]},

src/emqx_logger_jsonfmt.erl

@@ -217,6 +217,7 @@ json_key(Term) ->
             throw({badkey, Term})
     end.
 
+
 -ifdef(TEST).
 -include_lib("proper/include/proper.hrl").
 -include_lib("eunit/include/eunit.hrl").

src/emqx_misc.erl

@@ -64,6 +64,8 @@
     nolink_apply/2
 ]).
 
+-export([redact/1]).
+
 -define(VALID_STR_RE, "^[A-Za-z0-9]+[A-Za-z0-9-_]*$").
 -define(DEFAULT_PMAP_TIMEOUT, 5000).
 
@@ -466,6 +468,67 @@ maybe_mute_rpc_log(Node) ->
             ok
     end.
 
+is_sensitive_key(token) -> true;
+is_sensitive_key("token") -> true;
+is_sensitive_key(<<"token">>) -> true;
+is_sensitive_key(password) -> true;
+is_sensitive_key("password") -> true;
+is_sensitive_key(<<"password">>) -> true;
+is_sensitive_key(secret) -> true;
+is_sensitive_key("secret") -> true;
+is_sensitive_key(<<"secret">>) -> true;
+is_sensitive_key(passcode) -> true;
+is_sensitive_key("passcode") -> true;
+is_sensitive_key(<<"passcode">>) -> true;
+is_sensitive_key(passphrase) -> true;
+is_sensitive_key("passphrase") -> true;
+is_sensitive_key(<<"passphrase">>) -> true;
+is_sensitive_key(key) -> true;
+is_sensitive_key("key") -> true;
+is_sensitive_key(<<"key">>) -> true;
+is_sensitive_key(aws_secret_access_key) -> true;
+is_sensitive_key("aws_secret_access_key") -> true;
+is_sensitive_key(<<"aws_secret_access_key">>) -> true;
+is_sensitive_key(secret_key) -> true;
+is_sensitive_key("secret_key") -> true;
+is_sensitive_key(<<"secret_key">>) -> true;
+is_sensitive_key(bind_password) -> true;
+is_sensitive_key("bind_password") -> true;
+is_sensitive_key(<<"bind_password">>) -> true;
+is_sensitive_key(_) -> false.
+
+redact(L) when is_list(L) ->
+    lists:map(fun redact/1, L);
+redact(M) when is_map(M) ->
+    maps:map(fun(K, V) ->
+                     redact(K, V)
+             end, M);
+redact({Key, Value}) ->
+    case is_sensitive_key(Key) of
+        true ->
+            {Key, redact_v(Value)};
+        false ->
+            {redact(Key), redact(Value)}
+    end;
+redact(T) when is_tuple(T) ->
+    Elements = erlang:tuple_to_list(T),
+    Redact = redact(Elements),
+    erlang:list_to_tuple(Redact);
+redact(Any) ->
+    Any.
+
+redact(K, V) ->
+    case is_sensitive_key(K) of
+        true ->
+            redact_v(V);
+        false ->
+            redact(V)
+    end.
+
+-define(REDACT_VAL, "******").
+redact_v(V) when is_binary(V) -> <<?REDACT_VAL>>;
+redact_v(_V) -> ?REDACT_VAL.
+
 -ifdef(TEST).
 -include_lib("eunit/include/eunit.hrl").
 
@@ -498,4 +561,53 @@ is_sane_id_test() ->
     ?assertMatch({error, _}, is_sane_id(list_to_binary(Bad))),
     ok.
 
+redact_test_() ->
+    Case = fun(Type, KeyT) ->
+        Key =
+            case Type of
+                atom -> KeyT;
+                string -> erlang:atom_to_list(KeyT);
+                binary -> erlang:atom_to_binary(KeyT)
+            end,
+
+        ?assert(is_sensitive_key(Key)),
+
+        %% direct
+        ?assertEqual({Key, ?REDACT_VAL}, redact({Key, foo})),
+        ?assertEqual(#{Key => ?REDACT_VAL}, redact(#{Key => foo})),
+        ?assertEqual({Key, Key, Key}, redact({Key, Key, Key})),
+        ?assertEqual({[{Key, ?REDACT_VAL}], bar}, redact({[{Key, foo}], bar})),
+
+        %% 1 level nested
+        ?assertEqual([{Key, ?REDACT_VAL}], redact([{Key, foo}])),
+        ?assertEqual([#{Key => ?REDACT_VAL}], redact([#{Key => foo}])),
+
+        %% 2 level nested
+        ?assertEqual(#{opts => [{Key, ?REDACT_VAL}]}, redact(#{opts => [{Key, foo}]})),
+        ?assertEqual(#{opts => #{Key => ?REDACT_VAL}}, redact(#{opts => #{Key => foo}})),
+        ?assertEqual({opts, [{Key, ?REDACT_VAL}]}, redact({opts, [{Key, foo}]})),
+
+        %% 3 level nested
+        ?assertEqual([#{opts => [{Key, ?REDACT_VAL}]}], redact([#{opts => [{Key, foo}]}])),
+        ?assertEqual([{opts, [{Key, ?REDACT_VAL}]}], redact([{opts, [{Key, foo}]}])),
+        ?assertEqual([{opts, [#{Key => ?REDACT_VAL}]}], redact([{opts, [#{Key => foo}]}]))
+    end,
+
+    Types = [atom, string, binary],
+    Keys = [
+        token,
+        password,
+        secret,
+        passcode,
+        passphrase,
+        key,
+        aws_secret_access_key,
+        secret_key,
+        bind_password
+    ],
+    [{case_name(Type, Key), fun() -> Case(Type, Key) end} || Key <- Keys, Type <- Types].
+
+case_name(Type, Key) ->
+    lists:concat([Type, "-", Key]).
+
 -endif.