From 9a3d756267311e44f9304209e5c14aab739495fa Mon Sep 17 00:00:00 2001 From: Martin Sumner Date: Fri, 1 Nov 2024 11:40:43 +0000 Subject: [PATCH 1/3] Make log functions exportable To make it easier to switch to logger in kv_index_tictactree - export the log functions from leveled so that they can be reused --- src/leveled_log.erl | 44 +++++++++++++++++++++++++++----------------- 1 file changed, 27 insertions(+), 17 deletions(-) diff --git a/src/leveled_log.erl b/src/leveled_log.erl index f698201d..49b69c37 100644 --- a/src/leveled_log.erl +++ b/src/leveled_log.erl @@ -9,6 +9,8 @@ log_timer/3, log_randomtimer/4]). +-export([log/5, log_timer/6]). + -export([set_loglevel/1, set_databaseid/1, add_forcedlogs/1, @@ -24,8 +26,9 @@ -type log_level() :: debug | info | warning | error | critical. -type log_options() :: #log_options{}. +-type log_base() :: #{atom() => {log_level(), binary()}}. --export_type([log_options/0, log_level/0]). +-export_type([log_options/0, log_level/0, log_base/0]). -define(LOG_LEVELS, [debug, info, warning, error, critical]). -define(DEFAULT_LOG_LEVEL, error). @@ -273,7 +276,7 @@ ic012 => {warning, <<"Tag ~w not found in Strategy ~w - maybe corrupted">>}, ic013 => - {warning, "File with name ~s to be ignored in manifest as scanning for first key returned empty - maybe corrupted"}, + {warning, <<"File with name ~s to be ignored in manifest as scanning for first key returned empty - maybe corrupted">>}, ic014 => {info, <<"Compaction to be run with strategy ~w and max_run_length ~w">>}, cdb01 => @@ -377,7 +380,7 @@ get_opts() -> } end. --spec return_settings() -> {log_level(), list(string())}. +-spec return_settings() -> {log_level(), list(atom())}. %% @doc %% Return the settings outside of the record return_settings() -> @@ -388,14 +391,15 @@ return_settings() -> %%% Prompt Logs %%%============================================================================ --spec log(atom(), list()) -> ok. +-spec log(atom(), list()) -> term(). log(LogReference, Subs) -> - log(LogReference, Subs, ?LOG_LEVELS). + log(LogReference, Subs, ?LOG_LEVELS, ?LOGBASE, backend). -log(LogRef, Subs, SupportedLogLevels) -> - {LogLevel, Log} = maps:get(LogRef, ?LOGBASE), +-spec log(atom(), list(), list(log_level()), log_base(), atom()) -> term(). +log(LogRef, Subs, SupportedLevels, LogBase, Tag) -> + {LogLevel, Log} = maps:get(LogRef, LogBase), LogOpts = get_opts(), - case should_i_log(LogLevel, SupportedLogLevels, LogRef, LogOpts) of + case should_i_log(LogLevel, SupportedLevels, LogRef, LogOpts) of true -> DBid = LogOpts#log_options.database_id, Prefix = @@ -405,7 +409,7 @@ log(LogRef, Subs, SupportedLogLevels) -> LogLevel, unicode:characters_to_list([Prefix, Log, Suffix]), Subs, - #{log_type => backend} + #{log_type => Tag} ); false -> ok @@ -428,12 +432,15 @@ is_active_level([L|_], L, _) -> true; is_active_level([L|_], _, L) -> false; is_active_level([_|T], C, L) -> is_active_level(T, C, L). --spec log_timer(atom(), list(), erlang:timestamp()) -> ok. +-spec log_timer(atom(), list(), erlang:timestamp()) -> term(). log_timer(LogReference, Subs, StartTime) -> - log_timer(LogReference, Subs, StartTime, ?LOG_LEVELS). + log_timer(LogReference, Subs, StartTime, ?LOG_LEVELS, ?LOGBASE, backend). -log_timer(LogRef, Subs, StartTime, SupportedLevels) -> - {LogLevel, Log} = maps:get(LogRef, ?LOGBASE), +-spec log_timer( + atom(), list(), erlang:timestamp(), list(log_level()), log_base(), atom()) + -> term(). +log_timer(LogRef, Subs, StartTime, SupportedLevels, LogBase, Tag) -> + {LogLevel, Log} = maps:get(LogRef, LogBase, LogBase), LogOpts = get_opts(), case should_i_log(LogLevel, SupportedLevels, LogRef, LogOpts) of true -> @@ -446,13 +453,13 @@ log_timer(LogRef, Subs, StartTime, SupportedLevels) -> LogLevel, unicode:characters_to_list([Prefix, Log, Duration, Suffix]), Subs, - #{log_type => backend} + #{log_type => Tag} ); false -> ok end. --spec log_randomtimer(atom(), list(), erlang:timestamp(), float()) -> ok. +-spec log_randomtimer(atom(), list(), erlang:timestamp(), float()) -> term(). log_randomtimer(LogReference, Subs, StartTime, RandomProb) -> R = leveled_rand:uniform(), case R < RandomProb of @@ -494,8 +501,11 @@ log_test() -> log_timer(d0001, [], os:timestamp()). log_warning_test() -> - ok = log(g0001, [], [warning, error]), - ok = log_timer(g0001, [], os:timestamp(), [warning, error]). + ok = log(g0001, [], [warning, error], ?LOGBASE, backend), + ok = + log_timer( + g0001, [], os:timestamp(), [warning, error], ?LOGBASE, backend + ). shouldilog_test() -> ok = set_loglevel(debug), From 3d69afb1b7bf83baf3fe7d18136f815db4f459c4 Mon Sep 17 00:00:00 2001 From: Martin Sumner Date: Thu, 7 Nov 2024 11:23:14 +0000 Subject: [PATCH 2/3] Changes post review Added brief description of the module to explain why the approach to logging is used. --- src/leveled_log.erl | 43 ++++++++++++++++++++++++++++++++++++------- 1 file changed, 36 insertions(+), 7 deletions(-) diff --git a/src/leveled_log.erl b/src/leveled_log.erl index 49b69c37..6268cb05 100644 --- a/src/leveled_log.erl +++ b/src/leveled_log.erl @@ -1,5 +1,24 @@ -%% Module to abstract from choice of logger, and allow use of logReferences -%% for fast lookup +%% -------- LOG --------- +%% +%% Centralised logging, to make it easier to change log implementation. +%% +%% The use of a ?LOGBASE map is a personal preference. With formatting of code +%% using maximum column widths, I prefer not to have log text within the code +%% itself, as there may be a temptation to make log text misleadingly terse to +%% make the code more readable. +%% +%% This means that using logger's capability to add actual code line references +%% to the log becomes mute - as all logs log from the same code line. However, +%% the process does enforce the use of log references to provide a simple way +%% to search the code and find where the log occurred. This can be helpful +%% when there are frequent code changes which may change line numbers between +%% releases (whereas log references stay stable). The log references +%% themselves can be helpful when optimising query times in splunk-like log +%% indexing tools. +%% +%% There are overheads with the approach (e.g. the maps:get/2 call for each log +%% ). However, the eprof testing of leveled indicates that this is not a +%% relatively significant overhead. -module(leveled_log). @@ -440,7 +459,7 @@ log_timer(LogReference, Subs, StartTime) -> atom(), list(), erlang:timestamp(), list(log_level()), log_base(), atom()) -> term(). log_timer(LogRef, Subs, StartTime, SupportedLevels, LogBase, Tag) -> - {LogLevel, Log} = maps:get(LogRef, LogBase, LogBase), + {LogLevel, Log} = maps:get(LogRef, LogBase), LogOpts = get_opts(), case should_i_log(LogLevel, SupportedLevels, LogRef, LogOpts) of true -> @@ -495,10 +514,6 @@ duration_text(StartTime) -> should_i_log(LogLevel, Levels, LogRef) -> should_i_log(LogLevel, Levels, LogRef, get_opts()). - -log_test() -> - log(d0001, []), - log_timer(d0001, [], os:timestamp()). log_warning_test() -> ok = log(g0001, [], [warning, error], ?LOGBASE, backend), @@ -507,6 +522,20 @@ log_warning_test() -> g0001, [], os:timestamp(), [warning, error], ?LOGBASE, backend ). +log_wrongkey_test() -> + ?assertException( + error, + {badkey, wrong0001}, + log(wrong0001, [],[warning, error], ?LOGBASE, backend) + ), + ?assertException( + error, + {badkey, wrong0001}, + log_timer( + wrong0001, [], os:timestamp(), [warning, error], ?LOGBASE, backend + ) + ). + shouldilog_test() -> ok = set_loglevel(debug), ?assertMatch(true, should_i_log(info, ?LOG_LEVELS, g0001)), From da63e7b251bc48b37aecaf02037a13d8cf1aa0f1 Mon Sep 17 00:00:00 2001 From: Martin Sumner Date: Wed, 13 Nov 2024 13:52:17 +0000 Subject: [PATCH 3/3] Result of log should be `ok` --- src/leveled_log.erl | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/leveled_log.erl b/src/leveled_log.erl index 756d70b0..4c1d9f12 100644 --- a/src/leveled_log.erl +++ b/src/leveled_log.erl @@ -410,11 +410,11 @@ return_settings() -> %%% Prompt Logs %%%============================================================================ --spec log(atom(), list()) -> term(). +-spec log(atom(), list()) -> ok. log(LogReference, Subs) -> log(LogReference, Subs, ?LOG_LEVELS, ?LOGBASE, backend). --spec log(atom(), list(), list(log_level()), log_base(), atom()) -> term(). +-spec log(atom(), list(), list(log_level()), log_base(), atom()) -> ok. log(LogRef, Subs, SupportedLevels, LogBase, Tag) -> {LogLevel, Log} = maps:get(LogRef, LogBase), LogOpts = get_opts(), @@ -451,13 +451,13 @@ is_active_level([L|_], L, _) -> true; is_active_level([L|_], _, L) -> false; is_active_level([_|T], C, L) -> is_active_level(T, C, L). --spec log_timer(atom(), list(), erlang:timestamp()) -> term(). +-spec log_timer(atom(), list(), erlang:timestamp()) -> ok. log_timer(LogReference, Subs, StartTime) -> log_timer(LogReference, Subs, StartTime, ?LOG_LEVELS, ?LOGBASE, backend). -spec log_timer( atom(), list(), erlang:timestamp(), list(log_level()), log_base(), atom()) - -> term(). + -> ok. log_timer(LogRef, Subs, StartTime, SupportedLevels, LogBase, Tag) -> {LogLevel, Log} = maps:get(LogRef, LogBase), LogOpts = get_opts(),