feat(#36): Adds telemetry events

closes #36

src/erf_http_server/erf_http_server_elli.erl

@@ -78,29 +78,38 @@ 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 :: term(),
     CallbackArgs :: [Name :: atom()].
 %% @doc Handles an elli event.
 %% @private
+handle_event(request_complete, Args, CallbackArgs) ->
+    handle_full_response(request_complete, Args, CallbackArgs);
+handle_event(chunk_complete, Args, CallbackArgs) ->
+    handle_full_response(chunk_complete, Args, CallbackArgs);
+handle_event(invalid_return, [Request, Unexpected], CallbackArgs) ->
+    handle_exception(Request, Unexpected, CallbackArgs);
 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
     ]);
 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.

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
+
+%% <code>erf</code>'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
+    }.
+