Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

Webmachine/Cowboy error pretty-printing #110

Merged
merged 3 commits into from

4 participants

@Vagabond
Collaborator

Webmachine errors go from:

2013-02-27 22:03:25.813 [error] <0.15064.1391> webmachine error:
                     path="/buckets
{error,{error,{badmatch,{error,timeout}},[{riak_kv_wm_buckets,produce_bucket_list,2,[{file,"src/riak_kv_wm_buckets.erl"},{line,123}]},{webmachine_resource,resource_call,3,[{file,"src/webmachine_resource.erl"},{line,169}]},{webmachine_resource,do,3,[{file,"src/webmachine_resource.erl"},{line,128}]},{webmachine_decision_core,resource_call,1,[{file,"src/webmachine_decision_core.erl"},{line,48}]},{webmachine_decision_core,decision,1,[{file,"src

To:

23:42:51.632 [error] Webmachine error at path "/buckets" : no match of right hand value {error,timeout} in riak_kv_wm_buckets:produce_bucket_list/2 line 123

There's also similar rewriting done for cowboy 0.8+ errors.

@Vagabond Vagabond was assigned
@seancribbs

Can't comment on the code, but this is a freaking awesome idea.

@mworrell

I think that you shouldn't loose your back trace.
There is useful information in there, like the resource handling the request, and where in the resource the call originated.

@Vagabond
Collaborator

It isn't lost, it is written to the crash.log if you need more debugging information than what was provided in the 'short' form.

@mworrell

Thanks for the clarification. In that case the short form is very welcome.

@mshonle mshonle was assigned
@mshonle

+1

@mshonle

Re +1, the new tests

@Vagabond Vagabond merged commit 57cc2d5 into master
@Vagabond Vagabond deleted the adt-http-errors branch
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
This page is out of date. Refresh to see the latest.
Showing with 96 additions and 0 deletions.
  1. +28 −0 src/error_logger_lager_h.erl
  2. +68 −0 test/lager_test_backend.erl
View
28 src/error_logger_lager_h.erl
@@ -86,6 +86,34 @@ handle_event(Event, State) ->
?CRASH_LOG(Event),
?LOGFMT(error, Pid, "gen_event ~w installed in ~w terminated with reason: ~s",
[ID, Name, format_reason(Reason)]);
+ "** Cowboy handler"++_ ->
+ %% Cowboy HTTP server error
+ ?CRASH_LOG(Event),
+ case Args of
+ [Module, Function, Arity, _Request, _State] ->
+ %% we only get the 5-element list when its a non-exported function
+ ?LOGFMT(error, Pid,
+ "Cowboy handler ~p terminated with reason: call to undefined function ~p:~p/~p",
+ [Module, Module, Function, Arity]);
+ [Module, Function, Arity, _Class, Reason | Tail] ->
+ %% any other cowboy error_format list *always* ends with the stacktrace
+ StackTrace = lists:last(Tail),
+ ?LOGFMT(error, Pid,
+ "Cowboy handler ~p terminated in ~p:~p/~p with reason: ~s",
+ [Module, Module, Function, Arity, format_reason({Reason, StackTrace})])
+ end;
+ "webmachine error"++_ ->
+ %% Webmachine HTTP server error
+ ?CRASH_LOG(Event),
+ [Path, Error] = Args,
+ %% webmachine likes to mangle the stack, for some reason
+ StackTrace = case Error of
+ {error, {error, Reason, Stack}} ->
+ {Reason, Stack};
+ _ ->
+ Error
+ end,
+ ?LOGFMT(error, Pid, "Webmachine error at path ~p : ~s", [Path, format_reason(StackTrace)]);
_ ->
?CRASH_LOG(Event),
?LOGMSG(error, Pid, lager:safe_format(Fmt, Args, ?DEFAULT_TRUNCATION))
View
68 test/lager_test_backend.erl
@@ -889,6 +889,74 @@ error_logger_redirect_test_() ->
test_body(Expected, lists:flatten(Msg))
end
},
+ {"webmachine error reports",
+ fun() ->
+ Path = "/cgi-bin/phpmyadmin",
+ Reason = {error,{error,{badmatch,{error,timeout}},
+ [{myapp,dostuff,2,[{file,"src/myapp.erl"},{line,123}]},
+ {webmachine_resource,resource_call,3,[{file,"src/webmachine_resource.erl"},{line,169}]}]}},
+ sync_error_logger:error_msg("webmachine error: path=~p~n~p~n", [Path, Reason]),
+ _ = gen_event:which_handlers(error_logger),
+ {Level, _, Msg,Metadata} = pop(),
+ ?assertEqual(lager_util:level_to_num(error),Level),
+ ?assertEqual(self(),proplists:get_value(pid,Metadata)),
+ ?assertEqual("Webmachine error at path \"/cgi-bin/phpmyadmin\" : no match of right hand value {error,timeout} in myapp:dostuff/2 line 123", lists:flatten(Msg))
+
+ end
+ },
+ {"Cowboy error reports, 8 arg version",
+ fun() ->
+ Stack = [{my_handler,init, 3,[{file,"src/my_handler.erl"},{line,123}]},
+ {cowboy_handler,handler_init,4,[{file,"src/cowboy_handler.erl"},{line,169}]}],
+
+ sync_error_logger:error_msg(
+ "** Cowboy handler ~p terminating in ~p/~p~n"
+ " for the reason ~p:~p~n"
+ "** Options were ~p~n"
+ "** Request was ~p~n"
+ "** Stacktrace: ~p~n~n",
+ [my_handler, init, 3, error, {badmatch, {error, timeout}}, [],
+ "Request", Stack]),
+ _ = gen_event:which_handlers(error_logger),
+ {Level, _, Msg,Metadata} = pop(),
+ ?assertEqual(lager_util:level_to_num(error),Level),
+ ?assertEqual(self(),proplists:get_value(pid,Metadata)),
+ ?assertEqual("Cowboy handler my_handler terminated in my_handler:init/3 with reason: no match of right hand value {error,timeout} in my_handler:init/3 line 123", lists:flatten(Msg))
+ end
+ },
+ {"Cowboy error reports, 10 arg version",
+ fun() ->
+ Stack = [{my_handler,somecallback, 3,[{file,"src/my_handler.erl"},{line,123}]},
+ {cowboy_handler,handler_init,4,[{file,"src/cowboy_handler.erl"},{line,169}]}],
+ sync_error_logger:error_msg(
+ "** Cowboy handler ~p terminating in ~p/~p~n"
+ " for the reason ~p:~p~n** Message was ~p~n"
+ "** Options were ~p~n** Handler state was ~p~n"
+ "** Request was ~p~n** Stacktrace: ~p~n~n",
+ [my_handler, somecallback, 3, error, {badmatch, {error, timeout}}, hello, [],
+ {}, "Request", Stack]),
+
+ _ = gen_event:which_handlers(error_logger),
+ {Level, _, Msg,Metadata} = pop(),
+ ?assertEqual(lager_util:level_to_num(error),Level),
+ ?assertEqual(self(),proplists:get_value(pid,Metadata)),
+ ?assertEqual("Cowboy handler my_handler terminated in my_handler:somecallback/3 with reason: no match of right hand value {error,timeout} in my_handler:somecallback/3 line 123", lists:flatten(Msg))
+ end
+ },
+ {"Cowboy error reports, 5 arg version",
+ fun() ->
+ sync_error_logger:error_msg(
+ "** Cowboy handler ~p terminating; "
+ "function ~p/~p was not exported~n"
+ "** Request was ~p~n** State was ~p~n~n",
+ [my_handler, to_json, 2, "Request", {}]),
+ _ = gen_event:which_handlers(error_logger),
+ {Level, _, Msg,Metadata} = pop(),
+ ?assertEqual(lager_util:level_to_num(error),Level),
+ ?assertEqual(self(),proplists:get_value(pid,Metadata)),
+ ?assertEqual("Cowboy handler my_handler terminated with reason: call to undefined function my_handler:to_json/2", lists:flatten(Msg))
+ end
+ },
{"messages should not be generated if they don't satisfy the threshold",
fun() ->
lager:set_loglevel(?MODULE, error),
Something went wrong with that request. Please try again.