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 => ?MODULE, interval => 1}}, 213: ok = mongoose_instrument:set_up(Event, ?LABELS, Cfg), 214: ExpectedMeasurements = #{event => Event, 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 => ?MODULE, 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 => ?MODULE, 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) -> 313: error(simulated_error); 314: probe(Event, Labels) -> 315: ?assertEqual(?LABELS, Labels), 316: #{event => Event, count => 1}.