diff --git a/src/leveled_log.erl b/src/leveled_log.erl index 618c871..f60ca76 100644 --- a/src/leveled_log.erl +++ b/src/leveled_log.erl @@ -309,10 +309,12 @@ log(LogReference, Subs) -> - {ok, {LogLevel, LogText}} = dict:find(LogReference, ?LOGBASE), + {LogLevel, LogText} = dict:fetch(LogReference, ?LOGBASE), case lists:member(LogLevel, ?LOG_LEVEL) of true -> - io:format(LogReference ++ " ~w " ++ LogText ++ "~n", + io:format(format_time() + ++ " " ++ LogReference ++ " ~w " + ++ LogText ++ "~n", [self()|Subs]); false -> ok @@ -320,7 +322,7 @@ log(LogReference, Subs) -> log_timer(LogReference, Subs, StartTime) -> - {ok, {LogLevel, LogText}} = dict:find(LogReference, ?LOGBASE), + {LogLevel, LogText} = dict:fetch(LogReference, ?LOGBASE), case lists:member(LogLevel, ?LOG_LEVEL) of true -> MicroS = timer:now_diff(os:timestamp(), StartTime), @@ -330,7 +332,9 @@ log_timer(LogReference, Subs, StartTime) -> MicroS -> {"ms", MicroS div 1000} end, - io:format(LogReference ++ " ~w " ++ LogText + io:format(format_time() + ++ LogReference ++ " ~w " + ++ LogText ++ " with time taken ~w " ++ Unit ++ "~n", [self()|Subs] ++ [Time]); false -> @@ -510,6 +514,17 @@ gen_timing_int({N, TimerD}, T0, TimerType, _KeyListFun, _LogPoint, _LogRef) -> TimerD)}. +format_time() -> + format_time(localtime_ms()). + +localtime_ms() -> + {_, _, Micro} = Now = os:timestamp(), + {Date, {Hours, Minutes, Seconds}} = calendar:now_to_local_time(Now), + {Date, {Hours, Minutes, Seconds, Micro div 1000 rem 1000}}. + +format_time({{Y, M, D}, {H, Mi, S, Ms}}) -> + io_lib:format("~b-~2..0b-~2..0b", [Y, M, D]) ++ "T" ++ + io_lib:format("~2..0b:~2..0b:~2..0b.~3..0b", [H, Mi, S, Ms]). %%%============================================================================ diff --git a/src/leveled_tree.erl b/src/leveled_tree.erl index 8804847..ba07a3f 100644 --- a/src/leveled_tree.erl +++ b/src/leveled_tree.erl @@ -524,7 +524,7 @@ search_test_by_type(Type) -> T = from_orderedlist(KL, Type), StartKeyFun = fun(V) -> V end, - SW = os:timestamp(), + statistics(runtime), ?assertMatch([], search_range(0, 1, T, StartKeyFun)), ?assertMatch([], search_range(201, 202, T, StartKeyFun)), ?assertMatch([{4, 2}], search_range(2, 4, T, StartKeyFun)), @@ -535,8 +535,9 @@ search_test_by_type(Type) -> ?assertMatch(49, length(search_range(2, 197, T, StartKeyFun))), ?assertMatch(49, length(search_range(4, 197, T, StartKeyFun))), ?assertMatch(48, length(search_range(5, 197, T, StartKeyFun))), + {_, T1} = statistics(runtime), io:format(user, "10 range tests with type ~w in ~w microseconds~n", - [Type, timer:now_diff(os:timestamp(), SW)]). + [Type, T1]). tree_oor_test() -> @@ -591,21 +592,30 @@ tolist_test_by_type(Type) -> ?assertMatch(KL, T_Reverse). tree_timing_test() -> - tree_test_by_(16, tree, 4000), + log_tree_test_by_(16, tree, 4000), tree_test_by_(8, tree, 1000), tree_test_by_(4, tree, 256). idxt_timing_test() -> - tree_test_by_(16, idxt, 4000), + log_tree_test_by_(16, idxt, 4000), tree_test_by_(8, idxt, 1000), tree_test_by_(4, idxt, 256). skpl_timing_test() -> tree_test_by_(auto, skpl, 6000), - tree_test_by_(auto, skpl, 4000), + log_tree_test_by_(auto, skpl, 4000), tree_test_by_(auto, skpl, 1000), tree_test_by_(auto, skpl, 256). +log_tree_test_by_(Width, Type, N) -> + erlang:statistics(runtime), + G0 = erlang:statistics(garbage_collection), + tree_test_by_(Width, Type, N), + {_, T1} = erlang:statistics(runtime), + G1 = erlang:statistics(garbage_collection), + io:format(user, "Test took ~w ms and GC transitioned from ~w to ~w~n", + [T1, G0, G1]). + tree_test_by_(Width, Type, N) -> io:format(user, "~nTree test for type and width: ~w ~w~n", [Type, Width]), KL = lists:ukeysort(1, generate_randomkeys(1, N, 1, N div 5)),