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

731 行
36 KiB

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. not_running_test() ->
  73. ?assertEqual({error, lager_not_running}, lager:log(info, self(), "not running")).
  74. lager_test_() ->
  75. {foreach,
  76. fun setup/0,
  77. fun cleanup/1,
  78. [
  79. {"observe that there is nothing up my sleeve",
  80. fun() ->
  81. ?assertEqual(undefined, pop()),
  82. ?assertEqual(0, count())
  83. end
  84. },
  85. {"logging works",
  86. fun() ->
  87. lager:warning("test message"),
  88. ?assertEqual(1, count()),
  89. {Level, _Time, Message} = pop(),
  90. ?assertMatch(Level, lager_util:level_to_num(warning)),
  91. [LevelStr, _LocStr, MsgStr] = re:split(Message, " ", [{return, list}, {parts, 3}]),
  92. ?assertEqual("[warning]", LevelStr),
  93. ?assertEqual("test message", MsgStr),
  94. ok
  95. end
  96. },
  97. {"logging with arguments works",
  98. fun() ->
  99. lager:warning("test message ~p", [self()]),
  100. ?assertEqual(1, count()),
  101. {Level, _Time, Message} = pop(),
  102. ?assertMatch(Level, lager_util:level_to_num(warning)),
  103. [LevelStr, _LocStr, MsgStr] = re:split(Message, " ", [{return, list}, {parts, 3}]),
  104. ?assertEqual("[warning]", LevelStr),
  105. ?assertEqual(lists:flatten(io_lib:format("test message ~p", [self()])), MsgStr),
  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(lager),
  209. gen_event:call(lager_event, ?MODULE, flush).
  210. cleanup(_) ->
  211. application:stop(lager),
  212. error_logger:tty(true).
  213. crash(Type) ->
  214. spawn(fun() -> gen_server:call(crash, Type) end),
  215. timer:sleep(100),
  216. _ = gen_event:which_handlers(error_logger),
  217. ok.
  218. error_logger_redirect_crash_test_() ->
  219. {foreach,
  220. fun() ->
  221. error_logger:tty(false),
  222. application:load(lager),
  223. application:set_env(lager, error_logger_redirect, true),
  224. application:set_env(lager, handlers, [{?MODULE, error}]),
  225. application:start(lager),
  226. crash:start()
  227. end,
  228. fun(_) ->
  229. application:stop(lager),
  230. case whereis(crash) of
  231. undefined -> ok;
  232. Pid -> exit(Pid, kill)
  233. end,
  234. error_logger:tty(true)
  235. end,
  236. [
  237. {"again, there is nothing up my sleeve",
  238. fun() ->
  239. ?assertEqual(undefined, pop()),
  240. ?assertEqual(0, count())
  241. end
  242. },
  243. {"bad return value",
  244. fun() ->
  245. Pid = whereis(crash),
  246. crash(bad_return),
  247. {_, _, Msg} = pop(),
  248. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad return value: bleh", [Pid])),
  249. ?assertEqual(Expected, lists:flatten(Msg))
  250. end
  251. },
  252. {"bad return value with string",
  253. fun() ->
  254. Pid = whereis(crash),
  255. crash(bad_return_string),
  256. {_, _, Msg} = pop(),
  257. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad return value: {tuple,{tuple,\"string\"}}", [Pid])),
  258. ?assertEqual(Expected, lists:flatten(Msg))
  259. end
  260. },
  261. {"case clause",
  262. fun() ->
  263. Pid = whereis(crash),
  264. crash(case_clause),
  265. {_, _, Msg} = pop(),
  266. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no case clause matching {} in crash:handle_call/3", [Pid])),
  267. ?assertEqual(Expected, lists:flatten(Msg))
  268. end
  269. },
  270. {"case clause string",
  271. fun() ->
  272. Pid = whereis(crash),
  273. crash(case_clause_string),
  274. {_, _, Msg} = pop(),
  275. 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])),
  276. ?assertEqual(Expected, lists:flatten(Msg))
  277. end
  278. },
  279. {"function clause",
  280. fun() ->
  281. Pid = whereis(crash),
  282. crash(function_clause),
  283. {_, _, Msg} = pop(),
  284. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no function clause matching crash:function({})", [Pid])),
  285. ?assertEqual(Expected, lists:flatten(Msg))
  286. end
  287. },
  288. {"if clause",
  289. fun() ->
  290. Pid = whereis(crash),
  291. crash(if_clause),
  292. {_, _, Msg} = pop(),
  293. 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])),
  294. ?assertEqual(Expected, lists:flatten(Msg))
  295. end
  296. },
  297. {"try clause",
  298. fun() ->
  299. Pid = whereis(crash),
  300. crash(try_clause),
  301. {_, _, Msg} = pop(),
  302. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: no try clause matching [] in crash:handle_call/3", [Pid])),
  303. ?assertEqual(Expected, lists:flatten(Msg))
  304. end
  305. },
  306. {"undefined function",
  307. fun() ->
  308. Pid = whereis(crash),
  309. crash(undef),
  310. {_, _, Msg} = pop(),
  311. 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])),
  312. ?assertEqual(Expected, lists:flatten(Msg))
  313. end
  314. },
  315. {"bad math",
  316. fun() ->
  317. Pid = whereis(crash),
  318. crash(badarith),
  319. {_, _, Msg} = pop(),
  320. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad arithmetic expression in crash:handle_call/3", [Pid])),
  321. ?assertEqual(Expected, lists:flatten(Msg))
  322. end
  323. },
  324. {"bad match",
  325. fun() ->
  326. Pid = whereis(crash),
  327. crash(badmatch),
  328. {_, _, Msg} = pop(),
  329. 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])),
  330. ?assertEqual(Expected, lists:flatten(Msg))
  331. end
  332. },
  333. {"bad arity",
  334. fun() ->
  335. Pid = whereis(crash),
  336. crash(badarity),
  337. {_, _, Msg} = pop(),
  338. 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])),
  339. ?assertEqual(Expected, lists:flatten(Msg))
  340. end
  341. },
  342. {"bad arg1",
  343. fun() ->
  344. Pid = whereis(crash),
  345. crash(badarg1),
  346. {_, _, Msg} = pop(),
  347. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad argument in crash:handle_call/3", [Pid])),
  348. ?assertEqual(Expected, lists:flatten(Msg))
  349. end
  350. },
  351. {"bad arg2",
  352. fun() ->
  353. Pid = whereis(crash),
  354. crash(badarg2),
  355. {_, _, Msg} = pop(),
  356. 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])),
  357. ?assertEqual(Expected, lists:flatten(Msg))
  358. end
  359. },
  360. {"noproc",
  361. fun() ->
  362. Pid = whereis(crash),
  363. crash(noproc),
  364. {_, _, Msg} = pop(),
  365. 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])),
  366. ?assertEqual(Expected, lists:flatten(Msg))
  367. end
  368. },
  369. {"badfun",
  370. fun() ->
  371. Pid = whereis(crash),
  372. crash(badfun),
  373. {_, _, Msg} = pop(),
  374. Expected = lists:flatten(io_lib:format("[error] ~w gen_server crash terminated with reason: bad function booger in crash:handle_call/3", [Pid])),
  375. ?assertEqual(Expected, lists:flatten(Msg))
  376. end
  377. }
  378. ]
  379. }.
  380. error_logger_redirect_test_() ->
  381. {foreach,
  382. fun() ->
  383. error_logger:tty(false),
  384. application:load(lager),
  385. application:set_env(lager, error_logger_redirect, true),
  386. application:set_env(lager, handlers, [{?MODULE, info}]),
  387. application:start(lager),
  388. lager:log(error, self(), "flush flush"),
  389. timer:sleep(100),
  390. gen_event:call(lager_event, ?MODULE, flush)
  391. end,
  392. fun(_) ->
  393. application:stop(lager),
  394. error_logger:tty(true)
  395. end,
  396. [
  397. {"error reports are printed",
  398. fun() ->
  399. sync_error_logger:error_report([{this, is}, a, {silly, format}]),
  400. _ = gen_event:which_handlers(error_logger),
  401. {_, _, Msg} = pop(),
  402. Expected = lists:flatten(io_lib:format("[error] ~w this: is, a, silly: format", [self()])),
  403. ?assertEqual(Expected, lists:flatten(Msg))
  404. end
  405. },
  406. {"string error reports are printed",
  407. fun() ->
  408. sync_error_logger:error_report("this is less silly"),
  409. _ = gen_event:which_handlers(error_logger),
  410. {_, _, Msg} = pop(),
  411. Expected = lists:flatten(io_lib:format("[error] ~w this is less silly", [self()])),
  412. ?assertEqual(Expected, lists:flatten(Msg))
  413. end
  414. },
  415. {"error messages are printed",
  416. fun() ->
  417. sync_error_logger:error_msg("doom, doom has come upon you all"),
  418. _ = gen_event:which_handlers(error_logger),
  419. {_, _, Msg} = pop(),
  420. Expected = lists:flatten(io_lib:format("[error] ~w doom, doom has come upon you all", [self()])),
  421. ?assertEqual(Expected, lists:flatten(Msg))
  422. end
  423. },
  424. {"error messages are truncated at 4096 characters",
  425. fun() ->
  426. sync_error_logger:error_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
  427. _ = gen_event:which_handlers(error_logger),
  428. {_, _, Msg} = pop(),
  429. ?assert(length(lists:flatten(Msg)) < 5100)
  430. end
  431. },
  432. {"info reports are printed",
  433. fun() ->
  434. sync_error_logger:info_report([{this, is}, a, {silly, format}]),
  435. _ = gen_event:which_handlers(error_logger),
  436. {_, _, Msg} = pop(),
  437. Expected = lists:flatten(io_lib:format("[info] ~w this: is, a, silly: format", [self()])),
  438. ?assertEqual(Expected, lists:flatten(Msg))
  439. end
  440. },
  441. {"info reports are truncated at 4096 characters",
  442. fun() ->
  443. sync_error_logger:info_report([[{this, is}, a, {silly, format}] || _ <- lists:seq(0, 600)]),
  444. _ = gen_event:which_handlers(error_logger),
  445. {_, _, Msg} = pop(),
  446. ?assert(length(lists:flatten(Msg)) < 5000)
  447. end
  448. },
  449. {"single term info reports are printed",
  450. fun() ->
  451. sync_error_logger:info_report({foolish, bees}),
  452. _ = gen_event:which_handlers(error_logger),
  453. {_, _, Msg} = pop(),
  454. Expected = lists:flatten(io_lib:format("[info] ~w {foolish,bees}", [self()])),
  455. ?assertEqual(Expected, lists:flatten(Msg))
  456. end
  457. },
  458. {"single term error reports are printed",
  459. fun() ->
  460. sync_error_logger:error_report({foolish, bees}),
  461. _ = gen_event:which_handlers(error_logger),
  462. {_, _, Msg} = pop(),
  463. Expected = lists:flatten(io_lib:format("[error] ~w {foolish,bees}", [self()])),
  464. ?assertEqual(Expected, lists:flatten(Msg))
  465. end
  466. },
  467. {"string info reports are printed",
  468. fun() ->
  469. sync_error_logger:info_report("this is less silly"),
  470. _ = gen_event:which_handlers(error_logger),
  471. {_, _, Msg} = pop(),
  472. Expected = lists:flatten(io_lib:format("[info] ~w this is less silly", [self()])),
  473. ?assertEqual(Expected, lists:flatten(Msg))
  474. end
  475. },
  476. {"string info reports are truncated at 4096 characters",
  477. fun() ->
  478. sync_error_logger:info_report(string:copies("this is less silly", 1000)),
  479. _ = gen_event:which_handlers(error_logger),
  480. {_, _, Msg} = pop(),
  481. ?assert(length(lists:flatten(Msg)) < 5100)
  482. end
  483. },
  484. {"strings in a mixed report are printed as strings",
  485. fun() ->
  486. sync_error_logger:info_report(["this is less silly", {than, "this"}]),
  487. _ = gen_event:which_handlers(error_logger),
  488. {_, _, Msg} = pop(),
  489. Expected = lists:flatten(io_lib:format("[info] ~w \"this is less silly\", than: \"this\"", [self()])),
  490. ?assertEqual(Expected, lists:flatten(Msg))
  491. end
  492. },
  493. {"info messages are printed",
  494. fun() ->
  495. sync_error_logger:info_msg("doom, doom has come upon you all"),
  496. _ = gen_event:which_handlers(error_logger),
  497. {_, _, Msg} = pop(),
  498. Expected = lists:flatten(io_lib:format("[info] ~w doom, doom has come upon you all", [self()])),
  499. ?assertEqual(Expected, lists:flatten(Msg))
  500. end
  501. },
  502. {"info messages are truncated at 4096 characters",
  503. fun() ->
  504. sync_error_logger:info_msg("doom, doom has come upon you all ~p", [string:copies("doom", 10000)]),
  505. _ = gen_event:which_handlers(error_logger),
  506. {_, _, Msg} = pop(),
  507. ?assert(length(lists:flatten(Msg)) < 5100)
  508. end
  509. },
  510. {"warning messages are printed at the correct level",
  511. fun() ->
  512. sync_error_logger:warning_msg("doom, doom has come upon you all"),
  513. Map = error_logger:warning_map(),
  514. _ = gen_event:which_handlers(error_logger),
  515. {_, _, Msg} = pop(),
  516. Expected = lists:flatten(io_lib:format("[~w] ~w doom, doom has come upon you all", [Map, self()])),
  517. ?assertEqual(Expected, lists:flatten(Msg))
  518. end
  519. },
  520. {"warning reports are printed at the correct level",
  521. fun() ->
  522. sync_error_logger:warning_report([{i, like}, pie]),
  523. Map = error_logger:warning_map(),
  524. _ = gen_event:which_handlers(error_logger),
  525. {_, _, Msg} = pop(),
  526. Expected = lists:flatten(io_lib:format("[~w] ~w i: like, pie", [Map, self()])),
  527. ?assertEqual(Expected, lists:flatten(Msg))
  528. end
  529. },
  530. {"single term warning reports are printed at the correct level",
  531. fun() ->
  532. sync_error_logger:warning_report({foolish, bees}),
  533. Map = error_logger:warning_map(),
  534. _ = gen_event:which_handlers(error_logger),
  535. {_, _, Msg} = pop(),
  536. Expected = lists:flatten(io_lib:format("[~w] ~w {foolish,bees}", [Map, self()])),
  537. ?assertEqual(Expected, lists:flatten(Msg))
  538. end
  539. },
  540. {"application stop reports",
  541. fun() ->
  542. sync_error_logger:info_report([{application, foo}, {exited, quittin_time}, {type, lazy}]),
  543. _ = gen_event:which_handlers(error_logger),
  544. {_, _, Msg} = pop(),
  545. Expected = lists:flatten(io_lib:format("[info] ~w Application foo exited with reason: quittin_time", [self()])),
  546. ?assertEqual(Expected, lists:flatten(Msg))
  547. end
  548. },
  549. {"supervisor reports",
  550. fun() ->
  551. sync_error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{name, mini_steve}, {mfargs, {a, b, [c]}}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
  552. _ = gen_event:which_handlers(error_logger),
  553. {_, _, Msg} = pop(),
  554. 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()])),
  555. ?assertEqual(Expected, lists:flatten(Msg))
  556. end
  557. },
  558. {"supervisor reports with real error",
  559. fun() ->
  560. 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}}]),
  561. _ = gen_event:which_handlers(error_logger),
  562. {_, _, Msg} = pop(),
  563. 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()])),
  564. ?assertEqual(Expected, lists:flatten(Msg))
  565. end
  566. },
  567. {"supervisor_bridge reports",
  568. fun() ->
  569. sync_error_logger:error_report(supervisor_report, [{errorContext, france}, {offender, [{mod, mini_steve}, {pid, bleh}]}, {reason, fired}, {supervisor, {local, steve}}]),
  570. _ = gen_event:which_handlers(error_logger),
  571. {_, _, Msg} = pop(),
  572. 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()])),
  573. ?assertEqual(Expected, lists:flatten(Msg))
  574. end
  575. },
  576. {"application progress report",
  577. fun() ->
  578. sync_error_logger:info_report(progress, [{application, foo}, {started_at, node()}]),
  579. _ = gen_event:which_handlers(error_logger),
  580. {_, _, Msg} = pop(),
  581. Expected = lists:flatten(io_lib:format("[info] ~w Application foo started on node ~w", [self(), node()])),
  582. ?assertEqual(Expected, lists:flatten(Msg))
  583. end
  584. },
  585. {"supervisor progress report",
  586. fun() ->
  587. lager:set_loglevel(?MODULE, debug),
  588. sync_error_logger:info_report(progress, [{supervisor, {local, foo}}, {started, [{mfargs, {foo, bar, 1}}, {pid, baz}]}]),
  589. _ = gen_event:which_handlers(error_logger),
  590. {_, _, Msg} = pop(),
  591. Expected = lists:flatten(io_lib:format("[debug] ~w Supervisor foo started foo:bar/1 at pid baz", [self()])),
  592. ?assertEqual(Expected, lists:flatten(Msg))
  593. end
  594. },
  595. {"crash report for emfile",
  596. fun() ->
  597. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {emfile, [{stack, trace, 1}]}, []}}], []]),
  598. _ = gen_event:which_handlers(error_logger),
  599. {_, _, Msg} = pop(),
  600. 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()])),
  601. ?assertEqual(Expected, lists:flatten(Msg))
  602. end
  603. },
  604. {"crash report for system process limit",
  605. fun() ->
  606. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, spawn, 1}]}, []}}], []]),
  607. _ = gen_event:which_handlers(error_logger),
  608. {_, _, Msg} = pop(),
  609. 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()])),
  610. ?assertEqual(Expected, lists:flatten(Msg))
  611. end
  612. },
  613. {"crash report for system process limit2",
  614. fun() ->
  615. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, spawn_opt, 1}]}, []}}], []]),
  616. _ = gen_event:which_handlers(error_logger),
  617. {_, _, Msg} = pop(),
  618. 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()])),
  619. ?assertEqual(Expected, lists:flatten(Msg))
  620. end
  621. },
  622. {"crash report for system port limit",
  623. fun() ->
  624. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, open_port, 1}]}, []}}], []]),
  625. _ = gen_event:which_handlers(error_logger),
  626. {_, _, Msg} = pop(),
  627. 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()])),
  628. ?assertEqual(Expected, lists:flatten(Msg))
  629. end
  630. },
  631. {"crash report for system port limit",
  632. fun() ->
  633. sync_error_logger:error_report(crash_report, [[{pid, self()}, {registered_name, []}, {error_info, {error, {system_limit, [{erlang, list_to_atom, 1}]}, []}}], []]),
  634. _ = gen_event:which_handlers(error_logger),
  635. {_, _, Msg} = pop(),
  636. 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()])),
  637. ?assertEqual(Expected, lists:flatten(Msg))
  638. end
  639. },
  640. {"crash report for system ets table limit",
  641. fun() ->
  642. 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}]}, []}}], []]),
  643. _ = gen_event:which_handlers(error_logger),
  644. {_, _, Msg} = pop(),
  645. 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])),
  646. ?assertEqual(Expected, lists:flatten(Msg))
  647. end
  648. },
  649. {"crash report for unknown system limit should be truncated at 500 characters",
  650. fun() ->
  651. sync_error_logger:error_report(crash_report, [[{pid, self()}, {error_info, {error, {system_limit,[{wtf,boom,[string:copies("aaaa", 4096)]}]}, []}}], []]),
  652. _ = gen_event:which_handlers(error_logger),
  653. {_, _, Msg} = pop(),
  654. ?assert(length(lists:flatten(Msg)) > 600),
  655. ?assert(length(lists:flatten(Msg)) < 650)
  656. end
  657. },
  658. {"crash reports for 'special processes' should be handled right",
  659. fun() ->
  660. {ok, Pid} = special_process:start(),
  661. unlink(Pid),
  662. Pid ! function_clause,
  663. timer:sleep(500),
  664. _ = gen_event:which_handlers(error_logger),
  665. {_, _, Msg} = pop(),
  666. 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)",
  667. [Pid, Pid])),
  668. ?assertEqual(Expected, lists:flatten(Msg))
  669. end
  670. },
  671. {"messages should not be generated if they don't satisfy the threshold",
  672. fun() ->
  673. lager:set_loglevel(?MODULE, error),
  674. sync_error_logger:info_report([hello, world]),
  675. _ = gen_event:which_handlers(error_logger),
  676. ?assertEqual(0, count()),
  677. ?assertEqual(0, count_ignored()),
  678. lager:set_loglevel(?MODULE, info),
  679. sync_error_logger:info_report([hello, world]),
  680. _ = gen_event:which_handlers(error_logger),
  681. ?assertEqual(1, count()),
  682. ?assertEqual(0, count_ignored()),
  683. lager:set_loglevel(?MODULE, error),
  684. lager_mochiglobal:put(loglevel, {?DEBUG, []}),
  685. sync_error_logger:info_report([hello, world]),
  686. _ = gen_event:which_handlers(error_logger),
  687. ?assertEqual(1, count()),
  688. ?assertEqual(1, count_ignored())
  689. end
  690. }
  691. ]
  692. }.
  693. safe_format_test() ->
  694. ?assertEqual("foo bar", lists:flatten(lager:safe_format("~p ~p", [foo, bar], 1024))),
  695. ?assertEqual("FORMAT ERROR: \"~p ~p ~p\" [foo,bar]", lists:flatten(lager:safe_format("~p ~p ~p", [foo, bar], 1024))),
  696. ok.
  697. -endif.