Event handler (#207)

This process is a single global process where the system register handlers. These handlers react on all metrics and log events, and therefore a single process becomes responsible for handling with virtually all metrics and logs of a quite big system, meaning, a bottleneck and a SPOF. Also, having this process deal with logs also means logs lose information about their calls, like stacktraces or file and line positions.

Instead, at the points of log and metric generations, these can be incremented locally. Performance is not a problem, metrics usually just increment a counter in an ETS table, which is very likely faster than passing a message with a big payload to a bottlenecked process. Likewise logs, most logs will only be filtered out against a log-level, which in the case of OTP Logger is indeed faster than any message passing even.

Author: NelsonVides

src/erldns_app.erl

@@ -36,8 +36,6 @@ start(_Type, _Args) ->
     Ret.
 
 start_phase(post_start, _StartType, _PhaseArgs) ->
-    erldns_events:add_handler(erldns_event_handler),
-
     case application:get_env(erldns, custom_zone_parsers) of
         {ok, Parsers} ->
             erldns_zone_parser:register_parsers(Parsers);
@@ -55,8 +53,18 @@ start_phase(post_start, _StartType, _PhaseArgs) ->
     ?LOG_INFO("Loading zones from local file"),
     erldns_zone_loader:load_zones(),
 
-    ?LOG_INFO("Notifying servers to start"),
-    erldns_events:notify({?MODULE, start_servers}),
+    % Start up the UDP and TCP servers
+    ?LOG_INFO("Starting the UDP and TCP supervisor"),
+    supervisor:start_child(
+        erldns_sup,
+        #{
+            id => erldns_server_sup,
+            start => {erldns_server_sup, start_link, []},
+            restart => permanent,
+            shutdown => infinity,
+            type => supervisor
+        }
+    ),
 
     ok.
 

src/erldns_decoder.erl

@@ -16,6 +16,7 @@
 %% system crash
 -module(erldns_decoder).
 
+-include_lib("kernel/include/logger.hrl").
 -include_lib("dns_erlang/include/dns_records.hrl").
 
 -export([decode_message/1]).
@@ -36,7 +37,10 @@ decode_message(Bin) ->
                     M
             catch
                 Exception:Reason ->
-                    erldns_events:notify({?MODULE, decode_message_error, {Exception, Reason, Bin}}),
+                    ?LOG_ERROR(
+                        "Error decoding message (module: ~p, event: ~p, data: ~p, exception: ~p, reason: ~p)",
+                        [?MODULE, decode_message_error, Bin, Exception, Reason]
+                    ),
                     {formerr, Reason, Bin}
             end
     end.

src/erldns_encoder.erl

@@ -16,6 +16,7 @@
 %% system crash.
 -module(erldns_encoder).
 
+-include_lib("kernel/include/logger.hrl").
 -include_lib("dns_erlang/include/dns_records.hrl").
 
 -export([
@@ -39,7 +40,9 @@ encode_message(Response) ->
                     M
             catch
                 Exception:Reason ->
-                    erldns_events:notify({?MODULE, encode_message_error, {Exception, Reason, Response}}),
+                    ?LOG_ERROR("Error encoding message (module: ~p, event: ~p, response: ~p, exception: ~p, reason: ~p)", [
+                        ?MODULE, encode_message_error, Response, Exception, Reason
+                    ]),
                     encode_message(build_error_response(Response))
             end
     end.
@@ -65,7 +68,10 @@ encode_message(Response, Opts) ->
                     M
             catch
                 Exception:Reason ->
-                    erldns_events:notify({?MODULE, encode_message_error, {Exception, Reason, Response, Opts}}),
+                    ?LOG_ERROR(
+                        "Error encoding with opts (module: ~p, event: ~p, response: ~p, opts: ~p, exception: ~p, reason: ~p)",
+                        [?MODULE, encode_message_error, Response, Opts, Exception, Reason]
+                    ),
                     {false, encode_message(build_error_response(Response))}
             end
     end.

src/erldns_event_handler.erl

@@ -107,9 +107,7 @@ handle(Message, Host, {throttled, Host, _ReqCount}) ->
 %% append the SOA record if it is a zone transfer and complete the response
 %% by filling out count-related header fields.
 handle(Message, Host, _) ->
-    erldns_events:notify({?MODULE, start_handle, [{host, Host}, {message, Message}]}),
     Response = folsom_metrics:histogram_timed_update(request_handled_histogram, ?MODULE, do_handle, [Message, Host]),
-    erldns_events:notify({?MODULE, end_handle, [{host, Host}, {message, Message}, {response, Response}]}),
     Response.
 
 do_handle(Message, Host) ->
@@ -123,10 +121,8 @@ do_handle(Message, Host) ->
 handle_message(Message, Host) ->
     case erldns_packet_cache:get({Message#dns_message.questions, Message#dns_message.additional}, Host) of
         {ok, CachedResponse} ->
-            erldns_events:notify({?MODULE, packet_cache_hit, [{host, Host}, {message, Message}]}),
             CachedResponse#dns_message{id = Message#dns_message.id};
         {error, Reason} ->
-            erldns_events:notify({?MODULE, packet_cache_miss, [{reason, Reason}, {host, Host}, {message, Message}]}),
             % SOA lookup
             handle_packet_cache_miss(Message, get_authority(Message), Host)
     end.
@@ -165,11 +161,10 @@ safe_handle_packet_cache_miss(Message, AuthorityRecords, Host) ->
                 Response ->
                     maybe_cache_packet(Response, Response#dns_message.aa)
             catch
-                Exception:Reason:Stacktrace ->
-                    % ?LOG_ERROR("Error answering request (module: ~p, event: ~p, exception: ~p, reason: ~p, message: ~p, stacktrace: "
-                    %            "~p)",
-                    %            [?MODULE, resolve_error, Exception, Reason, Message, Stacktrace]),
-                    erldns_events:notify({?MODULE, resolve_error, {Exception, Reason, Message, Stacktrace}}),
+                Class:Reason:Stacktrace ->
+                    ?LOG_ERROR(#{what => resolve_error, dns_message => Message, class => Class, reason => Reason, stacktrace => Stacktrace}),
+                    folsom_metrics:notify({erldns_handler_error_counter, {inc, 1}}),
+                    folsom_metrics:notify({erldns_handler_error_meter, 1}),
                     RCode =
                         case Reason of
                             {error, rcode, ?DNS_RCODE_SERVFAIL} -> ?DNS_RCODE_SERVFAIL;
@@ -210,11 +205,13 @@ complete_response(Message) ->
 notify_empty_response(Message) ->
     case {Message#dns_message.rc, Message#dns_message.anc + Message#dns_message.auc + Message#dns_message.adc} of
         {?DNS_RCODE_REFUSED, _} ->
-            erldns_events:notify({?MODULE, refused_response, Message#dns_message.questions}),
+            folsom_metrics:notify({refused_response_meter, 1}),
+            folsom_metrics:notify({refused_response_counter, {inc, 1}}),
             Message;
         {_, 0} ->
             ?LOG_INFO("Empty response (module: ~p, event: ~p, message: ~p)", [?MODULE, empty_response, Message]),
-            erldns_events:notify({?MODULE, empty_response, Message}),
+            folsom_metrics:notify({empty_response_meter, 1}),
+            folsom_metrics:notify({empty_response_counter, {inc, 1}}),
             Message;
         _ ->
             Message

src/erldns_events.erl

@@ -825,7 +825,8 @@ requires_additional_processing([], Acc) ->
 check_dnssec(Message, Host, Question) ->
     case proplists:get_bool(dnssec, erldns_edns:get_opts(Message)) of
         true ->
-            erldns_events:notify({?MODULE, dnssec_request, Host, Question#dns_query.name}),
+            folsom_metrics:notify(dnssec_request_counter, {inc, 1}),
+            folsom_metrics:notify(dnssec_request_meter, 1),
             true;
         false ->
             false

src/erldns_handler.erl

@@ -201,7 +201,10 @@ load_zones(Filename, false) when is_list(Filename) ->
             ?LOG_DEBUG("Loaded zones (count: ~p)", [length(JsonZones)]),
             {ok, length(JsonZones)};
         {error, Reason} ->
-            erldns_events:notify({?MODULE, failed_zones_load, Reason}),
+            ?LOG_ERROR(
+                "Failed to load zones (module: ~p, event: ~p, reason: ~p)",
+                [?MODULE, failed_zones_load, Reason]
+            ),
             {err, Reason}
     end.
 

src/erldns_resolver.erl

@@ -58,7 +58,6 @@ gc_registered(ProcessName) ->
 init(_Args) ->
     SysProcs =
         [
-            ?CHILD(erldns_events, worker, []),
             ?CHILD(erldns_zone_cache, worker, []),
             ?CHILD(erldns_zone_parser, worker, []),
             ?CHILD(erldns_zone_encoder, worker, []),