您最多选择25个主题 主题必须以字母或数字开头,可以包含连字符 (-),并且长度不得超过35个字符

731 行
37 KiB

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