Make sure rest_terminate is always called

Also improves error reporting.

src/cowboy_rest.erl

@@ -63,23 +63,26 @@ upgrade(Req, Env, Handler, HandlerOpts) ->
 		Method = cowboy_req:get(method, Req),
 		case erlang:function_exported(Handler, rest_init, 2) of
 			true ->
-				case Handler:rest_init(Req, HandlerOpts) of
+				try Handler:rest_init(Req, HandlerOpts) of
 					{ok, Req2, HandlerState} ->
 						service_available(Req2, #state{env=Env, method=Method,
 							handler=Handler, handler_state=HandlerState})
+				catch Class:Reason ->
+					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",
+						[Handler, rest_init, 2, Class, Reason, HandlerOpts,
+							cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+					{error, 500, Req}
 				end;
 			false ->
 				service_available(Req, #state{env=Env, method=Method,
 					handler=Handler})
 		end
-	catch Class:Reason ->
-		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",
-			[Handler, rest_init, 2, Class, Reason, HandlerOpts,
-				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
-		{error, 500, Req}
+	catch
+		throw:{?MODULE, error} ->
+			{error, 500, Req}
 	end.
 
 service_available(Req, State) ->
@@ -462,20 +465,34 @@ variances(Req, State=#state{content_types_p=CTP,
 		[_] -> Variances2;
 		[_|_] -> [<<"accept-charset">>|Variances2]
 	end,
-	{Variances4, Req3, State2} = case call(Req, State, variances) of
+	try variances(Req, State, Variances3) of
+		{Variances4, Req2, State2} ->
+			case [[<<", ">>, V] || V <- Variances4] of
+				[] ->
+					resource_exists(Req2, State2);
+				[[<<", ">>, H]|Variances5] ->
+					Req3 = cowboy_req:set_resp_header(
+						<<"vary">>, [H|Variances5], Req2),
+					resource_exists(Req3, State2)
+			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, variances, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
+	end.
+
+variances(Req, State, Variances) ->
+	case unsafe_call(Req, State, variances) of
 		no_call ->
-			{Variances3, Req, State};
+			{Variances, Req, State};
 		{HandlerVariances, Req2, HandlerState} ->
-			{Variances3 ++ HandlerVariances, Req2,
+			{Variances ++ HandlerVariances, Req2,
 				State#state{handler_state=HandlerState}}
-	end,
-	case [[<<", ">>, V] || V <- Variances4] of
-		[] ->
-			resource_exists(Req3, State2);
-		[[<<", ">>, H]|Variances5] ->
-			Req4 = cowboy_req:set_resp_header(
-				<<"vary">>, [H|Variances5], Req3),
-			resource_exists(Req4, State2)
 	end.
 
 resource_exists(Req, State) ->
@@ -493,11 +510,22 @@ if_match_exists(Req, State) ->
 	end.
 
 if_match(Req, State, EtagsList) ->
-	{Etag, Req2, State2} = generate_etag(Req, State),
-	case lists:member(Etag, EtagsList) of
-		true -> if_unmodified_since_exists(Req2, State2);
-		%% Etag may be `undefined' which cannot be a member.
-		false -> precondition_failed(Req2, State2)
+	try generate_etag(Req, State) of
+		{Etag, Req2, State2} ->
+			case lists:member(Etag, EtagsList) of
+				true -> if_unmodified_since_exists(Req2, State2);
+				%% Etag may be `undefined' which cannot be a member.
+				false -> precondition_failed(Req2, State2)
+			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, generate_etag, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
 	end.
 
 if_match_must_not_exist(Req, State) ->
@@ -518,10 +546,21 @@ if_unmodified_since_exists(Req, State) ->
 
 %% If LastModified is the atom 'no_call', we continue.
 if_unmodified_since(Req, State, IfUnmodifiedSince) ->
-	{LastModified, Req2, State2} = last_modified(Req, State),
-	case LastModified > IfUnmodifiedSince of
-		true -> precondition_failed(Req2, State2);
-		false -> if_none_match_exists(Req2, State2)
+	try last_modified(Req, State) of
+		{LastModified, Req2, State2} ->
+			case LastModified > IfUnmodifiedSince of
+				true -> precondition_failed(Req2, State2);
+				false -> if_none_match_exists(Req2, State2)
+			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, last_modified, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
 	end.
 
 if_none_match_exists(Req, State) ->
@@ -535,15 +574,26 @@ if_none_match_exists(Req, State) ->
 	end.
 
 if_none_match(Req, State, EtagsList) ->
-	{Etag, Req2, State2} = generate_etag(Req, State),
-	case Etag of
-		undefined ->
-			precondition_failed(Req2, State2);
-		Etag ->
-			case lists:member(Etag, EtagsList) of
-				true -> precondition_is_head_get(Req2, State2);
-				false -> if_modified_since_exists(Req2, State2)
+	try generate_etag(Req, State) of
+		{Etag, Req2, State2} ->
+			case Etag of
+				undefined ->
+					precondition_failed(Req2, State2);
+				Etag ->
+					case lists:member(Etag, EtagsList) of
+						true -> precondition_is_head_get(Req2, State2);
+						false -> if_modified_since_exists(Req2, State2)
+					end
 			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, generate_etag, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
 	end.
 
 precondition_is_head_get(Req, State=#state{method=Method})
@@ -569,22 +619,52 @@ if_modified_since_now(Req, State, IfModifiedSince) ->
 	end.
 
 if_modified_since(Req, State, IfModifiedSince) ->
-	{LastModified, Req2, State2} = last_modified(Req, State),
-	case LastModified of
-		no_call ->
+	try last_modified(Req, State) of
+		{no_call, Req2, State2} ->
 			method(Req2, State2);
-		LastModified ->
+		{LastModified, Req2, State2} ->
 			case LastModified > IfModifiedSince of
 				true -> method(Req2, State2);
 				false -> not_modified(Req2, State2)
 			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, last_modified, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
 	end.
 
 not_modified(Req, State) ->
 	Req2 = cowboy_req:delete_resp_header(<<"content-type">>, Req),
-	{Req3, State2} = set_resp_etag(Req2, State),
-	{Req4, State3} = set_resp_expires(Req3, State2),
-	respond(Req4, State3, 304).
+	try set_resp_etag(Req2, State) of
+		{Req3, State2} ->
+			try set_resp_expires(Req3, State2) of
+				{Req4, State3} ->
+					respond(Req4, State3, 304)
+			catch Class:Reason ->
+				error_logger:error_msg(
+					"** Cowboy handler ~p terminating in ~p/~p~n"
+					"   for the reason ~p:~p~n** Handler state was ~p~n"
+					"** Request was ~p~n** Stacktrace: ~p~n~n",
+					[State#state.handler, expires, 2,
+						Class, Reason, State#state.handler_state,
+						cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+				error_terminate(Req2, State)
+			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, generate_etag, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req2, State)
+	end.
 
 precondition_failed(Req, State) ->
 	respond(Req, State, 412).
@@ -649,7 +729,7 @@ method(Req, State=#state{method= <<"PATCH">>}) ->
 	patch_resource(Req, State);
 method(Req, State=#state{method=Method})
 		when Method =:= <<"GET">>; Method =:= <<"HEAD">> ->
-	set_resp_body(Req, State);
+	set_resp_body_etag(Req, State);
 method(Req, State) ->
 	multiple_choices(Req, State).
 
@@ -813,43 +893,88 @@ has_resp_body(Req, State) ->
 		false -> respond(Req, State, 204)
 	end.
 
+%% Set the Etag header if any for the response provided.
+set_resp_body_etag(Req, State) ->
+	try set_resp_etag(Req, State) of
+		{Req2, State2} ->
+			set_resp_body_last_modified(Req2, State2)
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, generate_etag, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
+	end.
+
+%% Set the Last-Modified header if any for the response provided.
+set_resp_body_last_modified(Req, State) ->
+	try last_modified(Req, State) of
+		{LastModified, Req2, State2} ->
+			case LastModified of
+				LastModified when is_atom(LastModified) ->
+					set_resp_body_expires(Req2, State2);
+				LastModified ->
+					LastModifiedBin = cowboy_clock:rfc1123(LastModified),
+					Req3 = cowboy_req:set_resp_header(
+						<<"last-modified">>, LastModifiedBin, Req2),
+					set_resp_body_expires(Req3, State2)
+			end
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, last_modified, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
+	end.
+
+%% Set the Expires header if any for the response provided.
+set_resp_body_expires(Req, State) ->
+	try set_resp_expires(Req, State) of
+		{Req2, State2} ->
+			set_resp_body(Req2, State2)
+	catch Class:Reason ->
+		error_logger:error_msg(
+			"** Cowboy handler ~p terminating in ~p/~p~n"
+			"   for the reason ~p:~p~n** Handler state was ~p~n"
+			"** Request was ~p~n** Stacktrace: ~p~n~n",
+			[State#state.handler, expires, 2,
+				Class, Reason, State#state.handler_state,
+				cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+		error_terminate(Req, State)
+	end.
+
 %% Set the response headers and call the callback found using
 %% content_types_provided/2 to obtain the request body and add
 %% it to the response.
 set_resp_body(Req, State=#state{handler=Handler, handler_state=HandlerState,
-		content_type_a={_Type, Fun}}) ->
-	{Req2, State2} = set_resp_etag(Req, State),
-	{LastModified, Req3, State3} = last_modified(Req2, State2),
-	Req4 = case LastModified of
-		LastModified when is_atom(LastModified) ->
-			Req3;
-		LastModified ->
-			LastModifiedBin = cowboy_clock:rfc1123(LastModified),
-			cowboy_req:set_resp_header(
-				<<"last-modified">>, LastModifiedBin, Req3)
-	end,
-	{Req5, State4} = set_resp_expires(Req4, State3),
-	case call(Req5, State4, Fun) of
+		content_type_a={_Type, Callback}}) ->
+	case call(Req, State, Callback) of
 		no_call ->
 			error_logger:error_msg(
 				"** Cowboy handler ~p terminating; "
 				"function ~p/~p was not exported~n"
 				"** Request was ~p~n** State was ~p~n~n",
-				[Handler, Fun, 2, cowboy_req:to_list(Req5), HandlerState]),
-			{error, 500, Req5};
-		{halt, Req6, HandlerState2} ->
-			terminate(Req6, State4#state{handler_state=HandlerState2});
-		{Body, Req6, HandlerState2} ->
-			State5 = State4#state{handler_state=HandlerState2},
-			Req7 = case Body of
+				[Handler, Callback, 2, cowboy_req:to_list(Req), HandlerState]),
+			{error, 500, Req};
+		{halt, Req2, HandlerState2} ->
+			terminate(Req2, State#state{handler_state=HandlerState2});
+		{Body, Req2, HandlerState2} ->
+			State2 = State#state{handler_state=HandlerState2},
+			Req3 = case Body of
 				{stream, StreamFun} ->
-					cowboy_req:set_resp_body_fun(StreamFun, Req6);
+					cowboy_req:set_resp_body_fun(StreamFun, Req2);
 				{stream, Len, StreamFun} ->
-					cowboy_req:set_resp_body_fun(Len, StreamFun, Req6);
+					cowboy_req:set_resp_body_fun(Len, StreamFun, Req2);
 				_Contents ->
-					cowboy_req:set_resp_body(Body, Req6)
+					cowboy_req:set_resp_body(Body, Req2)
 			end,
-			multiple_choices(Req7, State5)
+			multiple_choices(Req3, State2)
 	end.
 
 multiple_choices(Req, State) ->
@@ -889,7 +1014,7 @@ set_resp_expires(Req, State) ->
 generate_etag(Req, State=#state{etag=no_call}) ->
 	{undefined, Req, State};
 generate_etag(Req, State=#state{etag=undefined}) ->
-	case call(Req, State, generate_etag) of
+	case unsafe_call(Req, State, generate_etag) of
 		no_call ->
 			{undefined, Req, State#state{etag=no_call}};
 		{Etag, Req2, HandlerState} when is_binary(Etag) ->
@@ -904,7 +1029,7 @@ generate_etag(Req, State=#state{etag=Etag}) ->
 last_modified(Req, State=#state{last_modified=no_call}) ->
 	{undefined, Req, State};
 last_modified(Req, State=#state{last_modified=undefined}) ->
-	case call(Req, State, last_modified) of
+	case unsafe_call(Req, State, last_modified) of
 		no_call ->
 			{undefined, Req, State#state{last_modified=no_call}};
 		{LastModified, Req2, HandlerState} ->
@@ -917,7 +1042,7 @@ last_modified(Req, State=#state{last_modified=LastModified}) ->
 expires(Req, State=#state{expires=no_call}) ->
 	{undefined, Req, State};
 expires(Req, State=#state{expires=undefined}) ->
-	case call(Req, State, expires) of
+	case unsafe_call(Req, State, expires) of
 		no_call ->
 			{undefined, Req, State#state{expires=no_call}};
 		{Expires, Req2, HandlerState} ->
@@ -941,9 +1066,29 @@ expect(Req, State, Callback, Expected, OnTrue, OnFalse) ->
 			next(Req2, State#state{handler_state=HandlerState}, OnFalse)
 	end.
 
-call(Req, #state{handler=Handler, handler_state=HandlerState}, Fun) ->
-	case erlang:function_exported(Handler, Fun, 2) of
-		true -> Handler:Fun(Req, HandlerState);
+call(Req, State=#state{handler=Handler, handler_state=HandlerState},
+		Callback) ->
+	case erlang:function_exported(Handler, Callback, 2) of
+		true ->
+			try
+				Handler:Callback(Req, HandlerState)
+			catch Class:Reason ->
+				error_logger:error_msg(
+					"** Cowboy handler ~p terminating in ~p/~p~n"
+					"   for the reason ~p:~p~n** Handler state was ~p~n"
+					"** Request was ~p~n** Stacktrace: ~p~n~n",
+					[Handler, Callback, 2, Class, Reason, HandlerState,
+						cowboy_req:to_list(Req), erlang:get_stacktrace()]),
+				error_terminate(Req, State)
+			end;
+		false ->
+			no_call
+	end.
+
+unsafe_call(Req, #state{handler=Handler, handler_state=HandlerState},
+		Callback) ->
+	case erlang:function_exported(Handler, Callback, 2) of
+		true -> Handler:Callback(Req, HandlerState);
 		false -> no_call
 	end.
 
@@ -956,11 +1101,18 @@ respond(Req, State, StatusCode) ->
 	{ok, Req2} = cowboy_req:reply(StatusCode, Req),
 	terminate(Req2, State).
 
-terminate(Req, #state{env=Env, handler=Handler,
-		handler_state=HandlerState}) ->
+terminate(Req, State=#state{env=Env}) ->
+	rest_terminate(Req, State),
+	{ok, Req, [{result, ok}|Env]}.
+
+-spec error_terminate(cowboy_req:req(), #state{}) -> no_return().
+error_terminate(Req, State) ->
+	rest_terminate(Req, State),
+	erlang:throw({?MODULE, error}).
+
+rest_terminate(Req, #state{handler=Handler, handler_state=HandlerState}) ->
 	case erlang:function_exported(Handler, rest_terminate, 2) of
 		true -> ok = Handler:rest_terminate(
 			cowboy_req:lock(Req), HandlerState);
 		false -> ok
-	end,
-	{ok, Req, [{result, ok}|Env]}.
+	end.