25개 이상의 토픽을 선택하실 수 없습니다. Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

762 lines
37 KiB

14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
14 년 전
  1. %% Copyright (c) 2011 Basho Technologies, Inc. All Rights Reserved.
  2. %%
  3. %% This file is provided to you under the Apache License,
  4. %% Version 2.0 (the "License"); you may not use this file
  5. %% except in compliance with the License. You may obtain
  6. %% a copy of the License at
  7. %%
  8. %% http://www.apache.org/licenses/LICENSE-2.0
  9. %%
  10. %% Unless required by applicable law or agreed to in writing,
  11. %% software distributed under the License is distributed on an
  12. %% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
  13. %% KIND, either express or implied. See the License for the
  14. %% specific language governing permissions and limitations
  15. %% under the License.
  16. -module(lager_test_backend).
  17. -include("lager.hrl").
  18. -behaviour(gen_event).
  19. -export([init/1, handle_call/2, handle_event/2, handle_info/2, terminate/2,
  20. code_change/3]).
  21. -record(state, {level, buffer, ignored}).
  22. -compile([{parse_transform, lager_transform}]).
  23. -ifdef(TEST).
  24. -include_lib("eunit/include/eunit.hrl").
  25. -export([pop/0, count/0, count_ignored/0, flush/0]).
  26. -endif.
  27. init(Level) ->
  28. {ok, #state{level=lager_util:level_to_num(Level), buffer=[], ignored=[]}}.
  29. handle_call(count, #state{buffer=Buffer} = State) ->
  30. {ok, length(Buffer), State};
  31. handle_call(count_ignored, #state{ignored=Ignored} = State) ->
  32. {ok, length(Ignored), State};
  33. handle_call(flush, State) ->
  34. {ok, ok, State#state{buffer=[], ignored=[]}};
  35. handle_call(pop, #state{buffer=Buffer} = State) ->
  36. case Buffer of
  37. [] ->
  38. {ok, undefined, State};
  39. [H|T] ->
  40. {ok, H, State#state{buffer=T}}
  41. end;
  42. handle_call(get_loglevel, #state{level=Level} = State) ->
  43. {ok, Level, State};
  44. handle_call({set_loglevel, Level}, State) ->
  45. {ok, ok, State#state{level=lager_util:level_to_num(Level)}};
  46. handle_call(_Request, State) ->
  47. {ok, ok, State}.
  48. handle_event({log, [?MODULE], Level, Time, Message}, #state{buffer=Buffer} = State) ->
  49. {ok, State#state{buffer=Buffer ++ [{Level, Time, Message}]}};
  50. handle_event({log, Level, Time, Message}, #state{level=LogLevel,
  51. buffer=Buffer} = State) when Level =< LogLevel ->
  52. {ok, State#state{buffer=Buffer ++ [{Level, Time, Message}]}};
  53. handle_event({log, _Level, _Time, _Message}, #state{ignored=Ignored} = State) ->
  54. {ok, State#state{ignored=Ignored ++ [ignored]}};
  55. handle_event(_Event, State) ->
  56. {ok, State}.
  57. handle_info(_Info, State) ->
  58. {ok, State}.
  59. terminate(_Reason, _State) ->
  60. ok.
  61. code_change(_OldVsn, State, _Extra) ->
  62. {ok, State}.
  63. -ifdef(TEST).
  64. pop() ->
  65. gen_event:call(lager_event, ?MODULE, pop).
  66. count() ->
  67. gen_event:call(lager_event, ?MODULE, count).
  68. count_ignored() ->
  69. gen_event:call(lager_event, ?MODULE, count_ignored).
  70. flush() ->
  71. gen_event:call(lager_event, ?MODULE, flush).
  72. has_line_numbers() ->
  73. %% are we R15 or greater
  74. Rel = erlang:system_info(otp_release),
  75. {match, [Major]} = re:run(Rel, "^R(\\d+)[A|B](|0(\\d))$", [{capture, [1], list}]),
  76. list_to_integer(Major) >= 15.
  77. not_running_test() ->
  78. ?assertEqual({error, lager_not_running}, lager:log(info, self(), "not running")).
  79. lager_test_() ->
  80. {foreach,
  81. fun setup/0,
  82. fun cleanup/1,
  83. [
  84. {"observe that there is nothing up my sleeve",
  85. fun() ->
  86. ?assertEqual(undefined, pop()),
  87. ?assertEqual(0, count())
  88. end
  89. },
  90. {"logging works",
  91. fun() ->
  92. lager:warning("test message"),
  93. ?assertEqual(1, count()),
  94. {Level, _Time, Message} = pop(),
  95. ?assertMatch(Level, lager_util:level_to_num(warning)),
  96. [LevelStr, _LocStr, MsgStr] = re:split(Message, " ", [{return, list}, {parts, 3}]),
  97. ?assertEqual("[warning]", LevelStr),
  98. ?assertEqual("test message", MsgStr),
  99. ok
  100. end
  101. },
  102. {"logging with arguments works",
  103. fun() ->
  104. lager:warning("test message ~p", [self()]),
  105. ?assertEqual(1, count()),
  106. {Level, _Time, Message} = pop(),
  107. ?assertMatch(Level, lager_util:level_to_num(warning)),
  108. [LevelStr, _LocStr, MsgStr] = re:split(Message, " ", [{return, list}, {parts, 3}]),
  109. ?assertEqual("[warning]", LevelStr),
  110. ?assertEqual(lists:flatten(io_lib:format("test message ~p", [self()])), MsgStr),
  111. ok
  112. end
  113. },
  114. {"logging works from inside a begin/end block",
  115. fun() ->
  116. ?assertEqual(0, count()),
  117. begin
  118. lager:warning("test message 2")
  119. end,
  120. ?assertEqual(1, count()),
  121. ok
  122. end
  123. },
  124. {"logging works from inside a list comprehension",
  125. fun() ->
  126. ?assertEqual(0, count()),
  127. [lager:warning("test message") || _N <- lists:seq(1, 10)],
  128. ?assertEqual(10, count()),
  129. ok
  130. end
  131. },
  132. {"logging works from a begin/end block inside a list comprehension",
  133. fun() ->
  134. ?assertEqual(0, count()),
  135. [ begin lager:warning("test message") end || _N <- lists:seq(1, 10)],
  136. ?assertEqual(10, count()),
  137. ok
  138. end
  139. },
  140. {"logging works from a nested list comprehension",
  141. fun() ->
  142. ?assertEqual(0, count()),
  143. [ [lager:warning("test message") || _N <- lists:seq(1, 10)] ||
  144. _I <- lists:seq(1, 10)],
  145. ?assertEqual(100, count()),
  146. ok
  147. end
  148. },
  149. {"log messages below the threshold are ignored",
  150. fun() ->
  151. ?assertEqual(0, count()),
  152. lager:debug("this message will be ignored"),
  153. ?assertEqual(0, count()),
  154. ?assertEqual(0, count_ignored()),
  155. lager_mochiglobal:put(loglevel, {?DEBUG, []}),
  156. lager:debug("this message should be ignored"),
  157. ?assertEqual(0, count()),
  158. ?assertEqual(1, count_ignored()),
  159. lager:set_loglevel(?MODULE, debug),
  160. lager:debug("this message should be logged"),
  161. ?assertEqual(1, count()),
  162. ?assertEqual(1, count_ignored()),
  163. ?assertEqual(debug, lager:get_loglevel(?MODULE)),
  164. ok
  165. end
  166. },
  167. {"tracing works",
  168. fun() ->
  169. lager_mochiglobal:put(loglevel, {?ERROR, []}),
  170. ok = lager:info("hello world"),
  171. ?assertEqual(0, count()),
  172. lager_mochiglobal:put(loglevel, {?ERROR, [{[{module,
  173. ?MODULE}], ?DEBUG, ?MODULE}]}),
  174. ok = lager:info("hello world"),
  175. ?assertEqual(1, count()),
  176. ok
  177. end
  178. },
  179. {"tracing works with custom attributes",
  180. fun() ->
  181. lager_mochiglobal:put(loglevel, {?ERROR, []}),
  182. lager:info([{requestid, 6}], "hello world"),
  183. ?assertEqual(0, count()),
  184. lager_mochiglobal:put(loglevel, {?ERROR,
  185. [{[{requestid, 6}], ?DEBUG, ?MODULE}]}),
  186. lager:info([{requestid, 6}, {foo, bar}], "hello world"),
  187. ?assertEqual(1, count()),
  188. lager_mochiglobal:put(loglevel, {?ERROR,
  189. [{[{requestid, '*'}], ?DEBUG, ?MODULE}]}),
  190. lager:info([{requestid, 6}], "hello world"),
  191. ?assertEqual(2, count()),
  192. ok
  193. end
  194. },
  195. {"tracing honors loglevel",
  196. fun() ->
  197. lager_mochiglobal:put(loglevel, {?ERROR, [{[{module,
  198. ?MODULE}], ?NOTICE, ?MODULE}]}),
  199. ok = lager:info("hello world"),
  200. ?assertEqual(0, count()),
  201. ok = lager:notice("hello world"),
  202. ?assertEqual(1, count()),
  203. ok
  204. end
  205. }
  206. ]
  207. }.
  208. setup() ->
  209. error_logger:tty(false),
  210. application:load(lager),
  211. application:set_env(lager, handlers, [{?MODULE, info}]),
  212. application:set_env(lager, error_logger_redirect, false),
  213. application:start(compiler),
  214. application:start(syntax_tools),
  215. application:start(lager),
  216. gen_event:call(lager_event, ?MODULE, flush).
  217. cleanup(_) ->
  218. application:stop(lager),
  219. error_logger:tty(true).
  220. crash(Type) ->
  221. spawn(fun() -> gen_server:call(crash, Type) end),
  222. timer:sleep(100),
  223. _ = gen_event:which_handlers(error_logger),
  224. ok.
  225. test_body(Expected, Actual) ->
  226. case has_line_numbers() of
  227. true ->
  228. FileLine = string:substr(Actual, length(Expected)+1),
  229. Body = string:substr(Actual, 1, length(Expected)),
  230. ?assertEqual(Expected, Body),
  231. ?assertEqual(" line ", string:substr(FileLine, 1, 6));
  232. false ->
  233. ?assertEqual(Expected, Actual)
  234. end.
  235. error_logger_redirect_crash_test_() ->
  236. {foreach,
  237. fun() ->
  238. error_logger:tty(false),
  239. application:load(lager),
  240. application:set_env(lager, error_logger_redirect, true),
  241. application:set_env(lager, handlers, [{?MODULE, error}]),
  242. application:start(compiler),
  243. application:start(syntax_tools),
  244. application:start(lager),
  245. crash:start()
  246. end,
  247. fun(_) ->
  248. application:stop(lager),
  249. case whereis(crash) of
  250. undefined -> ok;
  251. Pid -> exit(Pid, kill)
  252. end,
  253. error_logger:tty(true)
  254. end,
  255. [
  256. {"again, there is nothing up my sleeve",
  257. fun() ->
  258. ?assertEqual(undefined, pop()),
  259. ?assertEqual(0, count())
  260. end
  261. },
  262. {"bad return value",
  263. fun() ->
  264. Pid = whereis(crash),
  265. crash(bad_return),
  266. {_, _, Msg} = pop(),
  267. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad return value: bleh", [Pid])),
  268. ?assertEqual(Expected, lists:flatten(Msg))
  269. end
  270. },
  271. {"bad return value with string",
  272. fun() ->
  273. Pid = whereis(crash),
  274. crash(bad_return_string),
  275. {_, _, Msg} = pop(),
  276. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad return value: {tuple,{tuple,\"string\"}}", [Pid])),
  277. ?assertEqual(Expected, lists:flatten(Msg))
  278. end
  279. },
  280. {"case clause",
  281. fun() ->
  282. Pid = whereis(crash),
  283. crash(case_clause),
  284. {_, _, Msg} = pop(),
  285. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no case clause matching {} in crash:handle_call/3", [Pid])),
  286. test_body(Expected, lists:flatten(Msg))
  287. end
  288. },
  289. {"case clause string",
  290. fun() ->
  291. Pid = whereis(crash),
  292. crash(case_clause_string),
  293. {_, _, Msg} = pop(),
  294. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no case clause matching \"crash\" in crash:handle_call/3", [Pid])),
  295. test_body(Expected, lists:flatten(Msg))
  296. end
  297. },
  298. {"function clause",
  299. fun() ->
  300. Pid = whereis(crash),
  301. crash(function_clause),
  302. {_, _, Msg} = pop(),
  303. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no function clause matching crash:function({})", [Pid])),
  304. test_body(Expected, lists:flatten(Msg))
  305. end
  306. },
  307. {"if clause",
  308. fun() ->
  309. Pid = whereis(crash),
  310. crash(if_clause),
  311. {_, _, Msg} = pop(),
  312. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no true branch found while evaluating if expression in crash:handle_call/3", [Pid])),
  313. test_body(Expected, lists:flatten(Msg))
  314. end
  315. },
  316. {"try clause",
  317. fun() ->
  318. Pid = whereis(crash),
  319. crash(try_clause),
  320. {_, _, Msg} = pop(),
  321. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no try clause matching [] in crash:handle_call/3", [Pid])),
  322. test_body(Expected, lists:flatten(Msg))
  323. end
  324. },
  325. {"undefined function",
  326. fun() ->
  327. Pid = whereis(crash),
  328. crash(undef),
  329. {_, _, Msg} = pop(),
  330. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: call to undefined function crash:booger/0 from crash:handle_call/3", [Pid])),
  331. test_body(Expected, lists:flatten(Msg))
  332. end
  333. },
  334. {"bad math",
  335. fun() ->
  336. Pid = whereis(crash),
  337. crash(badarith),
  338. {_, _, Msg} = pop(),
  339. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad arithmetic expression in crash:handle_call/3", [Pid])),
  340. test_body(Expected, lists:flatten(Msg))
  341. end
  342. },
  343. {"bad match",
  344. fun() ->
  345. Pid = whereis(crash),
  346. crash(badmatch),
  347. {_, _, Msg} = pop(),
  348. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no match of right hand value {} in crash:handle_call/3", [Pid])),
  349. test_body(Expected, lists:flatten(Msg))
  350. end
  351. },
  352. {"bad arity",
  353. fun() ->
  354. Pid = whereis(crash),
  355. crash(badarity),
  356. {_, _, Msg} = pop(),
  357. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: fun called with wrong arity of 1 instead of 3 in crash:handle_call/3", [Pid])),
  358. test_body(Expected, lists:flatten(Msg))
  359. end
  360. },
  361. {"bad arg1",
  362. fun() ->
  363. Pid = whereis(crash),
  364. crash(badarg1),
  365. {_, _, Msg} = pop(),
  366. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad argument in crash:handle_call/3", [Pid])),
  367. test_body(Expected, lists:flatten(Msg))
  368. end
  369. },
  370. {"bad arg2",
  371. fun() ->
  372. Pid = whereis(crash),
  373. crash(badarg2),
  374. {_, _, Msg} = pop(),
  375. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad argument in call to erlang:iolist_to_binary([\"foo\",bar]) in crash:handle_call/3", [Pid])),
  376. test_body(Expected, lists:flatten(Msg))
  377. end
  378. },
  379. {"bad record",
  380. fun() ->
  381. Pid = whereis(crash),
  382. crash(badrecord),
  383. {_, _, Msg} = pop(),
  384. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad record state in crash:handle_call/3", [Pid])),
  385. test_body(Expected, lists:flatten(Msg))
  386. end
  387. },
  388. {"noproc",
  389. fun() ->
  390. Pid = whereis(crash),
  391. crash(noproc),
  392. {_, _, Msg} = pop(),
  393. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no such process or port in call to gen_event:call(foo, bar, baz)", [Pid])),
  394. ?assertEqual(Expected, lists:flatten(Msg))
  395. end
  396. },
  397. {"badfun",
  398. fun() ->
  399. Pid = whereis(crash),
  400. crash(badfun),
  401. {_, _, Msg} = pop(),
  402. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad function booger in crash:handle_call/3", [Pid])),
  403. test_body(Expected, lists:flatten(Msg))
  404. end
  405. }
  406. ]
  407. }.
  408. error_logger_redirect_test_() ->
  409. {foreach,
  410. fun() ->
  411. error_logger:tty(false),
  412. application:load(lager),
  413. application:set_env(lager, error_logger_redirect, true),
  414. application:set_env(lager, handlers, [{?MODULE, info}]),
  415. application:start(lager),
  416. lager:log(error, self(), "flush flush"),
  417. timer:sleep(100),
  418. gen_event:call(lager_event, ?MODULE, flush)
  419. end,
  420. fun(_) ->
  421. application:stop(lager),
  422. error_logger:tty(true)
  423. end,
  424. [
  425. {"error reports are printed",
  426. fun() ->
  427. sync_error_logger:error_report([{this, is}, a, {silly, format}]),
  428. _ = gen_event:which_handlers(error_logger),
  429. {_, _, Msg} = pop(),
  430. Expected = lists:flatten(io_lib:format("[error] ~w this: is, a, silly: format", [self()])),
  431. ?assertEqual(Expected, lists:flatten(Msg))
  432. end
  433. },
  434. {"string error reports are printed",
  435. fun() ->
  436. sync_error_logger:error_report("this is less silly"),
  437. _ = gen_event:which_handlers(error_logger),
  438. {_, _, Msg} = pop(),
  439. Expected = lists:flatten(io_lib:format("[error] ~w this is less silly", [self()])),
  440. ?assertEqual(Expected, lists:flatten(Msg))
  441. end
  442. },
  443. {"error messages are printed",
  444. fun() ->
  445. sync_error_logger:error_msg("doom, doom has come upon you all"),
  446. _ = gen_event:which_handlers(error_logger),
  447. {_, _, Msg} = pop(),
  448. Expected = lists:flatten(io_lib:format("[error] ~w doom, doom has come upon you all", [self()])),
  449. ?assertEqual(Expected, lists:flatten(Msg))
  450. end
  451. },
  452. {"error messages are truncated at 4096 characters",
  453. fun() ->
  454. sync_error_logger:error_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
  455. _ = gen_event:which_handlers(error_logger),
  456. {_, _, Msg} = pop(),
  457. ?assert(length(lists:flatten(Msg)) < 5100)
  458. end
  459. },
  460. {"info reports are printed",
  461. fun() ->
  462. sync_error_logger:info_report([{this, is}, a, {silly, format}]),
  463. _ = gen_event:which_handlers(error_logger),
  464. {_, _, Msg} = pop(),
  465. Expected = lists:flatten(io_lib:format("[info] ~w this: is, a, silly: format", [self()])),
  466. ?assertEqual(Expected, lists:flatten(Msg))
  467. end
  468. },
  469. {"info reports are truncated at 4096 characters",
  470. fun() ->
  471. sync_error_logger:info_report([[{this, is}, a, {silly, format}] || _ <- lists:seq(0, 600)]),
  472. _ = gen_event:which_handlers(error_logger),
  473. {_, _, Msg} = pop(),
  474. ?assert(length(lists:flatten(Msg)) < 5000)
  475. end
  476. },
  477. {"single term info reports are printed",
  478. fun() ->
  479. sync_error_logger:info_report({foolish, bees}),
  480. _ = gen_event:which_handlers(error_logger),
  481. {_, _, Msg} = pop(),
  482. Expected = lists:flatten(io_lib:format("[info] ~w {foolish,bees}", [self()])),
  483. ?assertEqual(Expected, lists:flatten(Msg))
  484. end
  485. },
  486. {"single term error reports are printed",
  487. fun() ->
  488. sync_error_logger:error_report({foolish, bees}),
  489. _ = gen_event:which_handlers(error_logger),
  490. {_, _, Msg} = pop(),
  491. Expected = lists:flatten(io_lib:format("[error] ~w {foolish,bees}", [self()])),
  492. ?assertEqual(Expected, lists:flatten(Msg))
  493. end
  494. },
  495. {"string info reports are printed",
  496. fun() ->
  497. sync_error_logger:info_report("this is less silly"),
  498. _ = gen_event:which_handlers(error_logger),
  499. {_, _, Msg} = pop(),
  500. Expected = lists:flatten(io_lib:format("[info] ~w this is less silly", [self()])),
  501. ?assertEqual(Expected, lists:flatten(Msg))
  502. end
  503. },
  504. {"string info reports are truncated at 4096 characters",
  505. fun() ->
  506. sync_error_logger:info_report(string:copies("this is less silly", 1000)),
  507. _ = gen_event:which_handlers(error_logger),
  508. {_, _, Msg} = pop(),
  509. ?assert(length(lists:flatten(Msg)) < 5100)
  510. end
  511. },
  512. {"strings in a mixed report are printed as strings",
  513. fun() ->
  514. sync_error_logger:info_report(["this is less silly", {than, "this"}]),
  515. _ = gen_event:which_handlers(error_logger),
  516. {_, _, Msg} = pop(),
  517. Expected = lists:flatten(io_lib:format("[info] ~w \"this is less silly\", than: \"this\"", [self()])),
  518. ?assertEqual(Expected, lists:flatten(Msg))
  519. end
  520. },
  521. {"info messages are printed",
  522. fun() ->
  523. sync_error_logger:info_msg("doom, doom has come upon you all"),
  524. _ = gen_event:which_handlers(error_logger),
  525. {_, _, Msg} = pop(),
  526. Expected = lists:flatten(io_lib:format("[info] ~w doom, doom has come upon you all", [self()])),
  527. ?assertEqual(Expected, lists:flatten(Msg))
  528. end
  529. },
  530. {"info messages are truncated at 4096 characters",
  531. fun() ->
  532. sync_error_logger:info_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
  533. _ = gen_event:which_handlers(error_logger),
  534. {_, _, Msg} = pop(),
  535. ?assert(length(lists:flatten(Msg)) < 5100)
  536. end
  537. },
  538. {"warning messages are printed at the correct level",
  539. fun() ->
  540. sync_error_logger:warning_msg("doom, doom has come upon you all"),
  541. Map = error_logger:warning_map(),
  542. _ = gen_event:which_handlers(error_logger),
  543. {_, _, Msg} = pop(),
  544. Expected = lists:flatten(io_lib:format("[~w] ~w doom, doom has come upon you all", [Map, self()])),
  545. ?assertEqual(Expected, lists:flatten(Msg))
  546. end
  547. },
  548. {"warning reports are printed at the correct level",
  549. fun() ->
  550. sync_error_logger:warning_report([{i, like}, pie]),
  551. Map = error_logger:warning_map(),
  552. _ = gen_event:which_handlers(error_logger),
  553. {_, _, Msg} = pop(),
  554. Expected = lists:flatten(io_lib:format("[~w] ~w i: like, pie", [Map, self()])),
  555. ?assertEqual(Expected, lists:flatten(Msg))
  556. end
  557. },
  558. {"single term warning reports are printed at the correct level",
  559. fun() ->
  560. sync_error_logger:warning_report({foolish, bees}),
  561. Map = error_logger:warning_map(),
  562. _ = gen_event:which_handlers(error_logger),
  563. {_, _, Msg} = pop(),
  564. Expected = lists:flatten(io_lib:format("[~w] ~w {foolish,bees}", [Map, self()])),
  565. ?assertEqual(Expected, lists:flatten(Msg))
  566. end
  567. },
  568. {"application stop reports",
  569. fun() ->
  570. sync_error_logger:info_report([{application, foo}, {exited, quittin_time}, {type, lazy}]),
  571. _ = gen_event:which_handlers(error_logger),
  572. {_, _, Msg} = pop(),
  573. Expected = lists:flatten(io_lib:format("[info] ~w Application foo exited with reason: quittin_time", [self()])),
  574. ?assertEqual(Expected, lists:flatten(Msg))
  575. end
  576. },
  577. {"supervisor reports",
  578. fun() ->
  579. sync_error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{name, mini_steve}, {mfargs, {a, b, [c]}}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
  580. _ = gen_event:which_handlers(error_logger),
  581. {_, _, Msg} = pop(),
  582. Expected = lists:flatten(io_lib:format("[error] ~w Supervisor steve had child mini_steve started with a:b(c) at bleh exit with reason fired in context france", [self()])),
  583. ?assertEqual(Expected, lists:flatten(Msg))
  584. end
  585. },
  586. {"supervisor reports with real error",
  587. fun() ->
  588. sync_error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{name, mini_steve}, {mfargs, {a, b, [c]}}, {pid, bleh}]}, {reason, {function_clause,[{crash,handle_info,[foo]}]}}, {supervisor, {local, steve}}]),
  589. _ = gen_event:which_handlers(error_logger),
  590. {_, _, Msg} = pop(),
  591. Expected = lists:flatten(io_lib:format("[error] ~w Supervisor steve had child mini_steve started with a:b(c) at bleh exit with reason no function clause matching crash:handle_info(foo) in context france", [self()])),
  592. ?assertEqual(Expected, lists:flatten(Msg))
  593. end
  594. },
  595. {"supervisor_bridge reports",
  596. fun() ->
  597. sync_error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{mod, mini_steve}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
  598. _ = gen_event:which_handlers(error_logger),
  599. {_, _, Msg} = pop(),
  600. Expected = lists:flatten(io_lib:format("[error] ~w Supervisor steve had child at module mini_steve at bleh exit with reason fired in context france", [self()])),
  601. ?assertEqual(Expected, lists:flatten(Msg))
  602. end
  603. },
  604. {"application progress report",
  605. fun() ->
  606. sync_error_logger:info_report(progress, [{application, foo}, {started_at, node()}]),
  607. _ = gen_event:which_handlers(error_logger),
  608. {_, _, Msg} = pop(),
  609. Expected = lists:flatten(io_lib:format("[info] ~w Application foo started on node ~w", [self(), node()])),
  610. ?assertEqual(Expected, lists:flatten(Msg))
  611. end
  612. },
  613. {"supervisor progress report",
  614. fun() ->
  615. lager:set_loglevel(?MODULE, debug),
  616. sync_error_logger:info_report(progress, [{supervisor, {local, foo}}, {started, [{mfargs, {foo, bar, 1}}, {pid, baz}]}]),
  617. _ = gen_event:which_handlers(error_logger),
  618. {_, _, Msg} = pop(),
  619. Expected = lists:flatten(io_lib:format("[debug] ~w Supervisor foo started foo:bar/1 at pid baz", [self()])),
  620. ?assertEqual(Expected, lists:flatten(Msg))
  621. end
  622. },
  623. {"crash report for emfile",
  624. fun() ->
  625. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {emfile, [{stack, trace, 1}]}, []}}], []]),
  626. _ = gen_event:which_handlers(error_logger),
  627. {_, _, Msg} = pop(),
  628. Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: maximum number of file descriptors exhausted, check ulimit -n", [self(), self()])),
  629. ?assertEqual(Expected, lists:flatten(Msg))
  630. end
  631. },
  632. {"crash report for system process limit",
  633. fun() ->
  634. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, spawn, 1}]}, []}}], []]),
  635. _ = gen_event:which_handlers(error_logger),
  636. {_, _, Msg} = pop(),
  637. Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of processes exceeded", [self(), self()])),
  638. ?assertEqual(Expected, lists:flatten(Msg))
  639. end
  640. },
  641. {"crash report for system process limit2",
  642. fun() ->
  643. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, spawn_opt, 1}]}, []}}], []]),
  644. _ = gen_event:which_handlers(error_logger),
  645. {_, _, Msg} = pop(),
  646. Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of processes exceeded", [self(), self()])),
  647. ?assertEqual(Expected, lists:flatten(Msg))
  648. end
  649. },
  650. {"crash report for system port limit",
  651. fun() ->
  652. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, open_port, 1}]}, []}}], []]),
  653. _ = gen_event:which_handlers(error_logger),
  654. {_, _, Msg} = pop(),
  655. Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of ports exceeded", [self(), self()])),
  656. ?assertEqual(Expected, lists:flatten(Msg))
  657. end
  658. },
  659. {"crash report for system port limit",
  660. fun() ->
  661. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, list_to_atom, 1}]}, []}}], []]),
  662. _ = gen_event:which_handlers(error_logger),
  663. {_, _, Msg} = pop(),
  664. Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: tried to create an atom larger than 255, or maximum atom count exceeded", [self(), self()])),
  665. ?assertEqual(Expected, lists:flatten(Msg))
  666. end
  667. },
  668. {"crash report for system ets table limit",
  669. fun() ->
  670. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, test}, {error_info, {error, {system_limit,[{ets,new,[segment_offsets,[ordered_set,public]]},{mi_segment,open_write,1},{mi_buffer_converter,handle_cast,2},{gen_server,handle_msg,5},{proc_lib,init_p_do_apply,3}]}, []}}], []]),
  671. _ = gen_event:which_handlers(error_logger),
  672. {_, _, Msg} = pop(),
  673. Expected = lists:flatten(io_lib:format("[error] ~w CRASH REPORT Process ~w with 0 neighbours crashed with reason: system limit: maximum number of ETS tables exceeded", [self(), test])),
  674. ?assertEqual(Expected, lists:flatten(Msg))
  675. end
  676. },
  677. {"crash report for unknown system limit should be truncated at 500 characters",
  678. fun() ->
  679. sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit,[{wtf,boom,[string:copies("aaaa", 4096)]}]}, []}}], []]),
  680. _ = gen_event:which_handlers(error_logger),
  681. {_, _, Msg} = pop(),
  682. ?assert(length(lists:flatten(Msg)) > 600),
  683. ?assert(length(lists:flatten(Msg)) < 650)
  684. end
  685. },
  686. {"crash reports for 'special processes' should be handled right",
  687. fun() ->
  688. {ok, Pid} = special_process:start(),
  689. unlink(Pid),
  690. Pid ! function_clause,
  691. timer:sleep(500),
  692. _ = gen_event:which_handlers(error_logger),
  693. {_, _, Msg} = pop(),
  694. Expected = lists:flatten(io_lib:format("[error] ~p CRASH REPORT Process ~p with 0 neighbours crashed with reason: no function clause matching special_process:foo(bar)",
  695. [Pid, Pid])),
  696. test_body(Expected, lists:flatten(Msg))
  697. end
  698. },
  699. {"messages should not be generated if they don't satisfy the threshold",
  700. fun() ->
  701. lager:set_loglevel(?MODULE, error),
  702. sync_error_logger:info_report([hello, world]),
  703. _ = gen_event:which_handlers(error_logger),
  704. ?assertEqual(0, count()),
  705. ?assertEqual(0, count_ignored()),
  706. lager:set_loglevel(?MODULE, info),
  707. sync_error_logger:info_report([hello, world]),
  708. _ = gen_event:which_handlers(error_logger),
  709. ?assertEqual(1, count()),
  710. ?assertEqual(0, count_ignored()),
  711. lager:set_loglevel(?MODULE, error),
  712. lager_mochiglobal:put(loglevel, {?DEBUG, []}),
  713. sync_error_logger:info_report([hello, world]),
  714. _ = gen_event:which_handlers(error_logger),
  715. ?assertEqual(1, count()),
  716. ?assertEqual(1, count_ignored())
  717. end
  718. }
  719. ]
  720. }.
  721. safe_format_test() ->
  722. ?assertEqual("foo bar", lists:flatten(lager:safe_format("~p ~p", [foo, bar], 1024))),
  723. ?assertEqual("FORMAT ERROR: \"~p ~p ~p\" [foo,bar]", lists:flatten(lager:safe_format("~p ~p ~p", [foo, bar], 1024))),
  724. ok.
  725. -endif.