Re-factor the file backend so it starts one gen_event handler per file

src/lager_app.erl

@@ -42,8 +42,9 @@ start(_StartType, _StartArgs) ->
         {ok, Val} ->
             Val
     end,
+
     [supervisor:start_child(lager_handler_watcher_sup, [lager_event, Module, Config]) ||
-        {Module, Config} <- Handlers],
+        {Module, Config} <- expand_handlers(Handlers)],
 
     %% mask the messages we have no use for
     MinLog = lager:minimum_loglevel(lager:get_loglevels()),
@@ -66,3 +67,11 @@ start(_StartType, _StartArgs) ->
 stop(Handlers) ->
     [error_logger:add_report_handler(Handler) || Handler <- Handlers],
     ok.
+
+expand_handlers([]) ->
+    [];
+expand_handlers([{lager_file_backend, Configs}|T]) ->
+    [{{lager_file_backend, element(1, Config)}, Config} || Config <- Configs] ++
+      expand_handlers(T);
+expand_handlers([H|T]) ->
+    [H | expand_handlers(T)].

src/lager_file_backend.erl

@@ -40,9 +40,7 @@
 -export([init/1, handle_call/2, handle_event/2, handle_info/2, terminate/2,
         code_change/3]).
 
--record(state, {files}).
-
--record(file, {
+-record(state, {
         name :: string(),
         level :: integer(),
         fd :: file:io_device(),
@@ -55,94 +53,68 @@
 
 %% @private
 -spec init([{string(), lager:log_level()},...]) -> {ok, #state{}}.
-init(LogFiles) ->
-    Files = [begin
-                schedule_rotation(Name, Date),
-                case lager_util:open_logfile(Name, true) of
-                    {ok, {FD, Inode, _}} ->
-                        #file{name=Name, level=lager_util:level_to_num(Level),
-                            fd=FD, inode=Inode, size=Size, date=Date, count=Count};
-                    {error, Reason} ->
-                        ?INT_LOG(error, "Failed to open log file ~s with error ~s",
-                            [Name, file:format_error(Reason)]),
-                        #file{name=Name, level=lager_util:level_to_num(Level),
-                            flap=true, size=Size, date=Date, count=Count}
-                end
-        end ||
-        {Name, Level, Size, Date, Count} <- validate_logfiles(LogFiles)],
-    {ok, #state{files=Files}}.
+init(LogFile) ->
+    case validate_logfile(LogFile) of
+        {Name, Level, Size, Date, Count} -> 
+            schedule_rotation(Name, Date),
+            State = case lager_util:open_logfile(Name, true) of
+                {ok, {FD, Inode, _}} ->
+                    #state{name=Name, level=lager_util:level_to_num(Level),
+                        fd=FD, inode=Inode, size=Size, date=Date, count=Count};
+                {error, Reason} ->
+                    ?INT_LOG(error, "Failed to open log file ~s with error ~s",
+                        [Name, file:format_error(Reason)]),
+                    #state{name=Name, level=lager_util:level_to_num(Level),
+                        flap=true, size=Size, date=Date, count=Count}
+            end,
+            {ok, State};
+        false ->
+            ignore
+    end.
 
 %% @private
 handle_call({set_loglevel, _}, State) ->
     {ok, {error, missing_identifier}, State};
-handle_call({set_loglevel, Ident, Level}, #state{files=Files} = State) ->
-    case lists:keyfind(Ident, 2, Files) of
-        false ->
-            %% no such file exists
-            {ok, {error, bad_identifier}, State};
-        _ ->
-            NewFiles = lists:map(
-                fun(#file{name=Name} = File) when Name == Ident ->
-                        ?INT_LOG(notice, "Changed loglevel of ~s to ~p",
-                            [Ident, Level]),
-                        File#file{level=lager_util:level_to_num(Level)};
-                    (X) -> X
-                end, Files),
-            {ok, ok, State#state{files=NewFiles}}
-    end;
-handle_call(get_loglevel, #state{files=Files} = State) ->
-    Result = lists:foldl(fun(#file{level=Level}, L) -> erlang:max(Level, L);
-            (_, L) -> L end, -1,
-        Files),
-    {ok, Result, State};
+handle_call({set_loglevel, Ident, Level}, #state{name=Ident} = State) ->
+    ?INT_LOG(notice, "Changed loglevel of ~s to ~p", [Ident, Level]),
+    {ok, ok, State#state{level=lager_util:level_to_num(Level)}};
+handle_call(get_loglevel, #state{level=Level} = State) ->
+    {ok, Level, State};
 handle_call(_Request, State) ->
     {ok, ok, State}.
 
 %% @private
-handle_event({log, Level, {Date, Time}, Message}, #state{files=Files} = State) ->
-    NewFiles = lists:map(
-        fun(#file{level=L} = File) when Level =< L ->
-                write(File, Level, [Date, " ", Time, " ", Message, "\n"]);
-            (File) ->
-                File
-        end, Files),
-    {ok, State#state{files=NewFiles}};
+handle_event({log, Level, {Date, Time}, Message}, #state{level=L} = State) when Level =< L->
+    NewState = write(State, Level, [Date, " ", Time, " ", Message, "\n"]),
+    {ok, NewState};
 handle_event(_Event, State) ->
     {ok, State}.
 
 %% @private
-handle_info({rotate, File}, #state{files=Files} = State) ->
-    case lists:keyfind(File, #file.name, Files) of
-        false ->
-            %% no such file exists
-            ?INT_LOG(warning, "Asked to rotate non-existant file ~p", [File]),
-            {ok, State};
-        #file{name=Name, date=Date, count=Count} ->
-            lager_util:rotate_logfile(Name, Count),
-            schedule_rotation(Name, Date),
-            {ok, State}
-    end;
+handle_info({rotate, File}, #state{name=File,count=Count,date=Date} = State) ->
+    lager_util:rotate_logfile(File, Count),
+    schedule_rotation(File, Date),
+    {ok, State};
 handle_info(_Info, State) ->
     {ok, State}.
 
 %% @private
-terminate(_Reason, State) ->
+terminate(_Reason, #state{fd=FD}) ->
     %% flush and close any file handles
-    lists:foreach(
-        fun({_, _, FD, _}) -> file:datasync(FD), file:close(FD);
-            (_) -> ok
-        end, State#state.files).
+    file:datasync(FD),
+    file:close(FD),
+    ok.
 
 %% @private
 code_change(_OldVsn, State, _Extra) ->
     {ok, State}.
 
-write(#file{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize,
-        count=Count} = File, Level, Msg) ->
+write(#state{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize,
+        count=Count} = State, Level, Msg) ->
     case lager_util:ensure_logfile(Name, FD, Inode, true) of
         {ok, {_, _, Size}} when RotSize /= 0, Size > RotSize ->
             lager_util:rotate_logfile(Name, Count),
-            write(File, Level, Msg);
+            write(State, Level, Msg);
         {ok, {NewFD, NewInode, _}} ->
             file:write(NewFD, Msg),
             case Level of
@@ -158,33 +130,31 @@ write(#file{name=Name, fd=FD, inode=Inode, flap=Flap, size=RotSize,
                         _ ->
                             Flap
                     end,
-                    File#file{fd=NewFD, inode=NewInode, flap=Flap2};
+                    State#state{fd=NewFD, inode=NewInode, flap=Flap2};
                 _ -> 
-                    File#file{fd=NewFD, inode=NewInode}
+                    State#state{fd=NewFD, inode=NewInode}
             end;
         {error, Reason} ->
             case Flap of
                 true ->
-                    File;
+                    State;
                 _ ->
                     ?INT_LOG(error, "Failed to reopen log file ~s with error ~s",
                         [Name, file:format_error(Reason)]),
-                    File#file{flap=true}
+                    State#state{flap=true}
             end
     end.
 
-validate_logfiles([]) ->
-    [];
-validate_logfiles([{Name, Level}|T]) ->
+validate_logfile({Name, Level}) ->
     case lists:member(Level, ?LEVELS) of
         true ->
-            [{Name, Level, 0, undefined, 0}|validate_logfiles(T)];
+            {Name, Level, 0, undefined, 0};
         _ ->
             ?INT_LOG(error, "Invalid log level of ~p for ~s.",
                 [Level, Name]),
-            validate_logfiles(T)
+            false
     end;
-validate_logfiles([{Name, Level, Size, Date, Count}|T]) ->
+validate_logfile({Name, Level, Size, Date, Count}) ->
     ValidLevel = (lists:member(Level, ?LEVELS)),
     ValidSize = (is_integer(Size) andalso Size >= 0),
     ValidCount = (is_integer(Count) andalso Count >= 0),
@@ -192,33 +162,31 @@ validate_logfiles([{Name, Level, Size, Date, Count}|T]) ->
         {false, _, _} ->
             ?INT_LOG(error, "Invalid log level of ~p for ~s.",
                 [Level, Name]),
-            validate_logfiles(T);
+            false;
         {_, false, _} ->
             ?INT_LOG(error, "Invalid rotation size of ~p for ~s.",
                 [Size, Name]),
-            validate_logfiles(T);
+            false;
         {_, _, false} ->
             ?INT_LOG(error, "Invalid rotation count of ~p for ~s.",
                 [Count, Name]),
-            validate_logfiles(T);
+            false;
         {true, true, true} ->
             case lager_util:parse_rotation_date_spec(Date) of
                 {ok, Spec} ->
-                    [{Name, Level, Size, Spec,
-                            Count}|validate_logfiles(T)];
+                    {Name, Level, Size, Spec, Count};
                 {error, _} when Date == "" ->
                     %% blank ones are fine.
-                    [{Name, Level, Size, undefined,
-                            Count}|validate_logfiles(T)];
+                    {Name, Level, Size, undefined, Count};
                 {error, _} ->
                     ?INT_LOG(error, "Invalid rotation date of ~p for ~s.",
                         [Date, Name]),
-                    validate_logfiles(T)
+                    false
             end
     end;
-validate_logfiles([H|T]) ->
+validate_logfile(H) ->
     ?INT_LOG(error, "Invalid log file config ~p.", [H]),
-    validate_logfiles(T).
+    false.
 
 schedule_rotation(_, undefined) ->
     undefined;
@@ -229,31 +197,26 @@ schedule_rotation(Name, Date) ->
 
 get_loglevel_test() ->
     {ok, Level, _} = handle_call(get_loglevel,
-        #state{files=[
-                #file{name="foo", level=lager_util:level_to_num(warning), fd=0, inode=0},
-                #file{name="bar", level=lager_util:level_to_num(info), fd=0, inode=0}]}),
+        #state{name="bar", level=lager_util:level_to_num(info), fd=0, inode=0}),
     ?assertEqual(Level, lager_util:level_to_num(info)),
     {ok, Level2, _} = handle_call(get_loglevel,
-        #state{files=[
-                #file{name="foo", level=lager_util:level_to_num(warning), fd=0, inode=0},
-                #file{name="foo", level=lager_util:level_to_num(critical), fd=0, inode=0},
-                #file{name="bar", level=lager_util:level_to_num(error), fd=0, inode=0}]}),
+        #state{name="foo", level=lager_util:level_to_num(warning), fd=0, inode=0}),
     ?assertEqual(Level2, lager_util:level_to_num(warning)).
 
 rotation_test() ->
     {ok, {FD, Inode, _}} = lager_util:open_logfile("test.log", true),
-    ?assertMatch(#file{name="test.log", level=?DEBUG, fd=FD, inode=Inode},
-        write(#file{name="test.log", level=?DEBUG, fd=FD, inode=Inode}, 0, "hello world")),
+    ?assertMatch(#state{name="test.log", level=?DEBUG, fd=FD, inode=Inode},
+        write(#state{name="test.log", level=?DEBUG, fd=FD, inode=Inode}, 0, "hello world")),
     file:delete("test.log"),
-    Result = write(#file{name="test.log", level=?DEBUG, fd=FD, inode=Inode}, 0, "hello world"),
+    Result = write(#state{name="test.log", level=?DEBUG, fd=FD, inode=Inode}, 0, "hello world"),
     %% assert file has changed
-    ?assert(#file{name="test.log", level=?DEBUG, fd=FD, inode=Inode} =/= Result),
-    ?assertMatch(#file{name="test.log", level=?DEBUG}, Result),
+    ?assert(#state{name="test.log", level=?DEBUG, fd=FD, inode=Inode} =/= Result),
+    ?assertMatch(#state{name="test.log", level=?DEBUG}, Result),
     file:rename("test.log", "test.log.1"),
     Result2 = write(Result, 0, "hello world"),
     %% assert file has changed
     ?assert(Result =/= Result2),
-    ?assertMatch(#file{name="test.log", level=?DEBUG}, Result2),
+    ?assertMatch(#state{name="test.log", level=?DEBUG}, Result2),
     ok.
 
 filesystem_test_() ->
@@ -274,7 +237,7 @@ filesystem_test_() ->
         [
             {"under normal circumstances, file should be opened",
                 fun() ->
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         lager:log(error, self(), "Test message"),
                         {ok, Bin} = file:read_file("test.log"),
                         Pid = pid_to_list(self()),
@@ -285,7 +248,7 @@ filesystem_test_() ->
                 fun() ->
                         {ok, FInfo} = file:read_file_info("test.log"),
                         file:write_file_info("test.log", FInfo#file_info{mode = 0}),
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         ?assertEqual(1, lager_test_backend:count()),
                         {_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
                         ?assertEqual("Failed to open log file test.log with error permission denied", lists:flatten(Message))
@@ -293,7 +256,7 @@ filesystem_test_() ->
             },
             {"file that becomes unavailable at runtime should trigger an error message",
                 fun() ->
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         ?assertEqual(0, lager_test_backend:count()),
                         lager:log(error, self(), "Test message"),
                         ?assertEqual(1, lager_test_backend:count()),
@@ -314,7 +277,7 @@ filesystem_test_() ->
                         {ok, FInfo} = file:read_file_info("test.log"),
                         OldPerms = FInfo#file_info.mode,
                         file:write_file_info("test.log", FInfo#file_info{mode = 0}),
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         ?assertEqual(1, lager_test_backend:count()),
                         {_Level, _Time, [_, _, Message]} = lager_test_backend:pop(),
                         ?assertEqual("Failed to open log file test.log with error permission denied", lists:flatten(Message)),
@@ -327,7 +290,7 @@ filesystem_test_() ->
             },
             {"external logfile rotation/deletion should be handled",
                 fun() ->
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         ?assertEqual(0, lager_test_backend:count()),
                         lager:log(error, self(), "Test message1"),
                         ?assertEqual(1, lager_test_backend:count()),
@@ -345,7 +308,7 @@ filesystem_test_() ->
             },
             {"runtime level changes",
                 fun() ->
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         ?assertEqual(0, lager_test_backend:count()),
                         lager:log(info, self(), "Test message1"),
                         lager:log(error, self(), "Test message2"),
@@ -362,7 +325,7 @@ filesystem_test_() ->
             },
             {"invalid runtime level changes",
                 fun() ->
-                        gen_event:add_handler(lager_event, lager_file_backend, [{"test.log", info}]),
+                        gen_event:add_handler(lager_event, lager_file_backend, {"test.log", info}),
                         ?assertEqual({error, bad_identifier}, lager:set_loglevel(lager_file_backend, "test2.log", warning)),
                         ?assertEqual({error, missing_identifier}, lager:set_loglevel(lager_file_backend, warning))
                 end