diff --git a/src/erf_http_server/erf_http_server_elli.erl b/src/erf_http_server/erf_http_server_elli.erl index f356081..ecfeafb 100644 --- a/src/erf_http_server/erf_http_server_elli.erl +++ b/src/erf_http_server/erf_http_server_elli.erl @@ -78,21 +78,30 @@ handle(ElliRequest, [Name]) -> ErfResponse = erf_router:handle(Name, ErfRequest), postprocess(ErfRequest, ErfResponse). --spec handle_event(Event, Data, CallbackArgs) -> ok when - Event :: atom(), - Data :: term(), +-spec handle_event(Event, Args, CallbackArgs) -> ok when + Event :: elli_handler:event(), + Args :: elli_handler:callback_args(), CallbackArgs :: [Name :: atom()]. %% @doc Handles an elli event. %% @private +handle_event(request_complete, Args, Config) -> + handle_full_response(request_complete, Args, Config); +handle_event(chunk_complete, Args, Config) -> + handle_full_response(chunk_complete, Args, Config); +handle_event(invalid_return, [Request, Unexpected], Config) -> + handle_exception(Request, Unexpected, Config); handle_event(request_throw, [Request, Exception, Stacktrace], [Name]) -> + handle_exception(Request, [Exception, Stacktrace], [Name]), {ok, LogLevel} = erf_conf:log_level(Name), ?LOG(LogLevel, "[erf] Request ~p threw exception ~p:~n~p", [Request, Exception, Stacktrace]); handle_event(request_error, [Request, Exception, Stacktrace], [Name]) -> + handle_exception(Request, [Exception, Stacktrace], [Name]), {ok, LogLevel} = erf_conf:log_level(Name), ?LOG(LogLevel, "[erf] Request ~p errored with exception ~p.~nStacktrace:~n~p", [ preprocess(Request), Exception, Stacktrace ]); handle_event(request_exit, [Request, Exception, Stacktrace], [Name]) -> + handle_exception(Request, [Exception, Stacktrace], [Name]), {ok, LogLevel} = erf_conf:log_level(Name), ?LOG(LogLevel, "[erf] Request ~p exited with exception ~p.~nStacktrace:~n~p", [ preprocess(Request), Exception, Stacktrace @@ -100,7 +109,7 @@ handle_event(request_exit, [Request, Exception, Stacktrace], [Name]) -> handle_event(file_error, [ErrorReason], [Name]) -> {ok, LogLevel} = erf_conf:log_level(Name), ?LOG(LogLevel, "[erf] Returning file errored with reason: ~p", [ErrorReason]); -handle_event(_Event, _Data, _CallbackArgs) -> +handle_event(_Event, _Args, _CallbackArgs) -> % TODO: take better advantage of the event system ok. @@ -135,6 +144,74 @@ build_elli_conf(Name, HTTPServerConf, ExtraElliConf) -> ] ). +-spec duration(Timings, Key) -> Result when + Timings :: list(), + Key :: atom(), + Result :: integer(). +duration(Timings, request) -> + duration(request_start, request_end, Timings); + duration(Timings, headers) -> + duration(headers_start, headers_end, Timings); + duration(Timings, req_body) -> + duration(body_start, body_end, Timings); + duration(Timings, user) -> + duration(user_start, user_end, Timings); + duration(Timings, send) -> + duration(send_start, send_end, Timings). + +-spec duration(StartKey, EndKey, Timings) -> Result when + StartKey :: atom(), + EndKey :: atom(), + Timings :: list(), + Result :: integer(). +duration(StartKey, EndKey, Timings) -> + Start = proplists:get_value(StartKey, Timings), + End = proplists:get_value(EndKey, Timings), + End - Start. + +-spec handle_full_response(Event, Args, Config) -> ok when + Event :: elli_handler:event(), + Args :: elli_handler:callback_args(), + Config :: [Name :: atom()]. +handle_full_response(Event, [RawReq, StatusCode, Hs, Body, {Timings, Sizes}], [Name]) -> + Metrics = #{ + duration => duration(Timings, request), + req_body_duration => duration(Timings, req_body), + resp_duration => duration(Timings, user), + req_body_length => size(Sizes, request_body), + resp_body_length => size(Sizes, response_body) + }, + case preprocess(RawReq) of + {ok, Req} -> + erf_telemetry:event(Event, Name, Req, {StatusCode, Hs, Body}, Metrics); + _ -> + ok + end. + +-spec handle_exception(RawReq, Args, Config) -> ok when + RawReq :: elli:req(), + Args :: term(), + Config :: [Name :: atom()]. +handle_exception(RawReq, [Exception, Stacktrace], [Name]) -> + case preprocess(RawReq) of + {ok, Req} -> + erf_telemetry:exception_event(request_exception, Name, Req, #{ + stacktrace => list_to_binary(io_lib:format("~p", [Stacktrace])), + error => list_to_binary(io_lib:format("~p", [Exception])) + }); + _ -> + ok + end; +handle_exception(RawReq, Unexpected, [Name]) -> + case preprocess(RawReq) of + {ok, Req} -> + erf_telemetry:exception_event(request_exception, Name, Req, #{ + error => list_to_binary(io_lib:format("~p", [Unexpected])) + }); + _ -> + ok + end. + -spec postprocess(Request, Response) -> Resp when Request :: erf:request(), Response :: erf:response(), @@ -207,3 +284,25 @@ preprocess_method('TRACE') -> trace; preprocess_method(<<"CONNECT">>) -> connect. + +-spec size(Sizes, Key) -> Result when + Sizes :: list(), + Key :: atom(), + Result :: integer(). +size(Sizes, request_body) -> + proplists:get_value(req_body, Sizes); +size(Sizes, response) -> + size(Sizes, response_headers) + + size(Sizes, response_body); +size(Sizes, response_headers) -> + proplists:get_value(resp_headers, Sizes); +size(Sizes, response_body) -> + case proplists:get_value(chunks, Sizes) of + undefined -> + case proplists:get_value(file, Sizes) of + undefined -> + proplists:get_value(resp_body, Sizes); + FileSize -> FileSize + end; + ChunksSize -> ChunksSize + end. diff --git a/src/erf_telemetry.erl b/src/erf_telemetry.erl new file mode 100644 index 0000000..bdfefd3 --- /dev/null +++ b/src/erf_telemetry.erl @@ -0,0 +1,92 @@ +%%% Copyright 2023 Nomasystems, S.L. http://www.nomasystems.com +%% +%% Licensed under the Apache License, Version 2.0 (the "License"); +%% you may not use this file except in compliance with the License. +%% You may obtain a copy of the License at +%% +%% http://www.apache.org/licenses/LICENSE-2.0 +%% +%% Unless required by applicable law or agreed to in writing, software +%% distributed under the License is distributed on an "AS IS" BASIS, +%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +%% See the License for the specific language governing permissions and +%% limitations under the License + +%% erf's telemetry module. +-module(erf_telemetry). + +%%% EXTERNAL EXPORTS +-export([ + event/5, + exception_event/4 +]). + +-type event_name() :: request_complete | chunk_complete | request_exception. + +%%%----------------------------------------------------------------------------- +%%% EXTERNAL EXPORTS +%%%----------------------------------------------------------------------------- +-spec event(EventName, Ref, Req, Resp, Measurements) -> ok when + EventName :: event_name(), + Ref :: atom(), + Req :: erf:request(), + Resp :: {RespStatus, Headers, UserData}, + RespStatus :: integer(), + Headers :: list(), + UserData :: binary(), + Measurements :: map(). +event(EventName, Ref, Req, Resp, Measurements) -> + case code:is_loaded(telemetry) of + {file, _TelemetryBeam} -> + telemetry:execute( + event(EventName), + Measurements, + metadata(Ref, Req, Resp)); + _ -> + ok + end. + +-spec exception_event(EventName, Ref, Req, RawMetadata) -> ok when + EventName :: event_name(), + Ref :: atom(), + Req :: erf:request(), + RawMetadata :: map(). +exception_event(EventName, Ref, Req, RawMetadata) -> + case code:is_loaded(telemetry) of + {file, _TelemetryBeam} -> + telemetry:execute( + event(EventName), + [], + metadata(Ref, Req, RawMetadata) + ); + _ -> + ok + end. + + +%%%----------------------------------------------------------------------------- +%%% INTERNAL FUNCTIONS +%%%----------------------------------------------------------------------------- +event(request_complete) -> + [erf, request, stop]; +event(chunk_complete) -> + [erf, request, stop]; +event(request_exception) -> + [erf, request, fail]. + + +metadata(Ref, Req, RawMetadata) when is_map(RawMetadata) -> + RawMetadata#{ + req => Req, + resp_status => 500, + ref => Ref + }; +metadata(Ref, Req, {RespStatus, RespHeaders, UserData}) -> + #{ + req => Req, + resp_headers => RespHeaders, + resp_status => RespStatus, + ref => Ref, + user_data => UserData + }. +