Browse Source

Add a logger transport option

I had to use the process dictionary to work around the current
interface for one log call. You have been warned.
Loïc Hoguin 7 years ago
parent
commit
8759b87a29
5 changed files with 109 additions and 47 deletions
  1. 35 4
      src/ranch.erl
  2. 16 14
      src/ranch_acceptor.erl
  3. 18 9
      src/ranch_acceptors_sup.erl
  4. 23 20
      src/ranch_conns_sup.erl
  5. 17 0
      test/acceptor_SUITE.erl

+ 35 - 4
src/ranch.erl

@@ -42,6 +42,7 @@
 -export([filter_options/3]).
 -export([set_option_default/3]).
 -export([require/1]).
+-export([log/4]).
 
 -deprecated([start_listener/6, child_spec/6, accept_ack/1]).
 
@@ -61,6 +62,7 @@
 	connection_type => worker | supervisor,
 	handshake_timeout => timeout(),
 	max_connections => max_conns(),
+	logger => module(),
 	num_acceptors => pos_integer(),
 	shutdown => timeout() | brutal_kill,
 	socket => any(),
@@ -134,11 +136,11 @@ normalize_opts(List0) when is_list(List0) ->
 		Map =:= #{} ->
 			ok;
 		true ->
-			%% @todo This needs a test.
-			error_logger:warning_msg(
+			log(warning,
 				"Setting Ranch options together with socket options "
 				"is deprecated. Please use the new map syntax that allows "
-				"specifying socket options separately from other options.~n")
+				"specifying socket options separately from other options.~n",
+				[], Map)
 	end,
 	case List of
 		[] -> Map;
@@ -433,7 +435,13 @@ filter_user_options([], _) ->
 	[].
 
 filter_options_warning(Opt) ->
-	error_logger:warning_msg("Transport option ~p unknown or invalid.~n", [Opt]).
+	Logger = case get(logger) of
+		undefined -> error_logger;
+		Logger0 -> Logger0
+	end,
+	log(warning,
+		"Transport option ~p unknown or invalid.~n",
+		[Opt], Logger).
 
 merge_options({Key, _} = Option, OptionList) ->
 	lists:keystore(Key, 1, OptionList, Option);
@@ -457,3 +465,26 @@ require([App|Tail]) ->
 		{error, {already_started, App}} -> ok
 	end,
 	require(Tail).
+
+-spec log(logger:level(), io:format(), list(), module() | #{logger => module()}) -> ok.
+log(Level, Format, Args, Logger) when is_atom(Logger) ->
+	log(Level, Format, Args, #{logger => Logger});
+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).

+ 16 - 14
src/ranch_acceptor.erl

@@ -14,17 +14,17 @@
 
 -module(ranch_acceptor).
 
--export([start_link/3]).
--export([loop/3]).
+-export([start_link/4]).
+-export([loop/4]).
 
--spec start_link(inet:socket(), module(), pid())
+-spec start_link(inet:socket(), module(), module(), pid())
 	-> {ok, pid()}.
-start_link(LSocket, Transport, ConnsSup) ->
-	Pid = spawn_link(?MODULE, loop, [LSocket, Transport, ConnsSup]),
+start_link(LSocket, Transport, Logger, ConnsSup) ->
+	Pid = spawn_link(?MODULE, loop, [LSocket, Transport, Logger, ConnsSup]),
 	{ok, Pid}.
 
--spec loop(inet:socket(), module(), pid()) -> no_return().
-loop(LSocket, Transport, ConnsSup) ->
+-spec loop(inet:socket(), module(), module(), pid()) -> no_return().
+loop(LSocket, Transport, Logger, ConnsSup) ->
 	_ = case Transport:accept(LSocket, infinity) of
 		{ok, CSocket} ->
 			case Transport:controlling_process(CSocket, ConnsSup) of
@@ -39,21 +39,23 @@ loop(LSocket, Transport, ConnsSup) ->
 		%% We can't accept anymore anyway, so we might as well wait
 		%% a little for the situation to resolve itself.
 		{error, emfile} ->
-			error_logger:warning_msg("Ranch acceptor reducing accept rate: out of file descriptors~n"),
+			ranch:log(warning,
+				"Ranch acceptor reducing accept rate: out of file descriptors~n",
+				[], Logger),
 			receive after 100 -> ok end;
 		%% We want to crash if the listening socket got closed.
 		{error, Reason} when Reason =/= closed ->
 			ok
 	end,
-	flush(),
-	?MODULE:loop(LSocket, Transport, ConnsSup).
+	flush(Logger),
+	?MODULE:loop(LSocket, Transport, Logger, ConnsSup).
 
-flush() ->
+flush(Logger) ->
 	receive Msg ->
-		error_logger:error_msg(
+		ranch:log(warning,
 			"Ranch acceptor received unexpected message: ~p~n",
-			[Msg]),
-		flush()
+			[Msg], Logger),
+		flush(Logger)
 	after 0 ->
 		ok
 	end.

+ 18 - 9
src/ranch_acceptors_sup.erl

@@ -27,12 +27,21 @@ init([Ref, Transport]) ->
 	ConnsSup = ranch_server:get_connections_sup(Ref),
 	TransOpts = ranch_server:get_transport_options(Ref),
 	NumAcceptors = maps:get(num_acceptors, TransOpts, 10),
+	Logger = maps:get(logger, TransOpts, error_logger),
 	LSocket = case maps:get(socket, TransOpts, undefined) of
 		undefined ->
 			SocketOpts = maps:get(socket_opts, TransOpts, []),
+			%% We temporarily put the logger in the process dictionary
+			%% so that it can be used from ranch:filter_options. The
+			%% interface as it currently is does not allow passing it
+			%% down otherwise.
+			put(logger, Logger),
 			case Transport:listen(SocketOpts) of
-				{ok, Socket} -> Socket;
-				{error, Reason} -> listen_error(Ref, Transport, SocketOpts, Reason)
+				{ok, Socket} ->
+					erase(logger),
+					Socket;
+				{error, Reason} ->
+					listen_error(Ref, Transport, SocketOpts, Reason, Logger)
 			end;
 		Socket ->
 			Socket
@@ -41,18 +50,18 @@ init([Ref, Transport]) ->
 	ranch_server:set_addr(Ref, Addr),
 	Procs = [
 		{{acceptor, self(), N}, {ranch_acceptor, start_link, [
-			LSocket, Transport, ConnsSup
+			LSocket, Transport, Logger, ConnsSup
 		]}, permanent, brutal_kill, worker, []}
 			|| N <- lists:seq(1, NumAcceptors)],
 	{ok, {{one_for_one, 1, 5}, Procs}}.
 
--spec listen_error(any(), module(), any(), atom()) -> no_return().
-listen_error(Ref, Transport, TransOpts0, Reason) ->
-	TransOpts1 = lists:keyreplace(cert, 1, TransOpts0, {cert, '...'}),
-	TransOpts = lists:keyreplace(key, 1, TransOpts1, {key, '...'}),
-	error_logger:error_msg(
+-spec listen_error(any(), module(), any(), atom(), module()) -> no_return().
+listen_error(Ref, Transport, SocketOpts0, Reason, Logger) ->
+	SocketOpts1 = [{cert, '...'}|proplists:delete(cert, SocketOpts0)],
+	SocketOpts = [{key, '...'}|proplists:delete(key, SocketOpts1)],
+	ranch:log(error,
 		"Failed to start Ranch listener ~p in ~p:listen(~999999p) for reason ~p (~s)~n",
-		[Ref, Transport, TransOpts, Reason, format_error(Reason)]),
+		[Ref, Transport, SocketOpts, Reason, format_error(Reason)], Logger),
 	exit({listen_error, Ref, Reason}).
 
 format_error(no_cert) ->

+ 23 - 20
src/ranch_conns_sup.erl

@@ -40,7 +40,8 @@
 	protocol = undefined :: module(),
 	opts :: any(),
 	handshake_timeout :: timeout(),
-	max_conns = undefined :: ranch:max_conns()
+	max_conns = undefined :: ranch:max_conns(),
+	logger = undefined :: module()
 }).
 
 %% API.
@@ -102,15 +103,17 @@ init(Parent, Ref, Transport, Protocol) ->
 	ConnType = maps:get(connection_type, TransOpts, worker),
 	Shutdown = maps:get(shutdown, TransOpts, 5000),
 	HandshakeTimeout = maps:get(handshake_timeout, TransOpts, 5000),
+	Logger = maps:get(logger, TransOpts, error_logger),
 	ProtoOpts = ranch_server:get_protocol_options(Ref),
 	ok = proc_lib:init_ack(Parent, {ok, self()}),
 	loop(#state{parent=Parent, ref=Ref, conn_type=ConnType,
 		shutdown=Shutdown, transport=Transport, protocol=Protocol,
-		opts=ProtoOpts, handshake_timeout=HandshakeTimeout, max_conns=MaxConns}, 0, 0, []).
+		opts=ProtoOpts, handshake_timeout=HandshakeTimeout,
+		max_conns=MaxConns, logger=Logger}, 0, 0, []).
 
 loop(State=#state{parent=Parent, ref=Ref, conn_type=ConnType,
 		transport=Transport, protocol=Protocol, opts=Opts,
-		max_conns=MaxConns}, CurConns, NbChildren, Sleepers) ->
+		max_conns=MaxConns, logger=Logger}, CurConns, NbChildren, Sleepers) ->
 	receive
 		{?MODULE, start_protocol, To, Socket} ->
 			try Protocol:start_link(Ref, Socket, Transport, Opts) of
@@ -120,18 +123,18 @@ loop(State=#state{parent=Parent, ref=Ref, conn_type=ConnType,
 					handshake(State, CurConns, NbChildren, Sleepers, To, Socket, SupPid, ProtocolPid);
 				Ret ->
 					To ! self(),
-					error_logger:error_msg(
+					ranch:log(error,
 						"Ranch listener ~p connection process start failure; "
 						"~p:start_link/4 returned: ~999999p~n",
-						[Ref, Protocol, Ret]),
+						[Ref, Protocol, Ret], Logger),
 					Transport:close(Socket),
 					loop(State, CurConns, NbChildren, Sleepers)
 			catch Class:Reason ->
 				To ! self(),
-				error_logger:error_msg(
+				ranch:log(error,
 					"Ranch listener ~p connection process start failure; "
 					"~p:start_link/4 crashed with reason: ~p:~999999p~n",
-					[Ref, Protocol, Class, Reason]),
+					[Ref, Protocol, Class, Reason], Logger),
 				loop(State, CurConns, NbChildren, Sleepers)
 			end;
 		{?MODULE, active_connections, To, Tag} ->
@@ -166,10 +169,10 @@ loop(State=#state{parent=Parent, ref=Ref, conn_type=ConnType,
 		{'EXIT', Pid, Reason} when Sleepers =:= [] ->
 			case erase(Pid) of
 				active ->
-					report_error(Ref, Protocol, Pid, Reason),
+					report_error(Logger, Ref, Protocol, Pid, Reason),
 					loop(State, CurConns - 1, NbChildren - 1, Sleepers);
 				removed ->
-					report_error(Ref, Protocol, Pid, Reason),
+					report_error(Logger, Ref, Protocol, Pid, Reason),
 					loop(State, CurConns, NbChildren - 1, Sleepers);
 				undefined ->
 					loop(State, CurConns, NbChildren, Sleepers)
@@ -178,15 +181,15 @@ loop(State=#state{parent=Parent, ref=Ref, conn_type=ConnType,
 		{'EXIT', Pid, Reason} ->
 			case erase(Pid) of
 				active when CurConns > MaxConns ->
-					report_error(Ref, Protocol, Pid, Reason),
+					report_error(Logger, Ref, Protocol, Pid, Reason),
 					loop(State, CurConns - 1, NbChildren - 1, Sleepers);
 				active ->
-					report_error(Ref, Protocol, Pid, Reason),
+					report_error(Logger, Ref, Protocol, Pid, Reason),
 					[To|Sleepers2] = Sleepers,
 					To ! self(),
 					loop(State, CurConns - 1, NbChildren - 1, Sleepers2);
 				removed ->
-					report_error(Ref, Protocol, Pid, Reason),
+					report_error(Logger, Ref, Protocol, Pid, Reason),
 					loop(State, CurConns, NbChildren - 1, Sleepers);
 				undefined ->
 					loop(State, CurConns, NbChildren, Sleepers)
@@ -213,9 +216,9 @@ loop(State=#state{parent=Parent, ref=Ref, conn_type=ConnType,
 			To ! {Tag, {error, ?MODULE}},
 			loop(State, CurConns, NbChildren, Sleepers);
 		Msg ->
-			error_logger:error_msg(
+			ranch:log(error,
 				"Ranch listener ~p received unexpected message ~p~n",
-				[Ref, Msg]),
+				[Ref, Msg], Logger),
 			loop(State, CurConns, NbChildren, Sleepers)
 	end.
 
@@ -309,14 +312,14 @@ system_code_change(Misc, _, _, _) ->
 
 %% We use ~999999p here instead of ~w because the latter doesn't
 %% support printable strings.
-report_error(_, _, _, normal) ->
+report_error(_, _, _, _, normal) ->
 	ok;
-report_error(_, _, _, shutdown) ->
+report_error(_, _, _, _, shutdown) ->
 	ok;
-report_error(_, _, _, {shutdown, _}) ->
+report_error(_, _, _, _, {shutdown, _}) ->
 	ok;
-report_error(Ref, Protocol, Pid, Reason) ->
-	error_logger:error_msg(
+report_error(Logger, Ref, Protocol, Pid, Reason) ->
+	ranch:log(error,
 		"Ranch listener ~p had connection process started with "
 		"~p:start_link/4 at ~p exit with reason: ~999999p~n",
-		[Ref, Protocol, Pid, Reason]).
+		[Ref, Protocol, Pid, Reason], Logger).

+ 17 - 0
test/acceptor_SUITE.erl

@@ -65,6 +65,7 @@ groups() ->
 		misc_bad_transport_options,
 		misc_info,
 		misc_info_embedded,
+		misc_opts_logger,
 		misc_wait_for_connections
 	]}, {supervisor, [
 		connection_type_supervisor,
@@ -275,6 +276,22 @@ misc_info_embedded(_) ->
 do_get_listener_info(ListenerGroup) ->
 	lists:sort([L || L={{G, _}, _} <- ranch:info(), G=:=ListenerGroup]).
 
+misc_opts_logger(_) ->
+	doc("Confirm that messages are sent via the configured logger module."),
+	register(name(), self()),
+	{ok, _} = ranch:start_listener(name(),
+		ranch_tcp, #{logger => ?MODULE, socket_opts => [<<"garbage">>]},
+		echo_protocol, []),
+	receive
+		{warning, "Transport option " ++ _, [<<"garbage">>]} ->
+			ok
+	after 1000 ->
+		error(timeout)
+	end.
+
+warning(Format, Args) ->
+	misc_opts_logger ! {warning, Format, Args}.
+
 misc_wait_for_connections(_) ->
 	doc("Ensure wait for connections works."),
 	Name = name(),