From: Christopher Piro Date: Fri, 19 Oct 2007 21:34:31 +0000 (+0000) Subject: [thrift] clean up error logging in Erlang X-Git-Tag: 0.2.0~1167 X-Git-Url: https://source.supwisdom.com/gerrit/gitweb?a=commitdiff_plain;h=3b63fe4d3c75b20250ca1977750d4b4b3f80bf9b;p=common%2Fthrift.git [thrift] clean up error logging in Erlang Summary: pushed all formatting out of thrift_error_logger.erl, reenable crash logs, standardize Reviewed By: eletuchy Test Plan: works with latest ch server git-svn-id: https://svn.apache.org/repos/asf/incubator/thrift/trunk@665305 13f79535-47bb-0310-9956-ffa450edef68 --- diff --git a/lib/erl/include/thrift.hrl b/lib/erl/include/thrift.hrl index fdeaf1d8..efd2b432 100644 --- a/lib/erl/include/thrift.hrl +++ b/lib/erl/include/thrift.hrl @@ -9,8 +9,8 @@ -define(ERROR(F, D), error_logger:format(F, D)). --define(INFO(Type, Report), - error_logger:info_report({thrift_info, Type}, Report)). +-define(INFO(F, D), + error_logger:info_msg(F, D)). -include("thrift_macros.hrl"). -include("thrift_constants.hrl"). diff --git a/lib/erl/src/server/tErlServer.erl b/lib/erl/src/server/tErlServer.erl index 0e61e380..4e1f6fc5 100644 --- a/lib/erl/src/server/tErlServer.erl +++ b/lib/erl/src/server/tErlServer.erl @@ -69,7 +69,7 @@ effectful_serve(This) -> %% listen case gen_tcp:listen(Port, Options) of {ok, ListenSocket} -> - ?INFO(server_listening, {Port}), + ?INFO("thrift server listening on port ~p", [Port]), This1 = oop:set(This, listenSocket, ListenSocket), @@ -79,7 +79,7 @@ effectful_serve(This) -> {ok, This2}; {error, eaddrinuse} -> - error_logger:format("couldn't bind port ~p, address in use", [Port]), + ?ERROR("thrift couldn't bind port ~p, address in use", [Port]), {{error, eaddrinuse}, This} %% state before the accept end. @@ -111,7 +111,7 @@ catches(_This, _Pid, normal) -> %% {noreply,State}; %% %% terminate(Reason, State) -> %% -%% error_logger:info_msg( "Terminating error: ~p~n", [Reason]), % added %% +%% ?INFO( "Terminating error: ~p~n", [Reason]), % added %% %% gen_tcp:close(State#state.listen_socket), %% %% ok. %% %% %% diff --git a/lib/erl/src/thrift_logger.erl b/lib/erl/src/thrift_logger.erl index dee014b8..8528da37 100644 --- a/lib/erl/src/thrift_logger.erl +++ b/lib/erl/src/thrift_logger.erl @@ -71,6 +71,8 @@ init([]) -> {term_width, 80}, {force_one_line, false}, {omit, []}, + {omit_fmt, []}, + {show_pid, false}, {gen_server_messages, true}, {lookup, false} ], %% configuration before we try loading from file @@ -98,14 +100,18 @@ handle_event2(Symbol, Pid, Type, Message, State) -> % Message must be a string _ -> sformat("~p ", [Type]) end, - Banner = sformat("~s ~p ~s", [Symbol, Pid, Type1]), - BannerLen = length(Banner), - {Output, OutputSafe} = - try %% there's no way to see if Message is a string? just try - {sformat("~s", [Message]), - sformat("~s", [MessageSafe])} - catch X -> why_doesnt_this_work - end, + Banner = + case ?CONFIG(show_pid) of + true -> + sformat("~s ~s ~s", [Symbol, Pid, Type1]); + false -> + sformat("~s~i ~s", [Symbol, Pid, Type1]) + end, + BannerLen = length(Banner), + + %% there's no way to see if Message is a string? just try + Output = sformat("~s", [Message]), + OutputSafe = sformat("~s", [MessageSafe]), Length = case (length(OutputSafe) + BannerLen) < ?CONFIG(term_width) of @@ -179,9 +185,14 @@ handle_event1({What, _Gleader, {Ref, Format, Data}}, State) when is_list(Format) {?GS_TERM_FORMAT, _Dta} -> Message = sformat("DATA DIDN'T MATCH: ~p~n", [Data]) ++ sformat(Format, Data), handle_event2(Symbol, Ref, "", Message, State); - {_Fmt, _Dta} -> - Message = sformat(Format, Data), - handle_event2(Symbol, Ref, "", Message, State) + {_, _} -> + case lists:member(Format, ?CONFIG(omit_fmt)) of + false -> + Message = sformat(Format, Data), + handle_event2(Symbol, Ref, "", Message, State); + true -> + ok + end end, {ok, State}; @@ -194,22 +205,20 @@ handle_event1({What, _Gleader, {Pid, Type, Report}}, State) -> end, case Type of - {thrift_info, TI} -> - %% should we show it? - case not lists:member(TI, ?CONFIG(omit)) of - true -> - Message = handle_thrift_info(TI, Report, State), - handle_event2(Symbol, Pid, "", Message, State); - false -> - ok - end; - crash_report -> - %% [Cruft|_] = Report, %% - %% {value, {_, Reason}} = lists:keysearch(error_info, 1, Cruft), %% - %% {value, {_, {_, _, [_,_,_,_, Obj, []]}}} = lists:keysearch(initial_call, 1, Cruft), %% - %% sformat("state == ~s~nreason ==~s", [oop:inspect(Obj), oop:inspect(Reason)]), %% - ok; - progress -> + crash_report -> + case do_print_crash_report(Report) of + true -> + io:format("~~~~ crash report: '~p'~n", [Report]); + false -> + ok + end; +%% crash_report -> +%% [Cruft|_] = Report, +%% {value, {_, Reason}} = lists:keysearch(error_info, 1, Cruft), +%% {value, {_, {_, _, [_,_,_,_, Obj, []]}}} = lists:keysearch(initial_call, 1, Cruft), +%% sformat("state == ~s~nreason ==~s", [oop:inspect(Obj), oop:inspect(Reason)]), +%% ok; + progress -> ok; _ -> @@ -232,30 +241,6 @@ handle_event(Event, State) -> {ok, State} end. -%% thrift info handlers -handle_thrift_info(oop_new, {Args, Class, Object}, State) -> - %% arg Class can't come first! Then it'd look like a Class object - L = io_lib:format("~p:new(~s) = ~s", [Class, thrift_utils:unbrack(Args), oop:inspect(Object)]), - lists:flatten(L); - -handle_thrift_info(server_listening, {Port}, State) -> - sformat("server listening on port ~p", [Port]); - -handle_thrift_info(req_processed, {Value}, State) -> - sformat("request: ~p", [Value]); - -handle_thrift_info(conn_accepted, {AddrString}, State) -> - sformat("connection accepted from ~s", [AddrString]); - -handle_thrift_info(conn_timeout, {AddrString}, State) -> - sformat("connection timed out from ~s", [AddrString]); - -handle_thrift_info(conn_closed, {AddrString}, State) -> - sformat("connection closed from ~s", [AddrString]); - -handle_thrift_info(Else, Report, State) -> - sformat("~p ~s", [Else, oop:inspect(Report)]). - %%-------------------------------------------------------------------- %% @spec handle_call(Request, State) -> {ok, Reply, State} | %% {swap_handler, Reply, Args1, State1, @@ -348,3 +333,16 @@ config(Item, State) -> Else -> ?ERROR("config for ~p is unavailable: ~p", [Item, Else]) end. + +do_print_crash_report(Report) -> + case Report of + [[_,_,{error_info, XXX}|_] | _] -> + case thrift_utils:first_item(XXX) of + tTransportException -> + false; + _ -> + true + end; + _ -> + true + end. diff --git a/lib/erl/src/thrift_oop_server.erl b/lib/erl/src/thrift_oop_server.erl index c21c434d..57c4772a 100644 --- a/lib/erl/src/thrift_oop_server.erl +++ b/lib/erl/src/thrift_oop_server.erl @@ -76,7 +76,7 @@ init({Class, Args}) -> process_flag(trap_exit, true), try State = apply(Class, new, Args), - ?INFO(oop_new, {Args, Class, State}), + ?INFO("thrift ~p:new(~s) = ~s", [Class, thrift_utils:unbrack(Args), oop:inspect(State)]), {ok, State} catch E -> {stop, {new_failed, E}} diff --git a/lib/erl/src/thrift_utils.erl b/lib/erl/src/thrift_utils.erl index f78767c8..8305224a 100644 --- a/lib/erl/src/thrift_utils.erl +++ b/lib/erl/src/thrift_utils.erl @@ -35,18 +35,17 @@ unbrack(List) -> List1 = sformat("~w", [List]), string:substr(List1, 2, length(List1)-2). -first_item(DeepTuple) -> - case is_tuple(DeepTuple) of - true -> first_item(element(1, DeepTuple)); - false -> DeepTuple - end. +first_item(DeepTuple) when is_tuple(DeepTuple) -> + first_item(element(1, DeepTuple)); +first_item(NotTuple) -> + NotTuple. unnest_record(Term, RecordTag) -> case is_record(Term, RecordTag) of - true -> - {ok, Term}; - false when is_tuple(Term) -> - unnest_record(element(1, Term), RecordTag); - _ -> - error + true -> + {ok, Term}; + false when is_tuple(Term) -> + unnest_record(element(1, Term), RecordTag); + _ -> + error end. diff --git a/lib/erl/src/transport/tErlAcceptor.erl b/lib/erl/src/transport/tErlAcceptor.erl index f3308cf5..7586f607 100644 --- a/lib/erl/src/transport/tErlAcceptor.erl +++ b/lib/erl/src/transport/tErlAcceptor.erl @@ -72,7 +72,7 @@ accept(This, ListenSocket, GP, Handler) -> ?C0(ServerPid, effectful_new_acceptor), %% cast to create new acceptor AddrString = render_addr(Socket), - ?INFO(conn_accepted, {AddrString}), + ?INFO("thrift connection accepted from ~s", [AddrString]), %% start_new(tSocket, []) Client = oop:start_new(tSocket, []), @@ -91,9 +91,9 @@ accept(This, ListenSocket, GP, Handler) -> case receive_loop(This, Processor, Prot, Prot) of conn_timeout -> - ?INFO(conn_timeout, {AddrString}); + ?INFO("thrift connection timed out from ~s", [AddrString]); conn_closed -> - ?INFO(conn_closed, {AddrString}); + ?INFO("thrift connection closed from ~s", [AddrString]); {Class, Else} -> ?ERROR("unhandled ~p in tErlAcceptor: ~p", [Class, Else]) end, @@ -108,10 +108,10 @@ receive_loop(This, Processor, Iprot, Oprot) -> try ?R2(Processor, process, Iprot, Oprot) of {error, TAE} when is_record(TAE, tApplicationException), TAE#tApplicationException.type == ?tApplicationException_HANDLER_ERROR -> - ?ERROR("handler returned an error: ~p", [oop:get(TAE, message)]), + ?ERROR("thrift handler returned an error: ~p", [oop:get(TAE, message)]), receive_loop(This, Processor, Iprot, Oprot); Value -> - ?INFO(req_processed, {Value}), + ?INFO("thrift request: ~p", [Value]), receive_loop(This, Processor, Iprot, Oprot) catch exit:{timeout, _} ->