path: root/src/cowboy_http.erl
diff options
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 /src/cowboy_http.erl
parent16143354361651cc7c14b81595760118efce8870 (diff)
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.
Diffstat (limited to 'src/cowboy_http.erl')
1 files changed, 31 insertions, 24 deletions
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)
%% 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{
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.'})
@@ -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),
-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) ->
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.'})
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),
@@ -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.
@@ -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
-stream_call_terminate(StreamID, Reason, StreamState) ->
+stream_call_terminate(StreamID, Reason, StreamState, #state{opts=Opts}) ->
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)
%% @todo max_reqs also
@@ -1298,9 +1305,9 @@ early_error(StatusCode0, #state{socket=Socket, transport=Transport,
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),
exit({shutdown, Reason}).
-terminate_all_streams([], _) ->
+terminate_all_streams(_, [], _) ->
-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