Merge pull request #300 from inaka/cabol.136.support_log_queries_in_m…

…nesia

[#136] – Ensure all backends respect the log_queries option

rebar.config

@@ -110,4 +110,4 @@
 
 %% == Shell ==
 
-{shell, [{apps, [sumo_db]}]}.
+{shell, [{apps, [sumo_db]}]}.

src/adapters/sumo_store_mnesia.erl

@@ -43,7 +43,10 @@
 -type option() :: disc_copies | ram_copies | majority
                 | snmp | storage_properties.
 
--type state() :: #{default_options => [{option(), term()}]}.
+-type state() :: #{
+  verbose         => boolean(),
+  default_options => [{option(), term()}]
+}.
 
 %%%=============================================================================
 %%% API
@@ -52,7 +55,8 @@
 -spec init(term()) -> {ok, state()}.
 init(Options) ->
   DefaultOptions = parse(Options),
-  {ok, #{default_options => DefaultOptions}}.
+  Verbose = application:get_env(sumo_db, verbose, false),
+  {ok, #{default_options => DefaultOptions, verbose => Verbose}}.
 
 -spec persist(Doc, State) -> Response when
   Doc      :: sumo_internal:doc(),
@@ -79,6 +83,7 @@ persist(Doc, State) ->
       {error, Reason, State};
     {atomic, ok} ->
       NewDoc = sumo_internal:set_field(IdField, NewId, Doc),
+      _ = maybe_log(persist, [DocName, NewDoc], State),
       {ok, NewDoc, State}
   end.
 
@@ -92,6 +97,7 @@ fetch(DocName, Id, State) ->
     [Result] = mnesia:dirty_read(DocName, Id),
     Schema = sumo_internal:get_schema(DocName),
     Fields = schema_field_names(Schema),
+    _ = maybe_log(fetch, [DocName, Id], State),
     {ok, wakeup(result_to_doc(Result, Fields)), State}
   catch
     _:_ -> {error, notfound, State}
@@ -113,6 +119,7 @@ delete_by(DocName, Conditions, State) ->
     {aborted, Reason} ->
       {error, Reason, State};
     {atomic, Result} ->
+      _ = maybe_log(delete_by, [DocName, Conditions], State),
       {ok, Result, State}
   end.
 
@@ -124,6 +131,7 @@ delete_all(DocName, State) ->
   Count = mnesia:table_info(DocName, size),
   case mnesia:clear_table(DocName) of
     {atomic, ok} ->
+      _ = maybe_log(delete_all, [DocName], State),
       {ok, Count, State};
     {aborted, Reason} ->
       {error, Reason, State}
@@ -196,6 +204,7 @@ find_by(DocName, Conditions, [], Limit, Offset, State) ->
       Schema = sumo_internal:get_schema(DocName),
       Fields = schema_field_names(Schema),
       Docs = [wakeup(result_to_doc(Result, Fields)) || Result <- Results],
+      _ = maybe_log(find_by, [DocName, Conditions, Limit, Offset, MatchSpec], State),
       {ok, Docs, State}
   end;
 find_by(_DocName, _Conditions, _Sort, _Limit, _Offset, State) ->
@@ -414,3 +423,16 @@ wakeup_fun(date, _, {Date, _} = _FieldValue, _) ->
   Date;
 wakeup_fun(_, _, FieldValue, _) ->
   FieldValue.
+
+%% @private
+maybe_log(Fun, Args, #{verbose := true}) ->
+  lager:debug(log_format(Fun), Args);
+maybe_log(_, _, _) ->
+  ok.
+
+%% @private
+log_format(persist)    -> "persist(~p, ~p)";
+log_format(fetch)      -> "fetch(~p, ~p)";
+log_format(delete_by)  -> "delete_by(~p, ~p)";
+log_format(delete_all) -> "delete_all(~p)";
+log_format(find_by)    -> "find_by(~p, ~p, [], ~p, ~p)~nMatchSpec: ~p".

src/sumo_config.erl

@@ -38,22 +38,29 @@
 
 -include_lib("stdlib/include/ms_transform.hrl").
 
-%%%===================================================================
+%%%=============================================================================
 %%% Types
-%%%===================================================================
+%%%=============================================================================
 
--type doc_config() :: {DocName :: atom(), Store :: atom(), Props :: map()}.
+-type doc_config() :: {
+  SchemaName :: sumo:schema_name(),
+  Store      :: atom(),
+  Props      :: map()
+}.
 
--type event_config() :: {DocName :: atom(), EventHandler :: module()}.
+-type event_config() :: {
+  SchemaName   :: sumo:schema_name(),
+  EventHandler :: module()
+}.
 
 -export_type([
   doc_config/0,
   event_config/0
 ]).
 
-%%%===================================================================
+%%%=============================================================================
 %%% API
-%%%===================================================================
+%%%=============================================================================
 
 -spec init() -> ok.
 init() ->
@@ -118,18 +125,18 @@ remove_event_managers(DocName, EventManagers) when is_list(EventManagers) ->
 remove_event_managers(DocName, EventManagers) when is_atom(EventManagers) ->
   remove_event_managers(DocName, [EventManagers]).
 
-%%%===================================================================
+%%%=============================================================================
 %%% Internal functions
-%%%===================================================================
+%%%=============================================================================
 
 %% @private
 do_init() ->
   ?MODULE = ets:new(?MODULE, [named_table, public, {read_concurrency, true}]),
   Docs = application:get_env(sumo_db, docs, []),
   Events = application:get_env(sumo_db, events, []),
   UpdatedDocs = load_events(Docs, Events),
-  EvManagers = load_event_managers(UpdatedDocs),
-  Entries = [{'$event_managers', EvManagers} | UpdatedDocs],
+  EventManagers = load_event_managers(UpdatedDocs),
+  Entries = [{'$event_managers', EventManagers} | UpdatedDocs],
   set_entries(Entries).
 
 %% @private
@@ -145,8 +152,8 @@ load_entries(Docs, Events) ->
 load_entries(Docs, Events, Fun) ->
   UpdatedDocs = load_events(Docs, Events, Fun),
   ok = set_entries(UpdatedDocs),
-  EvManagers = load_event_managers(get_docs()),
-  set_entries({'$event_managers', EvManagers}).
+  EventManagers = load_event_managers(get_docs()),
+  set_entries({'$event_managers', EventManagers}).
 
 %% @private
 load_events(Docs, Events) ->

src/sumo_internal.erl

@@ -78,9 +78,9 @@
 
 -export_type([schema/0, doc/0, field/0]).
 
-%%%===================================================================
+%%%=============================================================================
 %%% API
-%%%===================================================================
+%%%=============================================================================
 
 %% @doc Returns a new schema.
 -spec new_schema(sumo:schema_name(), [field()]) -> schema().
@@ -192,9 +192,9 @@ check_operator(Op) -> exit({unknown_operator, Op}).
 report_overrun(Report) ->
   lager:error("~p", [Report]).
 
-%%%===================================================================
+%%%=============================================================================
 %%% Internal functions
-%%%===================================================================
+%%%=============================================================================
 
 %% @doc Returns field marked as ID for the given schema or doc name.
 %% @private

test/test.config

@@ -1,7 +1,7 @@
 [
  {sumo_db, [
    {wpool_opts, [{overrun_warning, 100}]},
-   {log_queries, true},
+   {verbose, true},
    {query_timeout, 30000},
    {storage_backends, [
      {sumo_test_backend_mnesia, sumo_backend_mnesia, []}
@@ -17,11 +17,28 @@
      {people, sumo_test_mnesia, #{module => sumo_test_people_mnesia}}
    ]},
    {events, [
-     {'_', sumo_test_people_events_manager}
+     {people, sumo_test_people_events_manager}
    ]}
  ]},
 
  {sasl, [
    {sasl_error_logger, false}
+ ]},
+
+ {lager, [
+   {colored, true},
+   {async_threshold, 200},
+   {async_threshold_window, 5},
+   {error_logger_hwm, 500},
+   {handlers, [
+     {lager_console_backend, [
+       debug,
+       {lager_default_formatter, [
+         color, time, " [", severity, "]",
+         " [", {module, ""}, ":", {function, ""}, ":", {line, ""}, "] ",
+         message, "\e[0m\n"
+       ]}
+     ]}
+   ]}
  ]}
 ].