1: -module(mongoose_instrument_SUITE).
2: -compile([export_all, nowarn_export_all]).
3:
4: -include("log_helper.hrl").
5: -include_lib("eunit/include/eunit.hrl").
6: -include_lib("common_test/include/ct.hrl").
7:
8: -define(HANDLER, mongoose_instrument_test_handler).
9: -define(INACTIVE_HANDLER, mongoose_instrument_inactive_handler).
10: -define(ADDED_HANDLER, mongoose_instrument_added_handler).
11: -define(FAILING_HANDLER, mongoose_instrument_failing_handler).
12: -define(LABELS, #{key => value}).
13: -define(CFG, #{metrics => #{time => histogram}}).
14: -define(MEASUREMENTS, #{count => 1}).
15:
16: %% Setup and teardown
17:
18: all() ->
19: [{group, persistent},
20: {group, not_persistent}
21: ].
22:
23: groups() ->
24: [{persistent, [parallel], api_test_cases()},
25: {not_persistent, [parallel], api_test_cases()}].
26:
27: api_test_cases() ->
28: [set_up_and_execute,
29: set_up_multiple_and_execute_one,
30: set_up_fails_when_already_registered,
31: set_up_fails_for_inconsistent_labels,
32: set_up_and_tear_down,
33: set_up_and_tear_down_multiple,
34: execute_fails_when_not_set_up,
35: set_up_and_span,
36: set_up_and_span_with_arg,
37: set_up_and_span_with_error,
38: span_fails_when_not_set_up,
39: set_up_probe,
40: set_up_failing_probe,
41: set_up_and_tear_down_probe,
42: unexpected_events,
43: add_and_remove_handler,
44: cannot_add_existing_handler,
45: cannot_remove_non_existing_handler].
46:
47: init_per_suite(Config) ->
48: log_helper:set_up(),
49: mongoose_config:set_opts(opts()),
50: maps:map(fun mock_handler/2, mocked_handlers()),
51: Config.
52:
53: mock_handler(Module, {SetUpResult, HandleEventF}) ->
54: meck:new(Module, [non_strict, no_link]),
55: meck:expect(Module, set_up, fun(_Event, #{}, #{}) -> SetUpResult end),
56: meck:expect(Module, handle_event, fun(_Event, #{}, #{}, #{}) -> HandleEventF() end).
57:
58: end_per_suite(_Config) ->
59: lists:foreach(fun meck:unload/1, maps:keys(mocked_handlers())),
60: mongoose_config:erase_opts(),
61: log_helper:tear_down().
62:
63: init_per_group(Group, Config) ->
64: lists:foreach(fun meck:reset/1, maps:keys(mocked_handlers())),
65: Config1 = async_helper:start(Config, mongoose_instrument, start_link, []),
66: set_up_persistence(Group),
67: Config1.
68:
69: init_per_testcase(Case, Config) ->
70: log_helper:subscribe(),
71: [{event, event_name(Case)} | Config].
72:
73: end_per_testcase(_Case, _Config) ->
74: log_helper:unsubscribe().
75:
76: mocked_handlers() ->
77: #{?HANDLER => {true, fun() -> ok end},
78: ?INACTIVE_HANDLER => {false, fun() -> ok end},
79: ?ADDED_HANDLER => {true, fun() -> ok end},
80: ?FAILING_HANDLER => {true, fun() -> error(failed) end}}.
81:
82: set_up_persistence(persistent) ->
83: mongoose_instrument:persist(),
84: ?assertEqual(#{}, persistent_term:get(mongoose_instrument));
85: set_up_persistence(not_persistent) ->
86: ?assertError(badarg, persistent_term:get(mongoose_instrument)).
87:
88: end_per_group(_Group, Config) ->
89: async_helper:stop_all(Config),
90: mongoose_helper:wait_until(fun() -> whereis(mongoose_instrument) end, undefined),
91: ?assertError(badarg, persistent_term:get(mongoose_instrument)).
92:
93: opts() ->
94: #{instrumentation => #{test_handler => #{}, inactive_handler => #{}, failing_handler => #{}}}.
95:
96: event_name(Case) ->
97: list_to_atom(atom_to_list(Case) ++ "_event").
98:
99: %% Test cases
100:
101: set_up_and_execute(Config) ->
102: Event = ?config(event, Config),
103: Measurements = ?MEASUREMENTS,
104: Labels = ?LABELS,
105: ok = mongoose_instrument:set_up(Event, ?LABELS, ?CFG),
106: ?assertEqual([{[Event, Labels, ?CFG], true}], history(?HANDLER, set_up, Event)),
107: ?assertEqual([{[Event, Labels, ?CFG], false}], history(?INACTIVE_HANDLER, set_up, Event)),
108: ?assertEqual([{[Event, Labels, ?CFG], true}], history(?FAILING_HANDLER, set_up, Event)),
109:
110: ok = mongoose_instrument:execute(Event, Labels, Measurements),
111: ?assertEqual([{[Event, Labels, ?CFG, Measurements], ok}],
112: history(?HANDLER, handle_event, Event)),
113: ?assertEqual([], history(?INACTIVE_HANDLER, handle_event, Event)),
114: HandlerFun = fun ?FAILING_HANDLER:handle_event/4,
115: ?assertLog(error, #{what := event_handler_failed,
116: class := error, reason := failed, stacktrace := _,
117: event_name := Event, labels := Labels, measurements := Measurements,
118: handler_fun := HandlerFun}).
119:
120: set_up_multiple_and_execute_one(Config) ->
121: Event = ?config(event, Config),
122: Specs = [{Event, Labels1 = #{key => value1}, ?CFG},
123: {Event, Labels2 = #{key => value2}, ?CFG}],
124: ok = mongoose_instrument:set_up(Specs),
125: ?assertEqual([{[Event, Labels1, ?CFG], true}, {[Event, Labels2, ?CFG], true}],
126: history(?HANDLER, set_up, Event)),
127: ok = mongoose_instrument:execute(Event, Labels1, ?MEASUREMENTS),
128: ?assertEqual([{[Event, Labels1, ?CFG, ?MEASUREMENTS], ok}],
129: history(?HANDLER, handle_event, Event)).
130:
131: set_up_fails_when_already_registered(Config) ->
132: Event = ?config(event, Config),
133: ok = mongoose_instrument:set_up(Event, ?LABELS, ?CFG),
134: ?assertError(#{what := event_already_registered},
135: mongoose_instrument:set_up(Event, ?LABELS, ?CFG)),
136: ?assertError(#{what := event_already_registered},
137: mongoose_instrument:set_up(Event, ?LABELS, #{})).
138:
139: set_up_fails_for_inconsistent_labels(Config) ->
140: Event = ?config(event, Config),
141: Labels = ?LABELS,
142: ok = mongoose_instrument:set_up(Event, Labels, ?CFG),
143: ?assertError(#{what := inconsistent_labels},
144: mongoose_instrument:set_up(Event, #{}, ?CFG)),
145: ?assertError(#{what := inconsistent_labels},
146: mongoose_instrument:set_up(Event, Labels#{additional_key => value}, ?CFG)),
147: ?assertError(#{what := inconsistent_labels},
148: mongoose_instrument:set_up(Event, #{different_key => value}, ?CFG)).
149:
150: set_up_and_tear_down(Config) ->
151: Event = ?config(event, Config),
152: ok = mongoose_instrument:set_up(Event, ?LABELS, ?CFG),
153: ok = mongoose_instrument:tear_down(Event, ?LABELS),
154: ?assertError(#{what := event_not_registered},
155: mongoose_instrument:execute(Event, ?LABELS, ?MEASUREMENTS)),
156: [] = history(?HANDLER, handle_event, Event),
157: ok = mongoose_instrument:tear_down(Event, ?LABELS). % idempotent
158:
159: set_up_and_tear_down_multiple(Config) ->
160: Event = ?config(event, Config),
161: Specs = [{Event, Labels1 = #{key => value1}, ?CFG},
162: {Event, Labels2 = #{key => value2}, ?CFG}],
163: ok = mongoose_instrument:set_up(Specs),
164: ok = mongoose_instrument:tear_down(Specs),
165: ?assertError(#{what := event_not_registered},
166: mongoose_instrument:execute(Event, Labels1, ?MEASUREMENTS)),
167: ?assertError(#{what := event_not_registered},
168: mongoose_instrument:execute(Event, Labels2, ?MEASUREMENTS)),
169: [] = history(?HANDLER, handle_event, Event).
170:
171: execute_fails_when_not_set_up(Config) ->
172: Event = ?config(event, Config),
173: ?assertError(#{what := event_not_registered},
174: mongoose_instrument:execute(Event, ?LABELS, ?MEASUREMENTS)),
175: [] = history(?HANDLER, handle_event, Event).
176:
177: set_up_and_span(Config) ->
178: {Event, Labels, InstrConfig} = {?config(event, Config), ?LABELS, ?CFG},
179: ok = mongoose_instrument:set_up(Event, Labels, InstrConfig),
180: ok = mongoose_instrument:span(Event, Labels, fun test_op/0, fun measure_test_op/2),
181: [{[Event, Labels, InstrConfig, #{time := Time, result := ok}], ok}] =
182: history(?HANDLER, handle_event, Event),
183: ?assert(Time >= 1000).
184:
185: set_up_and_span_with_arg(Config) ->
186: {Event, Labels, InstrConfig} = {?config(event, Config), ?LABELS, ?CFG},
187: ok = mongoose_instrument:set_up(Event, Labels, InstrConfig),
188: ok = mongoose_instrument:span(Event, Labels, fun test_op/1, [2], fun measure_test_op/2),
189: [{[Event, Labels, InstrConfig, #{time := Time, result := ok}], ok}] =
190: history(?HANDLER, handle_event, Event),
191: ?assert(Time >= 2000).
192:
193: set_up_and_span_with_error(Config) ->
194: Event = ?config(event, Config),
195: ok = mongoose_instrument:set_up(Event, ?LABELS, ?CFG),
196: ?assertError(simulated_error,
197: mongoose_instrument:span(Event, ?LABELS, fun crashing_op/0, fun measure_test_op/2)),
198: [] = history(?HANDLER, handle_event, Event).
199:
200: span_fails_when_not_set_up(Config) ->
201: Event = ?config(event, Config),
202: Labels = #{key => value},
203: ?assertError(#{what := event_not_registered},
204: mongoose_instrument:span(Event, Labels, fun test_op/0, fun measure_test_op/2)),
205: %% Also checks that the function is not executed - otherwise 'simulated_error' would be raised
206: ?assertError(#{what := event_not_registered},
207: mongoose_instrument:span(Event, Labels, fun crashing_op/0, fun measure_test_op/2)),
208: [] = history(?HANDLER, handle_event, Event).
209:
210: set_up_probe(Config) ->
211: Event = ?config(event, Config),
212: Cfg = #{probe => ?MODULE, probe_interval => 1},
213: ok = mongoose_instrument:set_up(Event, ?LABELS, Cfg),
214: ExpectedMeasurements = #{event => Event, config => Cfg, count => 1},
215:
216: %% Wait until the probe is called
217: {ok, History1} = async_helper:wait_until(fun() -> history(?HANDLER, handle_event, Event) end,
218: fun(L) -> length(L) > 0 end),
219: ExpectedEvent = {[Event, ?LABELS, Cfg, ExpectedMeasurements], ok},
220: ?assertEqual([ExpectedEvent], History1),
221:
222: %% Wait until it's called again to ensure that it is done periodically
223: {ok, History2} = async_helper:wait_until(fun() -> history(?HANDLER, handle_event, Event) end,
224: fun(L) -> length(L) > 1 end),
225: ?assertEqual([ExpectedEvent, ExpectedEvent], History2).
226:
227: set_up_failing_probe(Config) ->
228: Event = ?config(event, Config),
229: Labels = ?LABELS,
230: Cfg = #{probe => ?MODULE, probe_interval => 1},
231: ok = mongoose_instrument:set_up(Event, Labels, Cfg),
232:
233: %% Wait until the error appears in logs
234: ?assertLog(error, #{what := probe_failed,
235: class := error, reason := simulated_error, stacktrace := _,
236: event_name := Event, labels := Labels, probe_mod := ?MODULE}, 5000),
237:
238: %% Make sure that the failing probe is not disabled
239: ?assertLog(error, #{what := probe_failed,
240: class := error, reason := simulated_error, stacktrace := _,
241: event_name := Event, labels := Labels, probe_mod := ?MODULE}, 5000).
242:
243: set_up_and_tear_down_probe(Config) ->
244: Event = ?config(event, Config),
245: Cfg = #{probe => ?MODULE, probe_interval => 1},
246: ok = mongoose_instrument:set_up(Event, ?LABELS, Cfg),
247: mongoose_instrument:tear_down(Event, ?LABELS),
248:
249: %% The probe shouldn't be called anymore
250: ?assertError({badmatch, _},
251: async_helper:wait_until(fun() -> history(?HANDLER, handle_event, Event) end,
252: fun(L) -> length(L) > 0 end,
253: #{time_left => timer:seconds(2)})).
254:
255: unexpected_events(_Config) ->
256: Pid = whereis(mongoose_instrument),
257: {error, #{what := unexpected_call}} = gen_server:call(mongoose_instrument, bad_call),
258: gen_server:cast(mongoose_instrument, bad_cast),
259: mongoose_instrument ! bad_info,
260: ?assertEqual(Pid, whereis(mongoose_instrument)). %% It should be still working
261:
262: add_and_remove_handler(Config) ->
263: Event = ?config(event, Config),
264: ok = mongoose_instrument:set_up(Event, Labels1 = #{key => value1}, ?CFG),
265:
266: %% Add handler
267: ok = mongoose_instrument:add_handler(added_handler, #{cfg_key => cfg_val}),
268: ?assertEqual(#{cfg_key => cfg_val}, mongoose_config:get_opt([instrumentation, added_handler])),
269: ?assertEqual([{[Event, Labels1, ?CFG], true}], history(?ADDED_HANDLER, set_up, Event)),
270: %% Make sure it's still possible to set up new events
271: ok = mongoose_instrument:set_up(Event, Labels2 = #{key => value2}, ?CFG),
272:
273: ok = mongoose_instrument:execute(Event, Labels1, ?MEASUREMENTS),
274: ok = mongoose_instrument:execute(Event, Labels2, ?MEASUREMENTS),
275: History = history(?ADDED_HANDLER, handle_event, Event),
276: ?assertEqual([{[Event, Labels1, ?CFG, ?MEASUREMENTS], ok},
277: {[Event, Labels2, ?CFG, ?MEASUREMENTS], ok}], History),
278:
279: %% Remove handler
280: ok = mongoose_instrument:remove_handler(added_handler),
281: ?assertEqual({error, not_found}, mongoose_config:lookup_opt([instrumentation, added_handler])),
282: ok = mongoose_instrument:execute(Event, Labels1, ?MEASUREMENTS),
283: ok = mongoose_instrument:execute(Event, Labels2, ?MEASUREMENTS),
284: ?assertEqual(History, history(?ADDED_HANDLER, handle_event, Event)). % no new events
285:
286: cannot_add_existing_handler(_Config) ->
287: ?assertError(#{what := handler_already_configured},
288: mongoose_instrument:add_handler(test_handler, #{})).
289:
290: cannot_remove_non_existing_handler(_Config) ->
291: ?assertError(#{what := handler_not_configured},
292: mongoose_instrument:remove_handler(unknown_handler)).
293:
294: %% Helpers
295:
296: history(HandlerMod, WantedF, WantedEvent) ->
297: [{Args, Result} || {_Pid, {_M, CalledF, [Event|_] = Args}, Result} <- meck:history(HandlerMod),
298: WantedF =:= CalledF andalso WantedEvent =:= Event].
299:
300: test_op(Delay) ->
301: timer:sleep(Delay).
302:
303: test_op() ->
304: test_op(1).
305:
306: crashing_op() ->
307: error(simulated_error).
308:
309: measure_test_op(Time, Result) ->
310: #{time => Time, result => Result}.
311:
312: probe(set_up_failing_probe_event, _Labels, _Config) ->
313: error(simulated_error);
314: probe(Event, Labels, Config) ->
315: ?assertEqual(?LABELS, Labels),
316: #{event => Event, config => Config, count => 1}.