From c8f12eb8bc83cf10455146985c284d5a06d7cedd Mon Sep 17 00:00:00 2001 From: walrusVision Date: Mon, 27 Feb 2017 11:25:17 +1300 Subject: [PATCH] Full support for function transforms * Updated README with instructions on how to use * Basic set of tests for working and non working examples --- README.md | 24 ++++ src/lager_transform.erl | 7 +- test/lager_test_function_transform.erl | 142 +++++++++++++++++++ test/lager_test_function_transform_error.erl | 80 +++++++++++ 4 files changed, 251 insertions(+), 2 deletions(-) create mode 100644 test/lager_test_function_transform.erl create mode 100644 test/lager_test_function_transform_error.erl diff --git a/README.md b/README.md index b7508a5..1146f4b 100644 --- a/README.md +++ b/README.md @@ -636,6 +636,30 @@ and caveats noted above apply. up to and including 3.1.0 or previous. The 2-tuple form wasn't added until 3.2.0. +Setting dynamic metadata at compile-time +---------------------------------------- +Lager supports supplying metadata from external sources. You can add these by +using the `{lager_parse_transform_functions, X}` option. In rebar, you can +add it to `erl_opts`: + +```erlang +{erl_opts, [{parse_transform, lager_transform}, + {lager_function_transforms, + [{metadata_name, {module_name, function_name}]}. +``` + +The MF called should take no arguments and should return a value that can be be + formatted into a log message. + +This metadata is also persistent across processes. + +**IMPORTANT**: Since you can calling functions, be aware that using these +could have an impact on your logging performance depending on what the call +will need to do. + +Also there is no protection against against an undefined module:function or +ensuring any required apps are started. + Setting the truncation limit at compile-time -------------------------------------------- Lager defaults to truncating messages at 4096 bytes, you can alter this by diff --git a/src/lager_transform.erl b/src/lager_transform.erl index d2b138c..44bec58 100644 --- a/src/lager_transform.erl +++ b/src/lager_transform.erl @@ -29,7 +29,6 @@ %% @private parse_transform(AST, Options) -> - io:format("~p~n", [?MODULE]), TruncSize = proplists:get_value(lager_truncation_size, Options, ?DEFAULT_TRUNCATION), Enable = proplists:get_value(lager_print_records_flag, Options, true), Sinks = [lager] ++ proplists:get_value(lager_extra_sinks, Options, []), @@ -57,6 +56,11 @@ walk_ast(Acc, [{attribute, _, module, {Module, _PmodArgs}}=H|T]) -> walk_ast(Acc, [{attribute, _, module, Module}=H|T]) -> put(module, Module), walk_ast([H|Acc], T); +walk_ast(Acc, [{attribute, _, lager_function_transforms, FromModule }=H|T]) -> + %% Merge transform options from the module over the compile options + FromOptions = get(functions), + put(functions, orddict:merge(fun(_Key, _V1, V2) -> V2 end, FromOptions, FromModule)), + walk_ast([H|Acc], T); walk_ast(Acc, [{function, Line, Name, Arity, Clauses}|T]) -> put(function, Name), walk_ast([{function, Line, Name, Arity, @@ -117,7 +121,6 @@ transform_statement(Stmt, _Sinks) -> add_function_transforms(_Line, DefaultAttrs, []) -> DefaultAttrs; add_function_transforms(Line, DefaultAttrs, [{Atom, {Module, Function}}|Remainder]) -> - io:format("Adding ~p:~p to line ~p~n", [Module, Function, Line]), NewFunction = {tuple, Line, [ {atom, Line, Atom}, {call, Line, {remote, Line, {atom, Line, Module}, {atom, Line, Function}} , []} diff --git a/test/lager_test_function_transform.erl b/test/lager_test_function_transform.erl new file mode 100644 index 0000000..2daea75 --- /dev/null +++ b/test/lager_test_function_transform.erl @@ -0,0 +1,142 @@ +%% ------------------------------------------------------------------- +%% +%% Copyright (c) 2011-2017 Basho Technologies, Inc. +%% +%% This file is provided to you under the Apache License, +%% Version 2.0 (the "License"); you may not use this file +%% except in compliance with the License. You may obtain +%% a copy of the License at +%% +%% http://www.apache.org/licenses/LICENSE-2.0 +%% +%% Unless required by applicable law or agreed to in writing, +%% software distributed under the License is distributed on an +%% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +%% KIND, either express or implied. See the License for the +%% specific language governing permissions and limitations +%% under the License. +%% +%% ------------------------------------------------------------------- + +-module(lager_test_function_transform). + +-include("lager.hrl"). + +-lager_function_transforms([ + {returns_static, {lager_test_function_transform, transform_static}}, + {returns_dynamic, {lager_test_function_transform, transform_dynamic}} +]). + +-compile({parse_transform, lager_transform}). + +-ifdef(TEST). +-include_lib("eunit/include/eunit.hrl"). +-export([ + transform_static/0, + transform_dynamic/0 +]). +-endif. + +-ifdef(TEST). + +transform_static() -> + static_result. + +transform_dynamic() -> + rand:uniform(10). + +not_running_test() -> + ?assertEqual({error, lager_not_running}, lager:log(info, self(), "not running")). + +setup() -> + error_logger:tty(false), + application:load(lager), + application:set_env(lager, handlers, [{lager_test_backend, info}]), + application:set_env(lager, error_logger_redirect, false), + application:unset_env(lager, traces), + lager:start(), + %% There is a race condition between the application start up, lager logging its own + %% start up condition and several tests that count messages or parse the output of + %% tests. When the lager start up message wins the race, it causes these tests + %% which parse output or count message arrivals to fail. + %% + %% We introduce a sleep here to allow `flush' to arrive *after* the start up + %% message has been received and processed. + %% + %% This race condition was first exposed during the work on + %% 4b5260c4524688b545cc12da6baa2dfa4f2afec9 which introduced the lager + %% manager killer PR. + timer:sleep(5), + gen_event:call(lager_event, lager_test_backend, flush). + + +cleanup(_) -> + catch ets:delete(lager_config), %% kill the ets config table with fire + application:stop(lager), + application:stop(goldrush), + error_logger:tty(true). + +transform_function_test_() -> + {foreach, + fun setup/0, + fun cleanup/1, + [ + {"observe that there is nothing up my sleeve", + fun() -> + ?assertEqual(undefined, lager_test_backend:pop()), + ?assertEqual(0, lager_test_backend:count()) + end + }, + {"logging works", + fun() -> + lager:warning("test message"), + ?assertEqual(1, lager_test_backend:count()), + {Level, _Time, Message, _Metadata} = lager_test_backend:pop(), + ?assertMatch(Level, lager_util:level_to_num(warning)), + ?assertEqual("test message", Message), + ok + end + }, + {"Test calling a function returns the same content", + fun() -> + lager:warning("static message"), + ?assertEqual(1, lager_test_backend:count()), + {_Level, _Time, _Message, Metadata} = lager_test_backend:pop(), + ?assertEqual(transform_static(), proplists:get_value(returns_static, Metadata)), + ok + end + }, + {"Test calling a function which returns content which can change", + fun() -> + lager:warning("dynamic message 1"), + lager:warning("dynamic message 2"), + lager:warning("dynamic message 3"), + lager:warning("dynamic message 4"), + lager:warning("dynamic message 5"), + lager:warning("dynamic message 6"), + ?assertEqual(6, lager_test_backend:count()), + {_Level1, _Time1, _Message1, Metadata1} = lager_test_backend:pop(), + Replacement1 = proplists:get_value(returns_dynamic, Metadata1), + ?assert((1 =< Replacement1) and (Replacement1 =< 10)), + {_Level2, _Time2, _Message2, Metadata2} = lager_test_backend:pop(), + Replacement2 = proplists:get_value(returns_dynamic, Metadata2), + ?assert((1 =< Replacement2) and (Replacement2 =< 10)), + {_Level3, _Time3, _Message3, Metadata3} = lager_test_backend:pop(), + Replacement3 = proplists:get_value(returns_dynamic, Metadata3), + ?assert((1 =< Replacement3) and (Replacement3 =< 10)), + {_Level4, _Time4, _Message4, Metadata4} = lager_test_backend:pop(), + Replacement4 = proplists:get_value(returns_dynamic, Metadata4), + ?assert((1 =< Replacement4) and (Replacement4 =< 10)), + {_Level5, _Time5, _Message5, Metadata5} = lager_test_backend:pop(), + Replacement5 = proplists:get_value(returns_dynamic, Metadata5), + ?assert((1 =< Replacement5) and (Replacement5 =< 10)), + {_Level6, _Time6, _Message6, Metadata6} = lager_test_backend:pop(), + Replacement6 = proplists:get_value(returns_dynamic, Metadata6), + ?assert((1 =< Replacement6) and (Replacement6 =< 10)), + ok + end + } + ] + }. + +-endif. diff --git a/test/lager_test_function_transform_error.erl b/test/lager_test_function_transform_error.erl new file mode 100644 index 0000000..6cd7a53 --- /dev/null +++ b/test/lager_test_function_transform_error.erl @@ -0,0 +1,80 @@ +%% ------------------------------------------------------------------- +%% +%% Copyright (c) 2011-2017 Basho Technologies, Inc. +%% +%% This file is provided to you under the Apache License, +%% Version 2.0 (the "License"); you may not use this file +%% except in compliance with the License. You may obtain +%% a copy of the License at +%% +%% http://www.apache.org/licenses/LICENSE-2.0 +%% +%% Unless required by applicable law or agreed to in writing, +%% software distributed under the License is distributed on an +%% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +%% KIND, either express or implied. See the License for the +%% specific language governing permissions and limitations +%% under the License. +%% +%% ------------------------------------------------------------------- + +-module(lager_test_function_transform_error). + +-compile([ + {parse_transform, lager_transform} +]). + +-lager_function_transforms([ + {returns_undefined, {not_real_module_fake, fake_not_real_function}} +]). + +-ifdef(TEST). +-include_lib("eunit/include/eunit.hrl"). +-endif. + +setup() -> + error_logger:tty(false), + application:load(lager), + application:set_env(lager, handlers, [{lager_test_backend, info}]), + application:set_env(lager, error_logger_redirect, false), + application:unset_env(lager, traces), + lager:start(), + %% There is a race condition between the application start up, lager logging its own + %% start up condition and several tests that count messages or parse the output of + %% tests. When the lager start up message wins the race, it causes these tests + %% which parse output or count message arrivals to fail. + %% + %% We introduce a sleep here to allow `flush' to arrive *after* the start up + %% message has been received and processed. + %% + %% This race condition was first exposed during the work on + %% 4b5260c4524688b545cc12da6baa2dfa4f2afec9 which introduced the lager + %% manager killer PR. + timer:sleep(5), + gen_event:call(lager_event, lager_test_backend, flush). + +cleanup(_) -> + catch ets:delete(lager_config), %% kill the ets config table with fire + application:stop(lager), + application:stop(goldrush), + error_logger:tty(true). + +transform_function_error_test_() -> + {foreach, + fun setup/0, + fun cleanup/1, + [ + {"observe that there is nothing up my sleeve", + fun() -> + ?assertEqual(undefined, lager_test_backend:pop()), + ?assertEqual(0, lager_test_backend:count()) + end + }, + {"Testing a function transform for a undefined function errors", + fun() -> + ?assertError(undef, lager:warning("undefined message")), + ok + end + } + ] + }. \ No newline at end of file