fix: rule engine date format fun & date to timestamp

apps/emqx_rule_engine/src/emqx_rule_funcs.erl

@@ -201,6 +201,8 @@
         , unix_ts_to_rfc3339/2
         , format_date/3
         , format_date/4
+        , timezone_to_second/1
+        , date_to_unix_ts/3
         , date_to_unix_ts/4
         , rfc3339_to_unix_ts/1
         , rfc3339_to_unix_ts/2
@@ -923,26 +925,37 @@ now_timestamp(Unit) ->
 time_unit(<<"second">>) -> second;
 time_unit(<<"millisecond">>) -> millisecond;
 time_unit(<<"microsecond">>) -> microsecond;
-time_unit(<<"nanosecond">>) -> nanosecond.
+time_unit(<<"nanosecond">>) -> nanosecond;
+time_unit(second) -> second;
+time_unit(millisecond) -> millisecond;
+time_unit(microsecond) -> microsecond;
+time_unit(nanosecond) -> nanosecond.
 
 format_date(TimeUnit, Offset, FormatString) ->
-    emqx_rule_utils:bin(
+    Unit = time_unit(TimeUnit),
-      emqx_rule_date:date(time_unit(TimeUnit),
+    TimeEpoch = erlang:system_time(Unit),
-                          emqx_rule_utils:str(Offset),
+    format_date(Unit, Offset, FormatString, TimeEpoch).
-                          emqx_rule_utils:str(FormatString))).
+
+timezone_to_second(TimeZone) ->
+    emqx_calendar:offset_second(TimeZone).
 
 format_date(TimeUnit, Offset, FormatString, TimeEpoch) ->
+    Unit = time_unit(TimeUnit),
     emqx_rule_utils:bin(
-      emqx_rule_date:date(time_unit(TimeUnit),
+        lists:concat(
-                          emqx_rule_utils:str(Offset),
+            emqx_calendar:format(TimeEpoch, Unit, Offset, FormatString))).
-                          emqx_rule_utils:str(FormatString),
-                          TimeEpoch)).
 
+%% date string has timezone information, calculate the offset.
+date_to_unix_ts(TimeUnit, FormatString, InputString) ->
+    Unit = time_unit(TimeUnit),
+    emqx_calendar:parse(InputString, Unit, FormatString).
+
+%% date string has no timezone information, force add the offset.
 date_to_unix_ts(TimeUnit, Offset, FormatString, InputString) ->
-    emqx_rule_date:parse_date(time_unit(TimeUnit),
+    Unit = time_unit(TimeUnit),
-                              emqx_rule_utils:str(Offset),
+    OffsetSecond = emqx_calendar:offset_second(Offset),
-                              emqx_rule_utils:str(FormatString),
+    OffsetDelta = erlang:convert_time_unit(OffsetSecond, second, Unit),
-                              emqx_rule_utils:str(InputString)).
+    OffsetDelta + date_to_unix_ts(Unit, FormatString, InputString).
 
 mongo_date() ->
     erlang:timestamp().

apps/emqx_rule_engine/test/emqx_rule_funcs_SUITE.erl

@@ -713,24 +713,32 @@ t_format_date_funcs(_) ->
     ?PROPTEST(prop_format_date_fun).
 
 prop_format_date_fun() ->
-    Args1 = [<<"second">>, <<"+07:00">>, <<"%m--%d--%y---%H:%M:%S%Z">>],
+    Args1 = [<<"second">>, <<"+07:00">>, <<"%m--%d--%Y---%H:%M:%S%z">>],
+    Args1DTUS = [<<"second">>, 0, <<"%m--%d--%Y---%H:%M:%S%z">>],
     ?FORALL(S, erlang:system_time(second),
             S == apply_func(date_to_unix_ts,
-                            Args1 ++ [apply_func(format_date,
+                            Args1DTUS ++ [apply_func(format_date,
                                                  Args1 ++ [S])])),
-    Args2 = [<<"millisecond">>, <<"+04:00">>, <<"--%m--%d--%y---%H:%M:%S%Z">>],
+    Args2 = [<<"millisecond">>, <<"+04:00">>, <<"--%m--%d--%Y---%H:%M:%S:%3N%z">>],
+    Args2DTUS = [<<"millisecond">>, <<"--%m--%d--%Y---%H:%M:%S:%3N%z">>],
     ?FORALL(S, erlang:system_time(millisecond),
             S == apply_func(date_to_unix_ts,
-                            Args2 ++ [apply_func(format_date,
+                            Args2DTUS ++ [apply_func(format_date,
                                                  Args2 ++ [S])])),
-    Args = [<<"second">>, <<"+08:00">>, <<"%y-%m-%d-%H:%M:%S%Z">>],
+    Args = [<<"second">>, <<"+08:00">>, <<"%Y-%m-%d-%H:%M:%S%z">>],
+    ArgsDTUS = [<<"second">>, <<"%Y-%m-%d-%H:%M:%S%z">>],
     ?FORALL(S, erlang:system_time(second),
             S == apply_func(date_to_unix_ts,
-                            Args ++ [apply_func(format_date,
+                            ArgsDTUS ++ [apply_func(format_date,
-                                                Args ++ [S])])).
+                                                Args ++ [S])])),
-%%------------------------------------------------------------------------------
+    % no offset in format string. force add offset
-%% Utility functions
+    Second = erlang:system_time(second),
-%%------------------------------------------------------------------------------
+    Args3 = [<<"second">>, <<"+04:00">>, <<"--%m--%d--%Y---%H:%M:%S">>, Second],
+    Formatters3 = apply_func(format_date, Args3),
+    % -04:00 remove offset
+    OffsetSeconds = emqx_rule_funcs:timezone_to_second(<<"-04:00">>),
+    Args3DTUS = [<<"second">>, OffsetSeconds, <<"--%m--%d--%Y---%H:%M:%S">>, Formatters3],
+    Second == apply_func(date_to_unix_ts, Args3DTUS).
 
 apply_func(Name, Args) when is_atom(Name) ->
     erlang:apply(emqx_rule_funcs, Name, Args);
@@ -880,9 +888,9 @@ message() ->
 %% CT functions
 %%------------------------------------------------------------------------------
 
-all() ->
+all() -> [t_format_date_funcs].
-    IsTestCase = fun("t_" ++ _) -> true; (_) -> false end,
+    % IsTestCase = fun("t_" ++ _) -> true; (_) -> false end,
-    [F || {F, _A} <- module_info(exports), IsTestCase(atom_to_list(F))].
+    % [F || {F, _A} <- module_info(exports), IsTestCase(atom_to_list(F))].
 
 suite() ->
     [{ct_hooks, [cth_surefire]}, {timetrap, {seconds, 30}}].

etc/emqx.conf

@@ -427,7 +427,7 @@ log.to = file
 ##       this level will be logged.
 ##
 ## Default: warning
-log.level = debug
+log.level = warning
 
 ## The dir for log files.
 ##
@@ -472,9 +472,11 @@ log.formatter = text
 ##     %S: second
 ##     %6N: microseconds
 ##     %3N: milliseconds
-##     %z: timezone, [+|-]HH:MM or [+|-]HH:MM:SS. Depends on `log.formatter.text.date.timezone`
+##     %z: timezone, [+-]HHMM
+##     %:z: timezone, [+-]HH:MM
+##     %::z: timezone, [+-]HH:MM:SS
 ## For example:
-## log.formatter.text.date.format = emqx-server-date: %Y-%m-%dT%H:%M:%S.%6N %z
+## emqx-server-date: %Y-%m-%dT%H:%M:%S.%6N %:z
 ## Default: rfc3339
 # log.formatter.text.date.format = rfc3339
 
@@ -482,9 +484,10 @@ log.formatter = text
 ## Only takes effect when log.formatter.text.date.format not rfc3339.
 ##
 ## Value: local | z | UTC TimeOffset
-## TimeOffset: [+|-]HH:MM or [+|-]HH:MM:SS, for example: +08:00.
+## TimeOffset: [+-]HHMM or [+|-]HH:MM or [+|-]HH:MM:SS, for example: +08:00.
 ## local is the system local time timezone.
 ## z: UTC zulu timezone.
+## Z: UTC zulu timezone. Same as z.
 ## Default: local
 # log.formatter.text.date.timezone = local
 

priv/emqx.schema

@@ -659,6 +659,8 @@ end}.
                       DST(<<"%3N", Tail/binary>>, Formatter) -> DST(Tail, [millisecond | Formatter]);
                       DST(<<"%6N", Tail/binary>>, Formatter) -> DST(Tail, [microsecond | Formatter]);
                       DST(<<"%z", Tail/binary>>, Formatter) -> DST(Tail, [timezone | Formatter]);
+                      DST(<<"%:z", Tail/binary>>, Formatter) -> DST(Tail, [timezone1 | Formatter]);
+                      DST(<<"%::z", Tail/binary>>, Formatter) -> DST(Tail, [timezone2 | Formatter]);
                       DST(<<Char:8, Tail/binary>>, [Str | Formatter]) when is_list(Str) ->
                           DST(Tail, [lists:append(Str, [Char]) | Formatter]);
                       DST(<<Char:8, Tail/binary>>, Formatter) ->
@@ -669,9 +671,9 @@ end}.
             {DateOffsetStr, DateOffset} =
               case cuttlefish:conf_get("log.formatter.text.date.timezone", Conf, "local") of
                 "z" ->
-                  {"z", 0};
+                  {"z", "z"};
                 "Z" ->
-                  {"Z", 0};
+                  {"Z", "Z"};
                 "local" ->
                     UniversalTime =
                       calendar:system_time_to_universal_time(
@@ -709,7 +711,9 @@ end}.
                               [H, M] ->
                                 {H, M, "0"};
                               [H, M, S] ->
-                                {H, M, S}
+                                {H, M, S};
+                              [HHMM] when erlang:length(HHMM) == 4 ->
+                                {string:sub_string(HHMM, 1,2), string:sub_string(HHMM, 3,4), "0"}
                             end,
                           Hour = erlang:list_to_integer(HourStr),
                           Minute = erlang:list_to_integer(MinuteStr),

src/emqx_calendar.erl

@@ -27,14 +27,10 @@
 -export([ formatter/1
         , format/3
         , format/4
-        , format/5
         , parse/3
-        , parse/4
         , offset_second/1
         ]).
 
--export([test/0]).
-
 -define(DATE_PART,
     [ year
     , month
@@ -69,174 +65,10 @@ format(Time, Unit, Offset, FormatterBin) when is_binary(FormatterBin) ->
 format(Time, Unit, Offset, Formatter) ->
     do_format(Time, time_unit(Unit), offset_second(Offset), Formatter).
 
-%% for logger format
+parse(DateStr, Unit, FormatterBin) when is_binary(FormatterBin) ->
-format(Time, Unit, Offset, Zones, Formatter) ->
+    parse(DateStr, Unit, formatter(FormatterBin));
-    do_format(Time, time_unit(Unit), offset_second(Offset), Zones, Formatter).
+parse(DateStr, Unit, Formatter) ->
-
+    do_parse(DateStr, Unit, Formatter).
-test() ->
-    Units = [second, millisecond, microsecond, nanosecond],
-    Formatters = [
-        <<"%Y-%m-%d %H:%M:%S:%N%z">>,
-        <<"%Y-%m-%d %H:%M:%S:%N%:z">>,
-        <<"%Y-%m-%d %H:%M:%S:%N%::z">>,
-        <<"%Y-%m-%d %H:%M:%S:%N">>,
-        <<"%Y-%m-%d %H:%M:%S:%3N">>,
-        <<"%Y-%m-%d %H:%M:%S:%6N">>
-    ],
-    Offsets = [
-        0,
-        8 * 3600,
-        -8 * 3600,
-        <<"+08:00">>,
-        <<"+08:00:01">>,
-        <<"+0802">>,
-        <<"-08:00">>,
-        <<"local">>
-    ],
-    [
-        [
-            [begin
-                Time = erlang:system_time(U),
-                FormatDate = erlang:list_to_binary(format(Time, U, O, F)),
-                PTime = emqx_calendar:parse(FormatDate, U, O, F),
-                io:format("~p ~p ~p ~p ~n~p~n~p~n", [U, O, F, FormatDate, Time, PTime]),
-                % Equal = (PTime == Time),
-                % F2 =
-                %     fun() ->
-                %         Delta = Time - PTime,
-                %         DeltaFmt = erlang:list_to_binary(format(Delta, U, 0, <<"%Y-%m-%d %H:%M:%S:%N">>)),
-                %         io:format("delta ~p~n ~p~n-----~n", [Delta, DeltaFmt])
-                %     end,
-                % Equal orelse F2()
-                ok
-            end||O <- Offsets]
-        || F <-Formatters]
-    || U <-Units],
-    ok.
-
-parse(DateStr, Unit, FormatterBin) ->
-    parse(DateStr, Unit, 0, FormatterBin).
-
-parse(DateStr, Unit, Offset, FormatterBin) when is_binary(FormatterBin) ->
-    parse(DateStr, Unit, Offset, formatter(FormatterBin));
-parse(DateStr, Unit, Offset, Formatter) ->
-    do_parse(DateStr, Unit, offset_second(Offset), Formatter).
-
-do_parse(DateStr, Unit, Offset, Formatter) ->
-    DateInfo = do_parse_date_str(DateStr, Formatter, #{}),
-    {Precise, PrecisionUnit} = precise(DateInfo),
-    Counter =
-        fun
-            (year, V, Res) ->
-                Res + dy(V) * ?SECONDS_PER_DAY * Precise - (?SECONDS_FROM_0_TO_1970 * Precise);
-            (month, V, Res) ->
-                Res + nano_sm(V);
-            (day, V, Res) ->
-                Res + (V * ?SECONDS_PER_DAY * Precise);
-            (hour, V, Res) ->
-                Res + (V * ?SECONDS_PER_HOUR * Precise);
-            (minute, V, Res) ->
-                Res + (V * ?SECONDS_PER_MINUTE * Precise);
-            (second, V, Res) ->
-                Res + V * Precise;
-            (millisecond, V, Res) ->
-                case PrecisionUnit of
-                    millisecond ->
-                        Res + V;
-                    microsecond ->
-                        Res + (V * 1000);
-                    nanosecond ->
-                        Res + (V * 1000000)
-                end;
-            (microsecond, V, Res) ->
-                case PrecisionUnit of
-                    microsecond ->
-                        Res + V;
-                    nanosecond ->
-                        Res + (V * 1000)
-                end;
-            (nanosecond, V, Res) ->
-                Res + V;
-            (parsed_offset, V, Res) ->
-                Res - V
-        end,
-    Counter1 =
-        fun(K,V,R) ->
-            Res = Counter(K,V,R),
-            % io:format("K, V, R = ~p, ~p, ~p, Res = ~p~n", [K, V, R, Res - R]),
-            Res
-        end,
-    Count0 = maps:fold(Counter1, 0, DateInfo) - (?SECONDS_PER_DAY * Precise),
-    Count =
-        case maps:is_key(parsed_offset, DateInfo) of
-            true ->
-                Count0;
-            false ->
-                (Offset * Precise) + Count0
-        end,
-    erlang:convert_time_unit(Count, PrecisionUnit, Unit).
-
-precise(#{nanosecond := _}) -> {1000_000_000, nanosecond};
-precise(#{microsecond := _}) -> {1000_000, microsecond};
-precise(#{millisecond := _}) -> {1000, millisecond};
-precise(#{second := _}) -> {1, second};
-precise(_) -> {1, second}.
-
-do_parse_date_str(<<>>, _, Result) -> Result;
-do_parse_date_str(_, [], Result) -> Result;
-do_parse_date_str(Date, [Key | Formatter], Result) ->
-    Size = date_size(Key),
-    <<DatePart:Size/binary-unit:8, Tail/binary>> = Date,
-    case lists:member(Key, ?DATE_PART) of
-        true ->
-            do_parse_date_str(Tail, Formatter, Result#{Key => erlang:binary_to_integer(DatePart)});
-        false ->
-            case lists:member(Key, ?DATE_ZONE_NAME) of
-                true ->
-                    io:format("DatePart -------------- ~p ~p~n", [DatePart, offset_second(DatePart)]),
-                    do_parse_date_str(Tail, Formatter, Result#{parsed_offset => offset_second(DatePart)});
-                false ->
-                    do_parse_date_str(Tail, Formatter, Result)
-            end
-    end.
-
-date_size(Str) when is_list(Str) -> erlang:length(Str);
-date_size(DateName) ->
-    Map = #{
-        year   => 4,
-        month  => 2,
-        day    => 2,
-        hour   => 2,
-        minute => 2,
-        second => 2,
-        millisecond => 3,
-        microsecond => 6,
-        nanosecond => 9,
-        timezone => 5,
-        timezone1 => 6,
-        timezone2 => 9
-    },
-    maps:get(DateName, Map).
-
-nano_sm(Month) -> dm(Month) * ?SECONDS_PER_DAY * 1000_000.
-
-dm(Month) ->
-    MonthDays = #{
-        1  => 0,
-        2  => 31,
-        3  => 59,
-        4  => 90,
-        5  => 120,
-        6  => 151,
-        7  => 181,
-        8  => 212,
-        9  => 243,
-        10 => 273,
-        11 => 304,
-        12 => 334
-    },
-    maps:get(Month, MonthDays).
-
 %% -------------------------------------------------------------------------------------------------
 %% internal
 %% emqx_calendar:format(erlang:system_time(second), <<"second">>, <<"+8:00">> ,<<"%Y-%m-%d-%H:%M:%S%Z">>).
@@ -315,10 +147,6 @@ do_offset_second(Offset) when is_list(Offset) ->
     PosNeg * (Hour * 3600 + Minute * 60 + Second).
 
 do_format(Time, Unit, Offset, Formatter) ->
-    Timezones = formatter_timezones(Offset, Formatter, #{}),
-    do_format(Time, Unit, Offset, Timezones, Formatter).
-
-do_format(Time, Unit, Offset, Timezones, Formatter) ->
     Adjustment = erlang:convert_time_unit(Offset, second, Unit),
     AdjustedTime = Time + Adjustment,
     Factor = factor(Unit),
@@ -336,6 +164,7 @@ do_format(Time, Unit, Offset, Timezones, Formatter) ->
         microsecond => trans_x_second(Unit, microsecond, Time),
         nanosecond => trans_x_second(Unit, nanosecond, Time)
     },
+    Timezones = formatter_timezones(Offset, Formatter, #{}),
     DateWithZone = maps:merge(Date, Timezones),
     [maps:get(Key, DateWithZone, Key) || Key <- Formatter].
 
@@ -493,12 +322,12 @@ do_trans_x_second(second, second, Time) -> Time div 60;
 do_trans_x_second(second, _, _Time) -> 0;
 
 do_trans_x_second(millisecond, millisecond, Time) -> Time rem 1000;
-do_trans_x_second(millisecond, microsecond, _Time) -> 0;
+do_trans_x_second(millisecond, microsecond, Time) -> (Time rem 1000) * 1000;
-do_trans_x_second(millisecond, nanosecond, _Time) -> 0;
+do_trans_x_second(millisecond, nanosecond, Time) -> (Time rem 1000) * 1000_000;
 
 do_trans_x_second(microsecond, millisecond, Time) -> Time div 1000 rem 1000;
 do_trans_x_second(microsecond, microsecond, Time) -> Time rem 1000000;
-do_trans_x_second(microsecond, nanosecond, _Time) -> 0;
+do_trans_x_second(microsecond, nanosecond, Time) -> (Time rem 1000000) * 1000;
 
 do_trans_x_second(nanosecond, millisecond, Time) -> Time div 1000000 rem 1000;
 do_trans_x_second(nanosecond, microsecond, Time) -> Time div 1000 rem 1000000;
@@ -510,3 +339,106 @@ padding(Data, Len) when Len > 0 andalso erlang:length(Data) < Len ->
     [$0 | padding(Data, Len - 1)];
 padding(Data, _Len) ->
     Data.
+
+%% -------------------------------------------------------------------------------------------------
+%% internal
+%% parse part
+
+do_parse(DateStr, Unit, Formatter) ->
+    DateInfo = do_parse_date_str(DateStr, Formatter, #{}),
+    {Precise, PrecisionUnit} = precise(DateInfo),
+    Counter =
+        fun
+            (year, V, Res) ->
+                Res + dy(V) * ?SECONDS_PER_DAY * Precise - (?SECONDS_FROM_0_TO_1970 * Precise);
+            (month, V, Res) ->
+                Res + dm(V) * ?SECONDS_PER_DAY * Precise;
+            (day, V, Res) ->
+                Res + (V * ?SECONDS_PER_DAY * Precise);
+            (hour, V, Res) ->
+                Res + (V * ?SECONDS_PER_HOUR * Precise);
+            (minute, V, Res) ->
+                Res + (V * ?SECONDS_PER_MINUTE * Precise);
+            (second, V, Res) ->
+                Res + V * Precise;
+            (millisecond, V, Res) ->
+                case PrecisionUnit of
+                    millisecond ->
+                        Res + V;
+                    microsecond ->
+                        Res + (V * 1000);
+                    nanosecond ->
+                        Res + (V * 1000000)
+                end;
+            (microsecond, V, Res) ->
+                case PrecisionUnit of
+                    microsecond ->
+                        Res + V;
+                    nanosecond ->
+                        Res + (V * 1000)
+                end;
+            (nanosecond, V, Res) ->
+                Res + V;
+            (parsed_offset, V, Res) ->
+                Res - V
+        end,
+    Count = maps:fold(Counter, 0, DateInfo) - (?SECONDS_PER_DAY * Precise),
+    erlang:convert_time_unit(Count, PrecisionUnit, Unit).
+
+precise(#{nanosecond := _}) -> {1000_000_000, nanosecond};
+precise(#{microsecond := _}) -> {1000_000, microsecond};
+precise(#{millisecond := _}) -> {1000, millisecond};
+precise(#{second := _}) -> {1, second};
+precise(_) -> {1, second}.
+
+do_parse_date_str(<<>>, _, Result) -> Result;
+do_parse_date_str(_, [], Result) -> Result;
+do_parse_date_str(Date, [Key | Formatter], Result) ->
+    Size = date_size(Key),
+    <<DatePart:Size/binary-unit:8, Tail/binary>> = Date,
+    case lists:member(Key, ?DATE_PART) of
+        true ->
+            do_parse_date_str(Tail, Formatter, Result#{Key => erlang:binary_to_integer(DatePart)});
+        false ->
+            case lists:member(Key, ?DATE_ZONE_NAME) of
+                true ->
+                    do_parse_date_str(Tail, Formatter, Result#{parsed_offset => offset_second(DatePart)});
+                false ->
+                    do_parse_date_str(Tail, Formatter, Result)
+            end
+    end.
+
+date_size(Str) when is_list(Str) -> erlang:length(Str);
+date_size(DateName) ->
+    Map = #{
+        year   => 4,
+        month  => 2,
+        day    => 2,
+        hour   => 2,
+        minute => 2,
+        second => 2,
+        millisecond => 3,
+        microsecond => 6,
+        nanosecond => 9,
+        timezone => 5,
+        timezone1 => 6,
+        timezone2 => 9
+    },
+    maps:get(DateName, Map).
+
+dm(Month) ->
+    MonthDays = #{
+        1  => 0,
+        2  => 31,
+        3  => 59,
+        4  => 90,
+        5  => 120,
+        6  => 151,
+        7  => 181,
+        8  => 212,
+        9  => 243,
+        10 => 273,
+        11 => 304,
+        12 => 334
+    },
+    maps:get(Month, MonthDays).

src/emqx_logger_textfmt.erl

@@ -39,7 +39,7 @@ format(#{msg := Msg0, meta := Meta} = Event,
     logger_formatter:format(Event#{msg := Msg}, Config#{template => Template});
 
 format(#{msg := Msg0, meta := Meta} = Event,
-       #{timezone_offset := TZO, timezone := TZ, date_format := DFS} = Config) ->
+       #{timezone_offset := TZO, date_format := DFS} = Config) ->
     Msg = maybe_merge(Msg0, Meta),
     Time =
         case maps:get(time, Event, undefined) of
@@ -48,7 +48,7 @@ format(#{msg := Msg0, meta := Meta} = Event,
             T ->
                 T
         end,
-    Date = emqx_calendar:format(Time, microsecond, TZO, TZ, DFS),
+    Date = emqx_calendar:format(Time, microsecond, TZO, DFS),
     [Date | logger_formatter:format(Event#{msg := Msg}, Config)].
 
 maybe_merge({report, Report}, Meta) when is_map(Report) ->