Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

Parse transform can't handle `Attr' as a variable #54

Merged
merged 2 commits into from

4 participants

Olle Törnström Andrew Thompson Likhanov Alexander Sean Cribbs
Olle Törnström

Log statements with Attr bound to a variable, causes the parse transform to fail with a function_clause. To reproduce, try out the following:

Attr = [{a, alpha}, {b, beta}],
lager:info(Attr, "Hello ~s", ["world!"]).

Crashes during compile with something like the following (cropped).

{function_clause, [
  {lager_transform, concat_lists, [
    {var,24,'Attr'}, ...

The cause is clear, it is expected that the DefaultAttrs can be appended to the passed property list of attributes, so there's no clause for a var in concat_lists.

But - It's already noted in lager_transform.erl that transformation of logging statements is ambiguous for calls with arity 3 (2 arguments). Sadly I think it's not only that, but actually also broken for arity 2 if Attr is a variable - the match for a property list doesn't work. Actually, Is is at all possible to walk the AST in a parse transform, when the variable is passed from outside the module? To me it seems that this could be the real bringer of bad news.

I like the general idea of lager, having log statements transformed in order to add implicit meta-data, but I think that the way the API is designed right now, it's very hard to support a more free way of using, and abusing, it.

To be on the safe side I guess the API has to use stricter ordering for optional parameters i.e. attributes are always arity 3 and always on the end of the call. Another option could be to use tagged parameters.

Perhaps a solution for lager, and this API version, is to simply amend the documentation and more clearly state that the attributes, must be defined as an inline property list.

Or does someone else have a solution for this?

With kind regards
/O

Andrew Thompson
Collaborator

How does this look? Sorry it took forever to look into this...

Likhanov Alexander

Hi! Voting this too.
But I think we can do a little better, because Attrs can be not only variable, but a function call, maybe record field(why not?)
My solution is here vegayours#1
It is almost the same (I have found this pull request after fixing Attrs as variable issue)
If you are going to accept this pull request we can merge our work

Andrew Thompson
Collaborator

Yes, you can merge your work with mine, and add some tests to support function call arguments or whatever (list comprehensions, whatever).

Andrew Thompson
Collaborator

@vegayours ping?

Likhanov Alexander
Andrew Thompson
Collaborator

@vegayours re-ping

Vagabond added some commits
Andrew Thompson Vagabond Support variables as arguments to lager:info and friends
As long as *one* of the arguments is a literal, lager can figure out
what you're trying to do and (re)arrange the arguments as necessary.
95fdf93
Andrew Thompson Vagabond Also allow list comps, function calls and record fields as lager argu…
…ments
0ec0d90
Andrew Thompson
Collaborator

Parse transform now handles variables, list comprehensions, function calls and record fields. Anything else? Begin/End blocks seem kind of stupid to support, as do clauses/ifs.

Sean Cribbs
Owner

Nothing in this PR concerns me except these EQC failures on seemingly unrelated code. Can you confirm?

Exception: badarg
FmtStr: []
Args:   []
Failed! After 1 tests.
{[],3}
trunc_io_eqc:42: eqc_test_...*failed*
in function trunc_io_eqc:'-eqc_test_/0-fun-1-'/1 (test/trunc_io_eqc.erl, line 42)
**error:{assertEqual_failed,[{module,trunc_io_eqc},
                     {line,42},
                     {expression,"eqc : quickcheck ( eqc : testing_time ( 14 , ? QC_OUT ( prop_format ( ) ) ) )"},
                     {expected,true},
                     {value,false}]}
  output:<<"Starting Quviq QuickCheck version 1.27.7
   (compiled at {{2012,11,20},{14,59,9}})
Licence for Basho reserved until {{2013,2,26},{10,54,59}}
">>

Failed! Reason: 
{'EXIT',{badarg,[{lager_trunc_io,format,
                                 [[],[]],
                                 [{file,"src/lager_trunc_io.erl"},{line,66}]},
                 {trunc_io_eqc,'-prop_equivalence/0-fun-2-',1,
                               [{file,"test/trunc_io_eqc.erl"},{line,197}]}]}}
After 1 tests.
[]
trunc_io_eqc:43: eqc_test_...*failed*
in function trunc_io_eqc:'-eqc_test_/0-fun-4-'/1 (test/trunc_io_eqc.erl, line 43)
**error:{assertEqual_failed,[{module,trunc_io_eqc},
                     {line,43},
                     {expression,"eqc : quickcheck ( eqc : testing_time ( 14 , ? QC_OUT ( prop_equivalence ( ) ) ) )"},
                     {expected,true},
                     {value,false}]}
Sean Cribbs
Owner

It seems @engelsanchez brought this up on #108.

Andrew Thompson
Collaborator

I think this is a different EQC problem, caused by this change. I'll investigate.

Andrew Thompson
Collaborator

Oh, so that EQC failure looks to be fixed over on the iolist branch:

https://github.com/basho/lager/pull/108/files#L0R32

If you rebase this branch on top of that one, the tests pass.

Sean Cribbs
Owner

:+1: then :smile:

Andrew Thompson Vagabond merged commit 2a8706b into from
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Commits on Feb 15, 2013
  1. Andrew Thompson

    Support variables as arguments to lager:info and friends

    Vagabond authored
    As long as *one* of the arguments is a literal, lager can figure out
    what you're trying to do and (re)arrange the arguments as necessary.
  2. Andrew Thompson
This page is out of date. Refresh to see the latest.
Showing with 153 additions and 2 deletions.
  1. +33 −2 src/lager_transform.erl
  2. +120 −0 test/lager_test_backend.erl
35 src/lager_transform.erl
View
@@ -107,10 +107,25 @@ transform_statement({call, Line, {remote, _Line1, {atom, _Line2, lager},
%% [Format, Args] or [Attr, Format].
%% The trace attributes will be a list of tuples, so check
%% for that.
- case Arg1 of
- {cons, _, {tuple, _, _}, _} ->
+ case {element(1, Arg1), Arg1} of
+ {_, {cons, _, {tuple, _, _}, _}} ->
{concat_lists(Arg1, DefaultAttrs),
Arg2, {atom, Line, none}};
+ {Type, _} when Type == var;
+ Type == lc;
+ Type == call;
+ Type == record_field ->
+ %% crap, its not a literal. look at the second
+ %% argument to see if it is a string
+ case Arg2 of
+ {string, _, _} ->
+ {concat_lists(Arg1, DefaultAttrs),
+ Arg2, {atom, Line, none}};
+ _ ->
+ %% not a string, going to have to guess
+ %% it's the argument list
+ {DefaultAttrs, Arg1, Arg2}
+ end;
_ ->
{DefaultAttrs, Arg1, Arg2}
end;
@@ -146,6 +161,22 @@ transform_statement(Stmt) ->
Stmt.
%% concat 2 list ASTs by replacing the terminating [] in A with the contents of B
+concat_lists({var, Line, _Name}=Var, B) ->
+ %% concatenating a var with a cons
+ {call, Line, {remote, Line, {atom, Line, lists},{atom, Line, flatten}},
+ [{cons, Line, Var, B}]};
+concat_lists({lc, Line, _Body, _Generator} = LC, B) ->
+ %% concatenating a LC with a cons
+ {call, Line, {remote, Line, {atom, Line, lists},{atom, Line, flatten}},
+ [{cons, Line, LC, B}]};
+concat_lists({call, Line, _Function, _Args} = Call, B) ->
+ %% concatenating a call with a cons
+ {call, Line, {remote, Line, {atom, Line, lists},{atom, Line, flatten}},
+ [{cons, Line, Call, B}]};
+concat_lists({record_field, Line, _Var, _Record, _Field} = Rec, B) ->
+ %% concatenating a record_field with a cons
+ {call, Line, {remote, Line, {atom, Line, lists},{atom, Line, flatten}},
+ [{cons, Line, Rec, B}]};
concat_lists({nil, _Line}, B) ->
B;
concat_lists({cons, Line, Element, Tail}, B) ->
120 test/lager_test_backend.erl
View
@@ -24,6 +24,7 @@
code_change/3]).
-record(state, {level, buffer, ignored}).
+-record(test, {attrs, format, args}).
-compile([{parse_transform, lager_transform}]).
-ifdef(TEST).
@@ -180,6 +181,125 @@ lager_test_() ->
ok
end
},
+ {"variables inplace of literals in logging statements work",
+ fun() ->
+ ?assertEqual(0, count()),
+ Attr = [{a, alpha}, {b, beta}],
+ Fmt = "format ~p",
+ Args = [world],
+ lager:info(Attr, "hello"),
+ lager:info(Attr, "hello ~p", [world]),
+ lager:info(Fmt, [world]),
+ lager:info("hello ~p", Args),
+ lager:info(Attr, "hello ~p", Args),
+ lager:info([{d, delta}, {g, gamma}], Fmt, Args),
+ ?assertEqual(6, count()),
+ {_Level, _Time, Message, Metadata} = pop(),
+ ?assertMatch([{a, alpha}, {b, beta}|_], Metadata),
+ ?assertEqual("hello", lists:flatten(Message)),
+ {_Level, _Time2, Message2, _Metadata2} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message2)),
+ {_Level, _Time3, Message3, _Metadata3} = pop(),
+ ?assertEqual("format world", lists:flatten(Message3)),
+ {_Level, _Time4, Message4, _Metadata4} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message4)),
+ {_Level, _Time5, Message5, _Metadata5} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message5)),
+ {_Level, _Time6, Message6, Metadata6} = pop(),
+ ?assertMatch([{d, delta}, {g, gamma}|_], Metadata6),
+ ?assertEqual("format world", lists:flatten(Message6)),
+ ok
+ end
+ },
+ {"list comprehension inplace of literals in logging statements work",
+ fun() ->
+ ?assertEqual(0, count()),
+ Attr = [{a, alpha}, {b, beta}],
+ Fmt = "format ~p",
+ Args = [world],
+ lager:info([{K, atom_to_list(V)} || {K, V} <- Attr], "hello"),
+ lager:info([{K, atom_to_list(V)} || {K, V} <- Attr], "hello ~p", [{atom, X} || X <- Args]),
+ lager:info([X || X <- Fmt], [world]),
+ lager:info("hello ~p", [{atom, X} || X <- Args]),
+ lager:info([{K, atom_to_list(V)} || {K, V} <- Attr], "hello ~p", [{atom, X} || X <- Args]),
+ lager:info([{d, delta}, {g, gamma}], Fmt, [{atom, X} || X <- Args]),
+ ?assertEqual(6, count()),
+ {_Level, _Time, Message, Metadata} = pop(),
+ ?assertMatch([{a, "alpha"}, {b, "beta"}|_], Metadata),
+ ?assertEqual("hello", lists:flatten(Message)),
+ {_Level, _Time2, Message2, _Metadata2} = pop(),
+ ?assertEqual("hello {atom,world}", lists:flatten(Message2)),
+ {_Level, _Time3, Message3, _Metadata3} = pop(),
+ ?assertEqual("format world", lists:flatten(Message3)),
+ {_Level, _Time4, Message4, _Metadata4} = pop(),
+ ?assertEqual("hello {atom,world}", lists:flatten(Message4)),
+ {_Level, _Time5, Message5, _Metadata5} = pop(),
+ ?assertEqual("hello {atom,world}", lists:flatten(Message5)),
+ {_Level, _Time6, Message6, Metadata6} = pop(),
+ ?assertMatch([{d, delta}, {g, gamma}|_], Metadata6),
+ ?assertEqual("format {atom,world}", lists:flatten(Message6)),
+ ok
+ end
+ },
+ {"function calls inplace of literals in logging statements work",
+ fun() ->
+ ?assertEqual(0, count()),
+ put(attrs, [{a, alpha}, {b, beta}]),
+ put(format, "format ~p"),
+ put(args, [world]),
+ lager:info(get(attrs), "hello"),
+ lager:info(get(attrs), "hello ~p", get(args)),
+ lager:info(get(format), [world]),
+ lager:info("hello ~p", erlang:get(args)),
+ lager:info(fun() -> get(attrs) end(), "hello ~p", get(args)),
+ lager:info([{d, delta}, {g, gamma}], get(format), get(args)),
+ ?assertEqual(6, count()),
+ {_Level, _Time, Message, Metadata} = pop(),
+ ?assertMatch([{a, alpha}, {b, beta}|_], Metadata),
+ ?assertEqual("hello", lists:flatten(Message)),
+ {_Level, _Time2, Message2, _Metadata2} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message2)),
+ {_Level, _Time3, Message3, _Metadata3} = pop(),
+ ?assertEqual("format world", lists:flatten(Message3)),
+ {_Level, _Time4, Message4, _Metadata4} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message4)),
+ {_Level, _Time5, Message5, _Metadata5} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message5)),
+ {_Level, _Time6, Message6, Metadata6} = pop(),
+ ?assertMatch([{d, delta}, {g, gamma}|_], Metadata6),
+ ?assertEqual("format world", lists:flatten(Message6)),
+ ok
+ end
+ },
+ {"record fields inplace of literals in logging statements work",
+ fun() ->
+ ?assertEqual(0, count()),
+ Test = #test{attrs=[{a, alpha}, {b, beta}], format="format ~p", args=[world]},
+ lager:info(Test#test.attrs, "hello"),
+ lager:info(Test#test.attrs, "hello ~p", Test#test.args),
+ lager:info(Test#test.format, [world]),
+ lager:info("hello ~p", Test#test.args),
+ lager:info(Test#test.attrs, "hello ~p", Test#test.args),
+ lager:info([{d, delta}, {g, gamma}], Test#test.format, Test#test.args),
+ ?assertEqual(6, count()),
+ {_Level, _Time, Message, Metadata} = pop(),
+ ?assertMatch([{a, alpha}, {b, beta}|_], Metadata),
+ ?assertEqual("hello", lists:flatten(Message)),
+ {_Level, _Time2, Message2, _Metadata2} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message2)),
+ {_Level, _Time3, Message3, _Metadata3} = pop(),
+ ?assertEqual("format world", lists:flatten(Message3)),
+ {_Level, _Time4, Message4, _Metadata4} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message4)),
+ {_Level, _Time5, Message5, _Metadata5} = pop(),
+ ?assertEqual("hello world", lists:flatten(Message5)),
+ {_Level, _Time6, Message6, Metadata6} = pop(),
+ ?assertMatch([{d, delta}, {g, gamma}|_], Metadata6),
+ ?assertEqual("format world", lists:flatten(Message6)),
+ ok
+ end
+ },
+
{"log messages below the threshold are ignored",
fun() ->
?assertEqual(0, count()),
Something went wrong with that request. Please try again.