aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorLoïc Hoguin <[email protected]>2018-06-28 17:10:18 +0200
committerLoïc Hoguin <[email protected]>2018-06-28 17:10:18 +0200
commita76c32db5e32ab6a6b35ce6625cb3aedcac067b6 (patch)
tree745b39ea422a946108cb406d1fbcd3ece678ec39
parent16143354361651cc7c14b81595760118efce8870 (diff)
downloadcowboy-a76c32db5e32ab6a6b35ce6625cb3aedcac067b6.tar.gz
cowboy-a76c32db5e32ab6a6b35ce6625cb3aedcac067b6.tar.bz2
cowboy-a76c32db5e32ab6a6b35ce6625cb3aedcac067b6.zip
Introduce undocumented option logger
This commit reworks the logging that Cowboy does via error_logger to make the module that will do the actual logging configurable. The logger module interface must be the same as logger and lager: a separate function per log level with the same log levels they support. The default behavior remains to call error_logger, although some messages were downgraded to warnings instead of errors. Since error_logger only supports three different log levels, some messages may get downgraded/upgraded depending on what the original log level was to make them compatible with error_logger. The {log, Level, Format, Args} command was also added to stream handlers. Stream handlers should use this command to log messages because it allows writing a stream handler to intercept some of those messages and extract information or block them as necessary. The logger option only applies to Cowboy itself, not to the messages Ranch logs, so more work remains to be done in that area.
-rw-r--r--doc/src/manual/cowboy_stream.asciidoc5
-rw-r--r--src/cowboy.erl31
-rw-r--r--src/cowboy_http.erl55
-rw-r--r--src/cowboy_http2.erl71
-rw-r--r--src/cowboy_stream.erl43
-rw-r--r--src/cowboy_stream_h.erl37
-rw-r--r--src/cowboy_tracer_h.erl28
7 files changed, 152 insertions, 118 deletions
diff --git a/doc/src/manual/cowboy_stream.asciidoc b/doc/src/manual/cowboy_stream.asciidoc
index 0207ad8..763cbd5 100644
--- a/doc/src/manual/cowboy_stream.asciidoc
+++ b/doc/src/manual/cowboy_stream.asciidoc
@@ -81,9 +81,8 @@ Stream handlers can return a list of commands to be executed
from the `init/3`, `data/4` and `info/3` callbacks. In addition,
the `early_error/5` callback must return a response command.
-// @todo We need a 'log' command that would call error_logger.
-// It's better than doing in the handlers directly because
-// then we can have other stream handlers manipulate those logs.
+// @todo The logger option and the {log, Level, Format, Args}
+// options need to be documented and tested.
The following commands are defined:
diff --git a/src/cowboy.erl b/src/cowboy.erl
index 99615de..0230f07 100644
--- a/src/cowboy.erl
+++ b/src/cowboy.erl
@@ -19,6 +19,10 @@
-export([stop_listener/1]).
-export([set_env/3]).
+%% Internal.
+-export([log/2]).
+-export([log/4]).
+
%% @todo Detailed opts.
-type opts() :: map().
-export_type([opts/0]).
@@ -71,3 +75,30 @@ set_env(Ref, Name, Value) ->
Env = maps:get(env, Opts, #{}),
Opts2 = maps:put(env, maps:put(Name, Value, Env), Opts),
ok = ranch:set_protocol_options(Ref, Opts2).
+
+%% Internal.
+
+-spec log({log, logger:level(), io:format(), list()}, opts()) -> ok.
+log({log, Level, Format, Args}, Opts) ->
+ log(Level, Format, Args, Opts).
+
+-spec log(logger:level(), io:format(), list(), opts()) -> ok.
+log(Level, Format, Args, #{logger := Logger})
+ when Logger =/= error_logger ->
+ _ = Logger:Level(Format, Args),
+ ok;
+%% We use error_logger by default. Because error_logger does
+%% not have all the levels we accept we have to do some
+%% mapping to error_logger functions.
+log(Level, Format, Args, _) ->
+ Function = case Level of
+ emergency -> error_msg;
+ alert -> error_msg;
+ critical -> error_msg;
+ error -> error_msg;
+ warning -> warning_msg;
+ notice -> warning_msg;
+ info -> info_msg;
+ debug -> info_msg
+ end,
+ error_logger:Function(Format, Args).
diff --git a/src/cowboy_http.erl b/src/cowboy_http.erl
index 818a88a..e1af0e9 100644
--- a/src/cowboy_http.erl
+++ b/src/cowboy_http.erl
@@ -30,6 +30,7 @@
idle_timeout => timeout(),
inactivity_timeout => timeout(),
linger_timeout => timeout(),
+ logger => module(),
max_authority_length => non_neg_integer(),
max_empty_lines => non_neg_integer(),
max_header_name_length => non_neg_integer(),
@@ -224,7 +225,7 @@ loop(State=#state{parent=Parent, socket=Socket, transport=Transport, opts=Opts,
loop(State, Buffer);
%% Unknown messages.
Msg ->
- error_logger:error_msg("Received stray message ~p.~n", [Msg]),
+ cowboy:log(warning, "Received stray message ~p.~n", [Msg], Opts),
loop(State, Buffer)
after InactivityTimeout ->
terminate(State, {internal_error, timeout, 'No message or data received before timeout.'})
@@ -300,16 +301,16 @@ after_parse({request, Req=#{streamid := StreamID, method := Method,
State = set_timeout(State1),
parse(Buffer, commands(State, StreamID, Commands))
catch Class:Exception ->
- cowboy_stream:report_error(init,
+ cowboy:log(cowboy_stream:make_error_log(init,
[StreamID, Req, Opts],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
early_error(500, State0, {internal_error, {Class, Exception},
'Unhandled exception in cowboy_stream:init/3.'}, Req),
parse(Buffer, State0)
end;
%% Streams are sequential so the body is always about the last stream created
%% unless that stream has terminated.
-after_parse({data, StreamID, IsFin, Data, State=#state{
+after_parse({data, StreamID, IsFin, Data, State=#state{opts=Opts,
streams=Streams0=[Stream=#stream{id=StreamID, state=StreamState0}|_]}, Buffer}) ->
try cowboy_stream:data(StreamID, IsFin, Data, StreamState0) of
{Commands, StreamState} ->
@@ -317,9 +318,9 @@ after_parse({data, StreamID, IsFin, Data, State=#state{
Stream#stream{state=StreamState}),
parse(Buffer, commands(State#state{streams=Streams}, StreamID, Commands))
catch Class:Exception ->
- cowboy_stream:report_error(data,
+ cowboy:log(cowboy_stream:make_error_log(data,
[StreamID, IsFin, Data, StreamState0],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
stream_reset(State, StreamID, {internal_error, {Class, Exception},
'Unhandled exception in cowboy_stream:data/4.'})
end;
@@ -821,7 +822,7 @@ parse_body(Buffer, State=#state{in_streamid=StreamID, in_state=
%% Message handling.
-down(State=#state{children=Children0}, Pid, Msg) ->
+down(State=#state{opts=Opts, children=Children0}, Pid, Msg) ->
case cowboy_children:down(Children0, Pid) of
%% The stream was terminated already.
{ok, undefined, Children} ->
@@ -831,11 +832,12 @@ down(State=#state{children=Children0}, Pid, Msg) ->
info(State#state{children=Children}, StreamID, Msg);
%% The process was unknown.
error ->
- error_logger:error_msg("Received EXIT signal ~p for unknown process ~p.~n", [Msg, Pid]),
+ cowboy:log(warning, "Received EXIT signal ~p for unknown process ~p.~n",
+ [Msg, Pid], Opts),
State
end.
-info(State=#state{streams=Streams0}, StreamID, Msg) ->
+info(State=#state{opts=Opts, streams=Streams0}, StreamID, Msg) ->
case lists:keyfind(StreamID, #stream.id, Streams0) of
Stream = #stream{state=StreamState0} ->
try cowboy_stream:info(StreamID, Msg, StreamState0) of
@@ -844,14 +846,15 @@ info(State=#state{streams=Streams0}, StreamID, Msg) ->
Stream#stream{state=StreamState}),
commands(State#state{streams=Streams}, StreamID, Commands)
catch Class:Exception ->
- cowboy_stream:report_error(info,
+ cowboy:log(cowboy_stream:make_error_log(info,
[StreamID, Msg, StreamState0],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
stream_reset(State, StreamID, {internal_error, {Class, Exception},
'Unhandled exception in cowboy_stream:info/3.'})
end;
false ->
- error_logger:error_msg("Received message ~p for unknown stream ~p.~n", [Msg, StreamID]),
+ cowboy:log(warning, "Received message ~p for unknown stream ~p.~n",
+ [Msg, StreamID], Opts),
State
end.
@@ -1077,7 +1080,7 @@ commands(State0=#state{ref=Ref, parent=Parent, socket=Socket, transport=Transpor
#state{streams=Streams} = info(State, StreamID, {inform, 101, Headers}),
#stream{state=StreamState} = lists:keyfind(StreamID, #stream.id, Streams),
%% @todo We need to shutdown processes here first.
- stream_call_terminate(StreamID, switch_protocol, StreamState),
+ stream_call_terminate(StreamID, switch_protocol, StreamState, State),
%% Terminate children processes and flush any remaining messages from the mailbox.
cowboy_children:terminate(Children),
flush(Parent),
@@ -1095,6 +1098,10 @@ commands(State, StreamID, [stop|Tail]) ->
%% the next request concurrently. This can be done as a
%% future optimization.
maybe_terminate(State, StreamID, Tail);
+%% Log event.
+commands(State=#state{opts=Opts}, StreamID, [Log={log, _, _, _}|Tail]) ->
+ cowboy:log(Log, Opts),
+ commands(State, StreamID, Tail);
%% HTTP/1.1 does not support push; ignore.
commands(State, StreamID, [{push, _, _, _, _, _, _, _}|Tail]) ->
commands(State, StreamID, Tail).
@@ -1160,7 +1167,7 @@ stream_terminate(State0=#state{opts=Opts, in_streamid=InStreamID, in_state=InSta
= lists:keytake(StreamID, #stream.id, Streams1),
State2 = State1#state{streams=Streams},
%% Stop the stream.
- stream_call_terminate(StreamID, Reason, StreamState),
+ stream_call_terminate(StreamID, Reason, StreamState, State2),
Children = cowboy_children:shutdown(Children0, StreamID),
%% We reset the timeout if there are no active streams anymore.
State = case Streams of
@@ -1195,13 +1202,13 @@ stream_terminate(State0=#state{opts=Opts, in_streamid=InStreamID, in_state=InSta
end
end.
-stream_call_terminate(StreamID, Reason, StreamState) ->
+stream_call_terminate(StreamID, Reason, StreamState, #state{opts=Opts}) ->
try
cowboy_stream:terminate(StreamID, Reason, StreamState)
catch Class:Exception ->
- cowboy_stream:report_error(terminate,
+ cowboy:log(cowboy_stream:make_error_log(terminate,
[StreamID, Reason, StreamState],
- Class, Exception, erlang:get_stacktrace())
+ Class, Exception, erlang:get_stacktrace()), Opts)
end.
%% @todo max_reqs also
@@ -1298,9 +1305,9 @@ early_error(StatusCode0, #state{socket=Socket, transport=Transport,
RespBody
])
catch Class:Exception ->
- cowboy_stream:report_error(early_error,
+ cowboy:log(cowboy_stream:make_error_log(early_error,
[StreamID, Reason, PartialReq, Resp, Opts],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
%% We still need to send an error response, so send what we initially
%% wanted to send. It's better than nothing.
Transport:send(Socket, cow_http:response(StatusCode0,
@@ -1312,16 +1319,16 @@ early_error(StatusCode0, #state{socket=Socket, transport=Transport,
terminate(undefined, Reason) ->
exit({shutdown, Reason});
terminate(State=#state{streams=Streams, children=Children}, Reason) ->
- terminate_all_streams(Streams, Reason),
+ terminate_all_streams(State, Streams, Reason),
cowboy_children:terminate(Children),
terminate_linger(State),
exit({shutdown, Reason}).
-terminate_all_streams([], _) ->
+terminate_all_streams(_, [], _) ->
ok;
-terminate_all_streams([#stream{id=StreamID, state=StreamState}|Tail], Reason) ->
- stream_call_terminate(StreamID, Reason, StreamState),
- terminate_all_streams(Tail, Reason).
+terminate_all_streams(State, [#stream{id=StreamID, state=StreamState}|Tail], Reason) ->
+ stream_call_terminate(StreamID, Reason, StreamState, State),
+ terminate_all_streams(State, Tail, Reason).
terminate_linger(State=#state{socket=Socket, transport=Transport, opts=Opts}) ->
case Transport:shutdown(Socket, write) of
diff --git a/src/cowboy_http2.erl b/src/cowboy_http2.erl
index 70a5e46..c2686aa 100644
--- a/src/cowboy_http2.erl
+++ b/src/cowboy_http2.erl
@@ -311,7 +311,7 @@ loop(State=#state{parent=Parent, socket=Socket, transport=Transport,
cowboy_children:handle_supervisor_call(Call, From, Children, ?MODULE),
loop(State, Buffer);
Msg ->
- error_logger:error_msg("Received stray message ~p.", [Msg]),
+ cowboy:log(warning, "Received stray message ~p.", [Msg], Opts),
loop(State, Buffer)
after InactivityTimeout ->
terminate(State, {internal_error, timeout, 'No message or data received before timeout.'})
@@ -567,14 +567,15 @@ data_frame(State, Stream0=#stream{id=StreamID, remote_window=StreamWindow,
%% We ignore DATA frames for streams that are flushing out data.
data_frame(State, Stream=#stream{state=flush}, _, _) ->
after_commands(State, Stream);
-data_frame(State, Stream=#stream{id=StreamID, state=StreamState0}, IsFin, Data) ->
+data_frame(State=#state{opts=Opts}, Stream=#stream{id=StreamID, state=StreamState0},
+ IsFin, Data) ->
try cowboy_stream:data(StreamID, IsFin, Data, StreamState0) of
{Commands, StreamState} ->
commands(State, Stream#stream{state=StreamState}, Commands)
catch Class:Exception ->
- cowboy_stream:report_error(data,
+ cowboy:log(cowboy_stream:make_error_log(data,
[StreamID, IsFin, Data, StreamState0],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
stream_reset(State, StreamID, {internal_error, {Class, Exception},
'Unhandled exception in cowboy_stream:data/4.'})
end.
@@ -614,7 +615,7 @@ continuation_frame(State, _) ->
terminate(State, {connection_error, protocol_error,
'An invalid frame was received in the middle of a header block. (RFC7540 6.2)'}).
-down(State=#state{children=Children0}, Pid, Msg) ->
+down(State=#state{opts=Opts, children=Children0}, Pid, Msg) ->
case cowboy_children:down(Children0, Pid) of
%% The stream was terminated already.
{ok, undefined, Children} ->
@@ -624,23 +625,25 @@ down(State=#state{children=Children0}, Pid, Msg) ->
info(State#state{children=Children}, StreamID, Msg);
%% The process was unknown.
error ->
- error_logger:error_msg("Received EXIT signal ~p for unknown process ~p.~n", [Msg, Pid]),
+ cowboy:log(warning, "Received EXIT signal ~p for unknown process ~p.~n",
+ [Msg, Pid], Opts),
State
end.
-info(State=#state{client_streamid=LastStreamID, streams=Streams}, StreamID, Msg) ->
+info(State=#state{opts=Opts, client_streamid=LastStreamID, streams=Streams}, StreamID, Msg) ->
case lists:keyfind(StreamID, #stream.id, Streams) of
#stream{state=flush} ->
- error_logger:error_msg("Received message ~p for terminated stream ~p.", [Msg, StreamID]),
+ cowboy:log(warning, "Received message ~p for terminated stream ~p.",
+ [Msg, StreamID], Opts),
State;
Stream = #stream{state=StreamState0} ->
try cowboy_stream:info(StreamID, Msg, StreamState0) of
{Commands, StreamState} ->
commands(State, Stream#stream{state=StreamState}, Commands)
catch Class:Exception ->
- cowboy_stream:report_error(info,
+ cowboy:log(cowboy_stream:make_error_log(info,
[StreamID, Msg, StreamState0],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
stream_reset(State, StreamID, {internal_error, {Class, Exception},
'Unhandled exception in cowboy_stream:info/3.'})
end;
@@ -650,8 +653,8 @@ info(State=#state{client_streamid=LastStreamID, streams=Streams}, StreamID, Msg)
%% around. In these cases we do not want to log anything.
State;
false ->
- error_logger:error_msg("Received message ~p for unknown stream ~p.",
- [Msg, StreamID]),
+ cowboy:log(warning, "Received message ~p for unknown stream ~p.",
+ [Msg, StreamID], Opts),
State
end.
@@ -782,7 +785,11 @@ commands(State0, #stream{id=StreamID}, [{switch_protocol, Headers, _Mod, _ModSta
commands(State, Stream=#stream{id=StreamID}, [stop|_Tail]) ->
%% @todo Do we want to run the commands after a stop?
%% @todo Do we even allow commands after?
- stream_terminate(after_commands(State, Stream), StreamID, normal).
+ stream_terminate(after_commands(State, Stream), StreamID, normal);
+%% Log event.
+commands(State=#state{opts=Opts}, StreamID, [Log={log, _, _, _}|Tail]) ->
+ cowboy:log(Log, Opts),
+ commands(State, StreamID, Tail).
after_commands(State=#state{streams=Streams0}, Stream=#stream{id=StreamID}) ->
Streams = lists:keystore(StreamID, #stream.id, Streams0, Stream),
@@ -952,12 +959,12 @@ terminate(undefined, Reason) ->
terminate(#state{socket=Socket, transport=Transport, parse_state={preface, _, _}}, Reason) ->
Transport:close(Socket),
exit({shutdown, Reason});
-terminate(#state{socket=Socket, transport=Transport, client_streamid=LastStreamID,
+terminate(State=#state{socket=Socket, transport=Transport, client_streamid=LastStreamID,
streams=Streams, children=Children}, Reason) ->
%% @todo We might want to optionally send the Reason value
%% as debug data in the GOAWAY frame here. Perhaps more.
Transport:send(Socket, cow_http2:goaway(LastStreamID, terminate_reason(Reason), <<>>)),
- terminate_all_streams(Streams, Reason),
+ terminate_all_streams(State, Streams, Reason),
cowboy_children:terminate(Children),
Transport:close(Socket),
exit({shutdown, Reason}).
@@ -967,14 +974,14 @@ terminate_reason({stop, _, _}) -> no_error;
terminate_reason({socket_error, _, _}) -> internal_error;
terminate_reason({internal_error, _, _}) -> internal_error.
-terminate_all_streams([], _) ->
+terminate_all_streams(_, [], _) ->
ok;
%% This stream was already terminated and is now just flushing the data out. Skip it.
-terminate_all_streams([#stream{state=flush}|Tail], Reason) ->
- terminate_all_streams(Tail, Reason);
-terminate_all_streams([#stream{id=StreamID, state=StreamState}|Tail], Reason) ->
- stream_call_terminate(StreamID, Reason, StreamState),
- terminate_all_streams(Tail, Reason).
+terminate_all_streams(State, [#stream{state=flush}|Tail], Reason) ->
+ terminate_all_streams(State, Tail, Reason);
+terminate_all_streams(State, [#stream{id=StreamID, state=StreamState}|Tail], Reason) ->
+ stream_call_terminate(StreamID, Reason, StreamState, State),
+ terminate_all_streams(State, Tail, Reason).
%% Stream functions.
@@ -1214,9 +1221,9 @@ stream_early_error(State0=#state{ref=Ref, opts=Opts, peer=Peer,
State#state{streams=[Stream|Streams]}
end
catch Class:Exception ->
- cowboy_stream:report_error(early_error,
+ cowboy:log(cowboy_stream:make_error_log(early_error,
[StreamID, Reason, PartialReq, Resp, Opts],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
%% We still need to send an error response, so send what we initially
%% wanted to send. It's better than nothing.
send_headers(State0, Stream0, StatusCode0, RespHeaders0, fin)
@@ -1237,9 +1244,9 @@ stream_handler_init(State=#state{opts=Opts,
te=maps:get(<<"te">>, Headers, undefined)},
Commands)
catch Class:Exception ->
- cowboy_stream:report_error(init,
+ cowboy:log(cowboy_stream:make_error_log(init,
[StreamID, Req, Opts],
- Class, Exception, erlang:get_stacktrace()),
+ Class, Exception, erlang:get_stacktrace()), Opts),
stream_reset(State, StreamID, {internal_error, {Class, Exception},
'Unhandled exception in cowboy_stream:init/3.'})
end.
@@ -1308,7 +1315,7 @@ stream_terminate(State0=#state{streams=Streams0, children=Children0}, StreamID,
State1 = #state{streams=Streams1} = info(State0, StreamID, {response, 204, #{}, <<>>}),
State = maybe_skip_body(State1, Stream, Reason),
#stream{state=StreamState} = lists:keyfind(StreamID, #stream.id, Streams1),
- stream_call_terminate(StreamID, Reason, StreamState),
+ stream_call_terminate(StreamID, Reason, StreamState, State),
Children = cowboy_children:shutdown(Children0, StreamID),
State#state{streams=Streams, children=Children};
%% When a response was sent but not terminated, we need to close the stream.
@@ -1317,7 +1324,7 @@ stream_terminate(State0=#state{streams=Streams0, children=Children0}, StreamID,
State1 = #state{streams=Streams1} = info(State0, StreamID, {data, fin, <<>>}),
State = maybe_skip_body(State1, Stream, Reason),
#stream{state=StreamState} = lists:keyfind(StreamID, #stream.id, Streams1),
- stream_call_terminate(StreamID, Reason, StreamState),
+ stream_call_terminate(StreamID, Reason, StreamState, State),
Children = cowboy_children:shutdown(Children0, StreamID),
State#state{streams=Streams, children=Children};
%% Unless there is still data in the buffer. We can however reset
@@ -1327,14 +1334,14 @@ stream_terminate(State0=#state{streams=Streams0, children=Children0}, StreamID,
%% because we are still sending data via the buffer. We will
%% reset the stream if necessary once the buffer is empty.
{value, Stream=#stream{state=StreamState, local=nofin}, Streams} ->
- stream_call_terminate(StreamID, Reason, StreamState),
+ stream_call_terminate(StreamID, Reason, StreamState, State0),
Children = cowboy_children:shutdown(Children0, StreamID),
State0#state{streams=[Stream#stream{state=flush, local=flush}|Streams],
children=Children};
%% Otherwise we sent or received an RST_STREAM and/or the stream is already closed.
{value, Stream=#stream{state=StreamState}, Streams} ->
State = maybe_skip_body(State0, Stream, Reason),
- stream_call_terminate(StreamID, Reason, StreamState),
+ stream_call_terminate(StreamID, Reason, StreamState, State),
Children = cowboy_children:shutdown(Children0, StreamID),
State#state{streams=Streams, children=Children};
%% The stream doesn't exist. This can occur for various reasons.
@@ -1355,13 +1362,13 @@ maybe_skip_body(State=#state{socket=Socket, transport=Transport},
maybe_skip_body(State, _, _) ->
State.
-stream_call_terminate(StreamID, Reason, StreamState) ->
+stream_call_terminate(StreamID, Reason, StreamState, #state{opts=Opts}) ->
try
cowboy_stream:terminate(StreamID, Reason, StreamState)
catch Class:Exception ->
- cowboy_stream:report_error(terminate,
+ cowboy:log(cowboy_stream:make_error_log(terminate,
[StreamID, Reason, StreamState],
- Class, Exception, erlang:get_stacktrace())
+ Class, Exception, erlang:get_stacktrace()), Opts)
end.
%% System callbacks.
diff --git a/src/cowboy_stream.erl b/src/cowboy_stream.erl
index 1a1031e..6776863 100644
--- a/src/cowboy_stream.erl
+++ b/src/cowboy_stream.erl
@@ -78,7 +78,7 @@
-export([info/3]).
-export([terminate/3]).
-export([early_error/5]).
--export([report_error/5]).
+-export([make_error_log/5]).
%% Note that this and other functions in this module do NOT catch
%% exceptions. We want the exception to go all the way down to the
@@ -148,47 +148,44 @@ early_error(StreamID, Reason, PartialReq, Resp, Opts) ->
PartialReq, Resp, Opts#{stream_handlers => Tail})
end.
--spec report_error(atom(), list(), error | exit | throw, any(), list()) -> ok.
-report_error(init, [StreamID, Req, Opts], Class, Exception, Stacktrace) ->
- error_logger:error_msg(
+-spec make_error_log(init | data | info | terminate | early_error,
+ list(), error | exit | throw, any(), list())
+ -> {log, error, string(), list()}.
+make_error_log(init, [StreamID, Req, Opts], Class, Exception, Stacktrace) ->
+ {log, error,
"Unhandled exception ~p:~p in cowboy_stream:init(~p, Req, Opts)~n"
"Stacktrace: ~p~n"
"Req: ~p~n"
"Opts: ~p~n",
- [Class, Exception, StreamID, Stacktrace, Req, Opts]);
-report_error(data, [StreamID, IsFin, Data, State], Class, Exception, Stacktrace) ->
- error_logger:error_msg(
+ [Class, Exception, StreamID, Stacktrace, Req, Opts]};
+make_error_log(data, [StreamID, IsFin, Data, State], Class, Exception, Stacktrace) ->
+ {log, error,
"Unhandled exception ~p:~p in cowboy_stream:data(~p, ~p, Data, State)~n"
"Stacktrace: ~p~n"
"Data: ~p~n"
"State: ~p~n",
- [Class, Exception, StreamID, IsFin, Stacktrace, Data, State]);
-report_error(info, [StreamID, Msg, State], Class, Exception, Stacktrace) ->
- error_logger:error_msg(
+ [Class, Exception, StreamID, IsFin, Stacktrace, Data, State]};
+make_error_log(info, [StreamID, Msg, State], Class, Exception, Stacktrace) ->
+ {log, error,
"Unhandled exception ~p:~p in cowboy_stream:info(~p, Msg, State)~n"
"Stacktrace: ~p~n"
"Msg: ~p~n"
"State: ~p~n",
- [Class, Exception, StreamID, Stacktrace, Msg, State]);
-report_error(terminate, [StreamID, Reason, State], Class, Exception, Stacktrace) ->
- error_logger:error_msg(
+ [Class, Exception, StreamID, Stacktrace, Msg, State]};
+make_error_log(terminate, [StreamID, Reason, State], Class, Exception, Stacktrace) ->
+ {log, error,
"Unhandled exception ~p:~p in cowboy_stream:terminate(~p, Reason, State)~n"
"Stacktrace: ~p~n"
"Reason: ~p~n"
"State: ~p~n",
- [Class, Exception, StreamID, Stacktrace, Reason, State]);
-report_error(early_error, [StreamID, Reason, PartialReq, Resp, Opts], Class, Exception, Stacktrace) ->
- error_logger:error_msg(
+ [Class, Exception, StreamID, Stacktrace, Reason, State]};
+make_error_log(early_error, [StreamID, Reason, PartialReq, Resp, Opts],
+ Class, Exception, Stacktrace) ->
+ {log, error,
"Unhandled exception ~p:~p in cowboy_stream:early_error(~p, Reason, PartialReq, Resp, Opts)~n"
"Stacktrace: ~p~n"
"Reason: ~p~n"
"PartialReq: ~p~n"
"Resp: ~p~n"
"Opts: ~p~n",
- [Class, Exception, StreamID, Stacktrace, Reason, PartialReq, Resp, Opts]);
-report_error(Callback, _, Class, Reason, Stacktrace) ->
- error_logger:error_msg(
- "Exception occurred in unknown callback ~p~n"
- "Reason: ~p:~p~n"
- "Stacktrace: ~p~n",
- [Callback, Class, Reason, Stacktrace]).
+ [Class, Exception, StreamID, Stacktrace, Reason, PartialReq, Resp, Opts]}.
diff --git a/src/cowboy_stream_h.erl b/src/cowboy_stream_h.erl
index 21651f7..55a1ca2 100644
--- a/src/cowboy_stream_h.erl
+++ b/src/cowboy_stream_h.erl
@@ -134,24 +134,32 @@ info(StreamID, Info={'EXIT', Pid, normal}, State=#state{pid=Pid}) ->
do_info(StreamID, Info, [stop], State);
info(StreamID, Info={'EXIT', Pid, {{request_error, Reason, _HumanReadable}, _}},
State=#state{pid=Pid}) ->
- %% @todo Optionally report the crash to help debugging.
- %%report_crash(Ref, StreamID, Pid, Reason, Stacktrace),
Status = case Reason of
timeout -> 408;
payload_too_large -> 413;
_ -> 400
end,
- %% @todo Headers? Details in body? More stuff in debug only?
+ %% @todo Headers? Details in body? Log the crash? More stuff in debug only?
do_info(StreamID, Info, [
{error_response, Status, #{<<"content-length">> => <<"0">>}, <<>>},
stop
], State);
info(StreamID, Exit={'EXIT', Pid, {Reason, Stacktrace}}, State=#state{ref=Ref, pid=Pid}) ->
- report_crash(Ref, StreamID, Pid, Reason, Stacktrace),
+ Commands0 = [{internal_error, Exit, 'Stream process crashed.'}],
+ Commands = case Reason of
+ normal -> Commands0;
+ shutdown -> Commands0;
+ {shutdown, _} -> Commands0;
+ _ -> [{log, error,
+ "Ranch listener ~p, connection process ~p, stream ~p "
+ "had its request process ~p exit with reason "
+ "~999999p and stacktrace ~999999p~n",
+ [Ref, self(), StreamID, Pid, Reason, Stacktrace]}
+ |Commands0]
+ end,
do_info(StreamID, Exit, [
- {error_response, 500, #{<<"content-length">> => <<"0">>}, <<>>},
- {internal_error, Exit, 'Stream process crashed.'}
- ], State);
+ {error_response, 500, #{<<"content-length">> => <<"0">>}, <<>>}
+ |Commands], State);
%% Request body, auto mode, no body buffered.
info(StreamID, Info={read_body, Ref, auto, infinity}, State=#state{read_body_buffer= <<>>}) ->
do_info(StreamID, Info, [], State#state{
@@ -244,21 +252,6 @@ send_request_body(Pid, Ref, fin, BodyLen, Data) ->
Pid ! {request_body, Ref, fin, BodyLen, Data},
ok.
-%% We use ~999999p here instead of ~w because the latter doesn't
-%% support printable strings.
-report_crash(_, _, _, normal, _) ->
- ok;
-report_crash(_, _, _, shutdown, _) ->
- ok;
-report_crash(_, _, _, {shutdown, _}, _) ->
- ok;
-report_crash(Ref, StreamID, Pid, Reason, Stacktrace) ->
- error_logger:error_msg(
- "Ranch listener ~p, connection process ~p, stream ~p "
- "had its request process ~p exit with reason "
- "~999999p and stacktrace ~999999p~n",
- [Ref, self(), StreamID, Pid, Reason, Stacktrace]).
-
%% Request process.
%% We catch all exceptions in order to add the stacktrace to
diff --git a/src/cowboy_tracer_h.erl b/src/cowboy_tracer_h.erl
index 932653b..bbe10a1 100644
--- a/src/cowboy_tracer_h.erl
+++ b/src/cowboy_tracer_h.erl
@@ -152,37 +152,37 @@ tracer_process(StreamID, Req=#{pid := Parent}, Opts=#{tracer_callback := Fun}) -
%% before it has finished processing the events in its queue.
process_flag(trap_exit, true),
State = Fun(init, {StreamID, Req, Opts}),
- tracer_loop(Parent, Fun, State).
+ tracer_loop(Parent, Opts, State).
-tracer_loop(Parent, Fun, State0) ->
+tracer_loop(Parent, Opts=#{tracer_callback := Fun}, State0) ->
receive
Msg when element(1, Msg) =:= trace_ts ->
State = Fun(Msg, State0),
- tracer_loop(Parent, Fun, State);
+ tracer_loop(Parent, Opts, State);
{'EXIT', Parent, Reason} ->
- tracer_terminate(Reason, Fun, State0);
+ tracer_terminate(Reason, Opts, State0);
{system, From, Request} ->
- sys:handle_system_msg(Request, From, Parent, ?MODULE, [], {Fun, State0});
+ sys:handle_system_msg(Request, From, Parent, ?MODULE, [], {Opts, State0});
Msg ->
- error_logger:error_msg("~p: Tracer process received stray message ~9999p~n",
- [?MODULE, Msg]),
- tracer_loop(Parent, Fun, State0)
+ cowboy:log(warning, "~p: Tracer process received stray message ~9999p~n",
+ [?MODULE, Msg], Opts),
+ tracer_loop(Parent, Opts, State0)
end.
-spec tracer_terminate(_, _, _) -> no_return().
-tracer_terminate(Reason, Fun, State) ->
+tracer_terminate(Reason, #{tracer_callback := Fun}, State) ->
_ = Fun(terminate, State),
exit(Reason).
%% System callbacks.
--spec system_continue(pid(), _, {fun(), any()}) -> no_return().
-system_continue(Parent, _, {Fun, State}) ->
- tracer_loop(Parent, Fun, State).
+-spec system_continue(pid(), _, {cowboy:opts(), any()}) -> no_return().
+system_continue(Parent, _, {Opts, State}) ->
+ tracer_loop(Parent, Opts, State).
-spec system_terminate(any(), _, _, _) -> no_return().
-system_terminate(Reason, _, _, {Fun, State}) ->
- tracer_terminate(Reason, Fun, State).
+system_terminate(Reason, _, _, {Opts, State}) ->
+ tracer_terminate(Reason, Opts, State).
-spec system_code_change(Misc, _, _, _) -> {ok, Misc} when Misc::any().
system_code_change(Misc, _, _, _) ->