Skip to content

Commit

Permalink
Fixup the tests after merging in the rotation code
Browse files Browse the repository at this point in the history
  • Loading branch information
Vagabond committed Aug 17, 2011
1 parent 116ee8d commit d828c35
Show file tree
Hide file tree
Showing 6 changed files with 146 additions and 53 deletions.
10 changes: 10 additions & 0 deletions include/lager.hrl
Expand Up @@ -63,6 +63,15 @@
%% internal non-blocking logging call
%% there's some special handing for when we try to log (usually errors) while
%% lager is still starting.
-ifdef(TEST).
-define(INT_LOG(Level, Format, Args),
case ?SHOULD_LOG(Level) of
true ->
?NOTIFY(Level, self(), Format, Args);
_ ->
ok
end).
-else.
-define(INT_LOG(Level, Format, Args),
Self = self(),
%% do this in a spawn so we don't cause a deadlock calling gen_event:which_handlers
Expand All @@ -83,3 +92,4 @@
end
end
end)).
-endif.
4 changes: 2 additions & 2 deletions src/lager_console_backend.erl
Expand Up @@ -99,7 +99,7 @@ console_log_test_() ->
end,
fun(_) ->
application:stop(lager),
application:load(lager),
application:unload(lager),
error_logger:tty(true)
end,
[
Expand Down Expand Up @@ -150,7 +150,7 @@ set_loglevel_test_() ->
end,
fun(_) ->
application:stop(lager),
application:load(lager),
application:unload(lager),
error_logger:tty(true)
end,
[
Expand Down
54 changes: 27 additions & 27 deletions src/lager_crash_log.erl
Expand Up @@ -226,7 +226,7 @@ sasl_limited_str(crash_report, Report, FmtMaxBytes) ->
filesystem_test_() ->
{foreach,
fun() ->
file:write_file("test.log", ""),
file:write_file("crash_test.log", ""),
error_logger:tty(false),
application:load(lager),
application:set_env(lager, handlers, [{lager_test_backend, info}]),
Expand All @@ -242,85 +242,85 @@ filesystem_test_() ->
exit(P, kill);
_ -> ok
end,
file:delete("test.log"),
file:delete("crash_test.log"),
application:stop(lager),
application:unload(lager),
error_logger:tty(true)
end,
[
{"under normal circumstances, file should be opened",
fun() ->
{ok, _} = ?MODULE:start_link("test.log", 65535),
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
error_logger:error_msg("Test message\n"),
timer:sleep(100),
{ok, Bin} = file:read_file("test.log"),
{ok, Bin} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message\n"], re:split(Bin, "\n", [{return, list}, {parts, 2}]))
end
},
{"file can't be opened on startup triggers an error message",
fun() ->
{ok, FInfo} = file:read_file_info("test.log"),
file:write_file_info("test.log", FInfo#file_info{mode = 0}),
{ok, _} = ?MODULE:start_link("test.log", 65535),
{ok, FInfo} = file:read_file_info("crash_test.log"),
file:write_file_info("crash_test.log", FInfo#file_info{mode = 0}),
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
?assertEqual(1, lager_test_backend:count()),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Failed to open crash log file test.log with error: permission denied", lists:flatten(Message))
?assertEqual("Failed to open crash log file crash_test.log with error: permission denied", lists:flatten(Message))
end
},
{"file that becomes unavailable at runtime should trigger an error message",
fun() ->
{ok, _} = ?MODULE:start_link("test.log", 65535),
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
?assertEqual(0, lager_test_backend:count()),
error_logger:error_msg("Test message\n"),
timer:sleep(100),
?assertEqual(1, lager_test_backend:count()),
file:delete("test.log"),
file:write_file("test.log", ""),
{ok, FInfo} = file:read_file_info("test.log"),
file:write_file_info("test.log", FInfo#file_info{mode = 0}),
file:delete("crash_test.log"),
file:write_file("crash_test.log", ""),
{ok, FInfo} = file:read_file_info("crash_test.log"),
file:write_file_info("crash_test.log", FInfo#file_info{mode = 0}),
error_logger:error_msg("Test message\n"),
timer:sleep(100),
?assertEqual(3, lager_test_backend:count()),
lager_test_backend:pop(),
lager_test_backend:pop(),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Failed to reopen crash log test.log with error: permission denied", lists:flatten(Message))
?assertEqual("Failed to reopen crash log crash_test.log with error: permission denied", lists:flatten(Message))
end
},
{"unavailable files that are fixed at runtime should start having log messages written",
fun() ->
{ok, FInfo} = file:read_file_info("test.log"),
{ok, FInfo} = file:read_file_info("crash_test.log"),
OldPerms = FInfo#file_info.mode,
file:write_file_info("test.log", FInfo#file_info{mode = 0}),
{ok, _} = ?MODULE:start_link("test.log", 65535),
file:write_file_info("crash_test.log", FInfo#file_info{mode = 0}),
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
?assertEqual(1, lager_test_backend:count()),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Failed to open crash log file test.log with error: permission denied", lists:flatten(Message)),
file:write_file_info("test.log", FInfo#file_info{mode = OldPerms}),
?assertEqual("Failed to open crash log file crash_test.log with error: permission denied", lists:flatten(Message)),
file:write_file_info("crash_test.log", FInfo#file_info{mode = OldPerms}),
error_logger:error_msg("Test message~n"),
timer:sleep(100),
{ok, Bin} = file:read_file("test.log"),
{ok, Bin} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message\n"], re:split(Bin, "\n", [{return, list}, {parts, 2}]))
end
},
{"external logfile rotation/deletion should be handled",
fun() ->
{ok, _} = ?MODULE:start_link("test.log", 65535),
{ok, _} = ?MODULE:start_link("crash_test.log", 65535, 0, undefined, 0),
?assertEqual(0, lager_test_backend:count()),
error_logger:error_msg("Test message~n"),
timer:sleep(100),
{ok, Bin} = file:read_file("test.log"),
{ok, Bin} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message\n"], re:split(Bin, "\n", [{return, list}, {parts, 2}])),
file:delete("test.log"),
file:write_file("test.log", ""),
file:delete("crash_test.log"),
file:write_file("crash_test.log", ""),
error_logger:error_msg("Test message1~n"),
timer:sleep(100),
{ok, Bin1} = file:read_file("test.log"),
{ok, Bin1} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message1\n"], re:split(Bin1, "\n", [{return, list}, {parts, 2}])),
file:rename("test.log", "test.log.0"),
file:rename("crash_test.log", "crash_test.log.0"),
error_logger:error_msg("Test message2~n"),
timer:sleep(100),
{ok, Bin2} = file:read_file("test.log"),
{ok, Bin2} = file:read_file("crash_test.log"),
?assertMatch([_, "Test message2\n"], re:split(Bin2, "\n", [{return, list}, {parts, 2}]))
end
}
Expand Down
13 changes: 11 additions & 2 deletions src/lager_file_backend.erl
Expand Up @@ -167,14 +167,23 @@ write(#file{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize,
true ->
File;
_ ->
?INT_LOG(error, "Failed to reopen logfile ~s with error ~s",
?INT_LOG(error, "Failed to reopen log file ~s with error ~s",
[Name, file:format_error(Reason)]),
File#file{flap=true}
end
end.

validate_logfiles([]) ->
[];
validate_logfiles([{Name, Level}|T]) ->
case lists:member(Level, ?LEVELS) of
true ->
[{Name, Level, 0, undefined, 0}|validate_logfiles(T)];
_ ->
?INT_LOG(error, "Invalid log level of ~p for ~s.",
[Level, Name]),
validate_logfiles(T)
end;
validate_logfiles([{Name, Level, Size, Date, Count}|T]) ->
ValidLevel = (lists:member(Level, ?LEVELS)),
ValidSize = (is_integer(Size) andalso Size >= 0),
Expand Down Expand Up @@ -208,7 +217,7 @@ validate_logfiles([{Name, Level, Size, Date, Count}|T]) ->
end
end;
validate_logfiles([H|T]) ->
?INT_LOG(error, "Invalid logfile config ~p.", [H]),
?INT_LOG(error, "Invalid log file config ~p.", [H]),
validate_logfiles(T).

schedule_rotation(_, undefined) ->
Expand Down
50 changes: 28 additions & 22 deletions src/lager_handler_watcher.erl
Expand Up @@ -107,16 +107,19 @@ reinstall_on_initial_failure_test_() ->
application:set_env(lager, error_logger_redirect, false),
application:unset_env(lager, crash_log),
application:start(lager),
?assertEqual(1, lager_test_backend:count()),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Lager failed to install handler lager_crash_backend into lager_event, retrying later", Message),
?assertEqual(0, lager_test_backend:count()),
timer:sleep(6000),
?assertEqual(0, lager_test_backend:count()),
?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))),
application:stop(lager),
application:unload(lager),
error_logger:tty(true)
try
?assertEqual(1, lager_test_backend:count()),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertMatch("Lager failed to install handler lager_crash_backend into lager_event, retrying later :"++_, Message),
?assertEqual(0, lager_test_backend:count()),
timer:sleep(6000),
?assertEqual(0, lager_test_backend:count()),
?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event)))
after
application:stop(lager),
application:unload(lager),
error_logger:tty(true)
end
end
]
}.
Expand All @@ -131,18 +134,21 @@ reinstall_on_runtime_failure_test_() ->
application:set_env(lager, error_logger_redirect, false),
application:unset_env(lager, crash_log),
application:start(lager),
?assertEqual(0, lager_test_backend:count()),
?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))),
timer:sleep(6000),
?assertEqual(2, lager_test_backend:count()),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Lager event handler lager_crash_backend exited with reason crash", Message),
{_Level2, _Time2, [_, _, Message2]} = lager_test_backend:pop(),
?assertEqual("Lager failed to install handler lager_crash_backend into lager_event, retrying later", Message2),
?assertEqual(false, lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))),
application:stop(lager),
application:unload(lager),
error_logger:tty(true)
try
?assertEqual(0, lager_test_backend:count()),
?assert(lists:member(lager_crash_backend, gen_event:which_handlers(lager_event))),
timer:sleep(6000),
?assertEqual(2, lager_test_backend:count()),
{_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
?assertEqual("Lager event handler lager_crash_backend exited with reason crash", Message),
{_Level2, _Time2, [_, _, Message2]} = lager_test_backend:pop(),
?assertMatch("Lager failed to install handler lager_crash_backend into lager_event, retrying later :"++_, Message2),
?assertEqual(false, lists:member(lager_crash_backend, gen_event:which_handlers(lager_event)))
after
application:stop(lager),
application:unload(lager),
error_logger:tty(true)
end
end
]
}.
Expand Down
68 changes: 68 additions & 0 deletions test/lager_crash_backend.erl
@@ -0,0 +1,68 @@
%% Copyright (c) 2011 Basho Technologies, Inc. All Rights Reserved.
%%
%% This file is provided to you under the Apache License,
%% Version 2.0 (the "License"); you may not use this file
%% except in compliance with the License. You may obtain
%% a copy of the License at
%%
%% http://www.apache.org/licenses/LICENSE-2.0
%%
%% Unless required by applicable law or agreed to in writing,
%% software distributed under the License is distributed on an
%% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
%% KIND, either express or implied. See the License for the
%% specific language governing permissions and limitations
%% under the License.

-module(lager_crash_backend).

-include("lager.hrl").

-behaviour(gen_event).

-export([init/1, handle_call/2, handle_event/2, handle_info/2, terminate/2,
code_change/3]).

-ifdef(TEST).
-include_lib("eunit/include/eunit.hrl").
-endif.

init([CrashBefore, CrashAfter]) ->
case is_tuple(CrashBefore) andalso (timer:now_diff(CrashBefore, os:timestamp()) > 0) of
true ->
%?debugFmt("crashing!~n", []),
{error, crashed};
_ ->
%?debugFmt("Not crashing!~n", []),
case is_tuple(CrashAfter) of
true ->
CrashTime = timer:now_diff(CrashAfter, os:timestamp()) div 1000,
case CrashTime > 0 of
true ->
%?debugFmt("crashing in ~p~n", [CrashTime]),
erlang:send_after(CrashTime, self(), crash),
{ok, {}};
_ -> {error, crashed}
end;
_ ->
{ok, {}}
end
end.

handle_call(_Request, State) ->
{ok, ok, State}.

handle_event(_Event, State) ->
{ok, State}.

handle_info(crash, _State) ->
%?debugFmt("Time to crash!~n", []),
crash;
handle_info(_Info, State) ->
{ok, State}.

terminate(_Reason, _State) ->
ok.

code_change(_OldVsn, State, _Extra) ->
{ok, State}.

0 comments on commit d828c35

Please sign in to comment.