Use mongoose_instrument for roster hook metrics

big_tests/tests/disco_and_caps_SUITE.erl

@@ -13,11 +13,10 @@ all() ->
      {group, disco_with_extra_features}].
 
 groups() ->
-    G = [{disco_with_caps, [parallel], basic_test_cases() ++ caps_test_cases()},
-         {disco_with_caps_and_extra_features, [parallel],
-          basic_test_cases() ++ caps_test_cases() ++ extra_feature_test_cases()},
-         {disco_with_extra_features, [parallel], basic_test_cases() ++ extra_feature_test_cases()}],
-    ct_helper:repeat_all_until_all_ok(G).
+    [{disco_with_caps, [parallel], basic_test_cases() ++ caps_test_cases()},
+     {disco_with_caps_and_extra_features, [parallel],
+      basic_test_cases() ++ caps_test_cases() ++ extra_feature_test_cases()},
+     {disco_with_extra_features, [parallel], basic_test_cases() ++ extra_feature_test_cases()}].
 
 basic_test_cases() ->
     [user_cannot_query_stranger_resources,
@@ -37,11 +36,13 @@ extra_feature_test_cases() ->
      user_can_query_server_info].
 
 init_per_suite(C) ->
+    instrument_helper:start(instrument_helper:declared_events(mod_disco)),
     C.
 
 end_per_suite(C) ->
     escalus_fresh:clean(),
-    escalus:end_per_suite(C).
+    escalus:end_per_suite(C),
+    instrument_helper:stop().
 
 init_per_group(Name, C) ->
     C2 = escalus:init_per_suite(dynamic_modules:save_modules(host_type(), C)),
@@ -89,7 +90,8 @@ user_cannot_query_stranger_resources(Config) ->
         Stanza = escalus:wait_for_stanza(Alice),
         escalus:assert(is_iq_error, [Request], Stanza),
         escalus:assert(is_error, [<<"cancel">>, <<"service-unavailable">>], Stanza),
-        escalus:assert(is_stanza_from, [BobJid], Stanza)
+        escalus:assert(is_stanza_from, [BobJid], Stanza),
+        assert_roster_get_event(Alice)
     end).
 
 user_cannot_query_stranger_features(Config) ->
@@ -100,7 +102,8 @@ user_cannot_query_stranger_features(Config) ->
         Stanza = escalus:wait_for_stanza(Alice),
         escalus:assert(is_iq_error, [Request], Stanza),
         escalus:assert(is_error, [<<"cancel">>, <<"service-unavailable">>], Stanza),
-        escalus:assert(is_stanza_from, [BobJid], Stanza)
+        escalus:assert(is_stanza_from, [BobJid], Stanza),
+        assert_roster_get_event(Alice)
     end).
 
 user_can_query_friend_resources(Config) ->
@@ -114,7 +117,8 @@ user_can_query_friend_resources(Config) ->
         BobName = escalus_client:username(Bob),
         Item = exml_query:subelement_with_attr(Query, <<"jid">>, BobFullJid),
         ?assertEqual(BobName, exml_query:attr(Item, <<"name">>)),
-        escalus:assert(is_stanza_from, [BobJid], Stanza)
+        escalus:assert(is_stanza_from, [BobJid], Stanza),
+        assert_roster_get_event(Alice)
     end).
 
 user_can_query_friend_features(Config) ->
@@ -124,7 +128,8 @@ user_can_query_friend_features(Config) ->
         escalus:send(Alice, escalus_stanza:disco_info(BobJid)),
         Stanza = escalus:wait_for_stanza(Alice),
         escalus:assert(has_identity, [<<"account">>, <<"registered">>], Stanza),
-        escalus:assert(is_stanza_from, [BobJid], Stanza)
+        escalus:assert(is_stanza_from, [BobJid], Stanza),
+        assert_roster_get_event(Alice)
     end).
 
 user_cannot_query_own_resources_with_unknown_node(Config) ->
@@ -227,3 +232,8 @@ name(sales) -> <<"sales-addresses">>.
 urls(abuse) -> [<<"abuse@example.com">>];
 urls(admin) -> [<<"admin@example.com">>, <<"operations@example.com">>];
 urls(sales) -> [<<"sales@example.com">>].
+
+assert_roster_get_event(Client) ->
+    ClientJid = jid:from_binary(escalus_client:full_jid(Client)),
+    instrument_helper:assert(mod_disco_roster_get, #{host_type => host_type()},
+                             fun(#{count := 1, jid := Jid}) -> ClientJid =:= Jid end).

big_tests/tests/graphql_roster_SUITE.erl

@@ -103,13 +103,16 @@ domain_admin_tests() ->
     ].
 
 init_per_suite(Config) ->
+    HostType = domain_helper:host_type(),
+    instrument_helper:start([{mod_roster_get, #{host_type => HostType}}]),
     Config1 = ejabberd_node_utils:init(mim(), Config),
     Config2 = escalus:init_per_suite(Config1),
-    dynamic_modules:save_modules(domain_helper:host_type(), Config2).
+    dynamic_modules:save_modules(HostType, Config2).
 
 end_per_suite(Config) ->
     dynamic_modules:restore_modules(Config),
-    escalus:end_per_suite(Config).
+    escalus:end_per_suite(Config),
+    instrument_helper:stop().
 
 init_per_group(admin_roster_http, Config) ->
     graphql_helper:init_admin_handler(Config);
@@ -394,7 +397,8 @@ admin_list_contacts_story(Config, Alice, Bob) ->
     Res = admin_list_contacts(Alice, Config),
     [#{<<"subscription">> := <<"NONE">>, <<"ask">> := <<"NONE">>, <<"jid">> := BobBin,
        <<"name">> := BobName, <<"groups">> := ?DEFAULT_GROUPS}] =
-        get_ok_value([data, roster, listContacts], Res).
+        get_ok_value([data, roster, listContacts], Res),
+    roster_helper:assert_roster_event(Alice, mod_roster_get).
 
 admin_list_contacts_wrong_user(Config) ->
     % User with a non-existent domain
@@ -543,7 +547,8 @@ user_list_contacts_story(Config, Alice, Bob) ->
     Res = user_list_contacts(Alice, Config),
     [#{<<"subscription">> := <<"NONE">>, <<"ask">> := <<"NONE">>, <<"jid">> := BobBin,
        <<"name">> := Name, <<"groups">> := ?DEFAULT_GROUPS}] =
-        get_ok_value(?LIST_CONTACTS_PATH, Res).
+        get_ok_value(?LIST_CONTACTS_PATH, Res),
+    roster_helper:assert_roster_event(Alice, mod_roster_get).
 
 user_get_contact(Config) ->
     escalus:fresh_story_with_config(Config, [{alice, 1}, {bob, 1}],

big_tests/tests/instrument_helper.erl

@@ -62,7 +62,8 @@ assert(EventName, Labels, MeasurementsList, CheckF) ->
                    [EventName, Labels, MeasurementsList]),
             ct:fail("No instrumentation events matched");
         Filtered ->
-            ct:log("Matching measurements: ~p", [Filtered]),
+            ct:log("Matching measurements for event ~p with labels ~p:~n~p",
+                   [EventName, Labels, Filtered]),
             event_tested(EventName, Labels)
     end.
 

big_tests/tests/metrics_api_SUITE.erl

@@ -178,7 +178,7 @@ one_iq_sent(Config) ->
         end,
        [{xmppIqSent, 3},
         {xmppIqReceived, 3},
-        {modRosterGets, 1},
+        {'mod_roster_get.count', 1},
         {xmppStanzaSent, 1 + user_alpha(3)},
         {xmppStanzaReceived, 1 + user_alpha(3)}]).
 

big_tests/tests/metrics_roster_SUITE.erl

@@ -20,6 +20,7 @@
 -import(distributed_helper, [mim/0, require_rpc_nodes/1, rpc/4]).
 -import(metrics_helper, [assert_counter/2, get_counter_value/1]).
 -import(domain_helper, [host_type/0]).
+-import(roster_helper, [assert_roster_event/2, assert_subscription_event/3]).
 
 %%--------------------------------------------------------------------
 %% Suite configuration
@@ -31,8 +32,8 @@ all() ->
     ].
 
 groups() ->
-    [{roster, [sequence], roster_tests()},
-     {subscriptions, [sequence], subscription_tests()}].
+    [{roster, [parallel], roster_tests()},
+     {subscriptions, [parallel], subscription_tests()}].
 
 suite() ->
     require_rpc_nodes([mim]) ++ escalus:suite().
@@ -41,15 +42,9 @@ roster_tests() -> [get_roster,
                    add_contact,
                    roster_push].
 
-%%  WARNING: Side-effects & test interference
-%%  subscribe affects subsequent tests
-%%  by sending a directed presence before the roster push
-%%  in add_sample_contact/2
-%%  TODO: investigate, fix.
-
-subscription_tests() -> [unsubscribe,
-                         decline_subscription,
-                         subscribe].
+subscription_tests() -> [subscribe,
+                         unsubscribe,
+                         decline_subscription].
 %%--------------------------------------------------------------------
 %% Init & teardown
 %%--------------------------------------------------------------------
@@ -108,16 +103,15 @@ end_rosters_remove(Config) ->
 get_roster(Config) ->
     escalus:fresh_story(Config, [{alice, 1}, {bob, 1}], fun(Alice, Bob) ->
         %% Presences trigger 'get_subscription_lists' events
-        assert_event(Alice, get_subscription_lists),
-        assert_event(Bob, get_subscription_lists),
+        assert_backend_event(Alice, get_subscription_lists),
+        assert_backend_event(Bob, get_subscription_lists),
         escalus_client:send(Alice, escalus_stanza:roster_get()),
         escalus_client:wait_for_stanza(Alice),
-        assert_event(Alice, get_roster)
+        assert_backend_event(Alice, get_roster),
+        assert_roster_event(Alice, mod_roster_get)
         end).
 
-add_contact(ConfigIn) ->
-    Config = mongoose_metrics(ConfigIn, [{['_', modRosterSets], 1}]),
-
+add_contact(Config) ->
     escalus:fresh_story(Config, [{alice, 1}, {bob, 1}], fun(Alice, Bob) ->
 
         %% add contact
@@ -126,15 +120,13 @@ add_contact(ConfigIn) ->
                                                               [<<"friends">>],
                                                               <<"Bobby">>)),
         Received = escalus_client:wait_for_stanza(Alice),
+        assert_roster_event(Alice, mod_roster_set),
         escalus_client:send(Alice, escalus_stanza:iq_result(Received)),
         escalus_client:wait_for_stanza(Alice)
 
         end).
 
-roster_push(ConfigIn) ->
-    Config = mongoose_metrics(ConfigIn, [{['_', modRosterSets], 1},
-                                         {['_', modRosterPush], 2}]),
-
+roster_push(Config) ->
     escalus:fresh_story(Config, [{alice, 2}, {bob, 1}], fun(Alice1, Alice2, Bob) ->
 
         %% add contact
@@ -143,18 +135,18 @@ roster_push(ConfigIn) ->
                                                               [<<"friends">>],
                                                               <<"Bobby">>)),
         Received = escalus_client:wait_for_stanza(Alice1),
+        assert_roster_event(Alice1, mod_roster_set),
+        assert_roster_event(Alice1, mod_roster_push),
         escalus_client:send(Alice1, escalus_stanza:iq_result(Received)),
         escalus_client:wait_for_stanza(Alice1),
 
         Received2 = escalus_client:wait_for_stanza(Alice2),
+        assert_roster_event(Alice2, mod_roster_push),
         escalus_client:send(Alice2, escalus_stanza:iq_result(Received2))
 
         end).
 
-
-subscribe(ConfigIn) ->
-    Config = mongoose_metrics(ConfigIn, [{['_', modPresenceSubscriptions], 1}]),
-
+subscribe(Config) ->
     escalus:fresh_story(Config, [{alice, 1}, {bob, 1}], fun(Alice,Bob) ->
         BobJid = escalus_client:short_jid(Bob),
         AliceJid = escalus_client:short_jid(Alice),
@@ -184,16 +176,14 @@ subscribe(ConfigIn) ->
 
         %% Alice receives subscribed
         escalus_client:wait_for_stanzas(Alice, 3),
+        assert_subscription_event(Bob, Alice, fun(#{subscription_count := 1}) -> true end),
 
         %% Bob receives roster push
         escalus_client:wait_for_stanza(Bob)
 
-
         end).
 
-decline_subscription(ConfigIn) ->
-    Config = mongoose_metrics(ConfigIn, [{['_', modPresenceUnsubscriptions], 1}]),
-
+decline_subscription(Config) ->
     escalus:fresh_story(Config, [{alice, 1}, {bob, 1}], fun(Alice,Bob) ->
         BobJid = escalus_client:short_jid(Bob),
         AliceJid = escalus_client:short_jid(Alice),
@@ -212,15 +202,14 @@ decline_subscription(ConfigIn) ->
         %% Bob refuses subscription
         escalus_client:send(Bob, escalus_stanza:presence_direct(AliceJid, <<"unsubscribed">>)),
 
-        %% Alice receives subscribed
-        escalus_client:wait_for_stanzas(Alice, 2)
+        %% Alice receives unsubscribed
+        escalus_client:wait_for_stanzas(Alice, 2),
+        assert_subscription_event(Bob, Alice, fun(#{unsubscription_count := 1}) -> true end)
 
         end).
 
 
-unsubscribe(ConfigIn) ->
-    Config = mongoose_metrics(ConfigIn, [{['_', modPresenceUnsubscriptions], 1}]),
-
+unsubscribe(Config) ->
     escalus:fresh_story(Config, [{alice, 1}, {bob, 1}], fun(Alice,Bob) ->
         BobJid = escalus_client:short_jid(Bob),
         AliceJid = escalus_client:short_jid(Alice),
@@ -263,8 +252,8 @@ unsubscribe(ConfigIn) ->
         escalus_client:send(Alice, escalus_stanza:iq_result(PushReqA2)),
 
         %% Bob receives unsubscribe
-
-        escalus_client:wait_for_stanzas(Bob, 2)
+        escalus_client:wait_for_stanzas(Bob, 2),
+        assert_subscription_event(Bob, Alice, fun(#{unsubscription_count := 1}) -> true end)
 
     end).
 
@@ -300,18 +289,25 @@ roster_rdbms_precondition() ->
     mod_roster_rdbms == rpc(mim(), mongoose_backend, get_backend_name, [domain_helper:host_type(), mod_roster]).
 
 declared_events() ->
+    declared_backend_events() ++ declared_sm_events() ++ instrument_helper:declared_events(mod_roster).
+
+declared_sm_events() ->
+    [{sm_presence_subscription, #{}}].
+
+declared_backend_events() ->
     BackendMod = backend_mod(),
     HostType = host_type(),
     Functions = [get_roster, get_subscription_lists],
     [{BackendMod, #{host_type => HostType, function => Function}} || Function <- Functions].
 
 %% This works only for get_roster and get_subscription_lists because of the function arguments
-assert_event(Client, Function) ->
+assert_backend_event(Client, Function) ->
     ClientJid = jid:from_binary(escalus_utils:get_short_jid(Client)),
-    instrument_helper:assert(backend_mod(), #{host_type => host_type(), function => Function},
-                             fun(#{count := 1, time := T, args := [_, User, Server]}) when T > 0 ->
-                                     ClientJid =:= jid:make_bare(User, Server)
-                             end).
+    instrument_helper:assert(
+      backend_mod(), #{host_type => host_type(), function => Function},
+      fun(#{count := 1, time := T, args := [_, User, Server]}) when T > 0 ->
+              ClientJid =:= jid:make_bare(User, Server)
+      end).
 
 backend_mod() ->
     rpc(mim(), mongoose_backend, get_backend_module, [host_type(), mod_roster]).

big_tests/tests/roster_helper.erl

@@ -1,5 +1,5 @@
 -module(roster_helper).
--export([set_versioning/3]).
+-compile([export_all, nowarn_export_all]).
 
 -import(distributed_helper, [mim/0, rpc/4]).
 -import(domain_helper, [host_type/0]).
@@ -10,3 +10,20 @@ set_versioning(Versioning, VersionStore, Config) ->
     dynamic_modules:ensure_modules(host_type(), [{mod_roster, Opts#{versioning => Versioning,
                                                                     store_current_id => VersionStore}}]),
     Config.
+
+%% Intrumentation events
+
+assert_roster_event(Client, Event) ->
+    ClientJid = jid:from_binary(escalus_utils:get_jid(Client)),
+    instrument_helper:assert(
+      Event, #{host_type => host_type()},
+      fun(#{count := 1, jid := Jid}) -> jid:are_bare_equal(ClientJid, Jid) end).
+
+assert_subscription_event(FromClient, ToClient, CheckF) ->
+    FromClientJid = jid:from_binary(escalus_utils:get_short_jid(FromClient)),
+    ToClientJid = jid:from_binary(escalus_utils:get_short_jid(ToClient)),
+    instrument_helper:assert(
+      sm_presence_subscription, #{},
+      fun(#{from_jid := FromJid, to_jid := ToJid} = M) ->
+              FromClientJid =:= FromJid andalso ToClientJid =:= ToJid andalso CheckF(M)
+      end).

rel/fed1.vars-toml.config

@@ -47,6 +47,12 @@
   tls.mode = \"starttls\"
   tls.ciphers = \"ECDHE-RSA-AES256-GCM-SHA384\""}.
 
+{instrumentation, "[instrumentation.exometer]
+
+[instrumentation.prometheus]
+
+[instrumentation.log]"}.
+
 {c2s_dhfile, "\"priv/ssl/fake_dh_server.pem\""}.
 {s2s_dhfile, "\"priv/ssl/fake_dh_server.pem\""}.
 

rel/mim1.vars-toml.config

@@ -96,6 +96,12 @@
 {mod_cache_users, "  time_to_live = 2
   number_of_segments = 5\n"}.
 
+{instrumentation, "[instrumentation.exometer]
+
+[instrumentation.prometheus]
+
+[instrumentation.log]"}.
+
 {c2s_dhfile, "\"priv/ssl/fake_dh_server.pem\""}.
 {s2s_dhfile, "\"priv/ssl/fake_dh_server.pem\""}.
 

rel/mim2.vars-toml.config

@@ -48,6 +48,13 @@
   password = \"secret\""}.
 {all_metrics_are_global, "true"}.
 
+{instrumentation, "[instrumentation.exometer]
+  all_metrics_are_global = true
+
+[instrumentation.prometheus]
+
+[instrumentation.log]"}.
+
 {http_server_name, "\"Classified\""}.
 
 {c2s_dhfile, "\"priv/ssl/fake_dh_server.pem\""}.