couch_log: use lager

With this change instead to use our own way to log file we are using
lager which improve the logging which will make couchdb more tolerant in
the face of large or many log messages, won't out of memory the node.

Note: Lager can handle multiple backend butwe are for now only handling
the file and console backend in the ini file. Other backends can be
configured using the app.config file.

5 files changed, 139 insertions, 103 deletions

diff --git a/apps/couch/src/couch.app.src b/apps/couch/src/couch.app.src
index b3ed46c8e..8674784ed 100644
--- a/apps/couch/src/couch.app.src
+++ b/apps/couch/src/couch.app.src
@@ -35,7 +35,7 @@
     ]},
     {mod, {couch_app, []}},
     {env, []},
-    {applications, [kernel, stdlib, crypto, sasl, asn1, public_key,
+    {applications, [kernel, stdlib, lager, crypto, sasl, asn1, public_key,
                     ssl, os_mon, inets]}
 ]}.
 
diff --git a/apps/couch/src/couch_log.erl b/apps/couch/src/couch_log.erl
index 7cfd47bbb..6cf04f4f5 100644
--- a/apps/couch/src/couch_log.erl
+++ b/apps/couch/src/couch_log.erl
@@ -11,7 +11,8 @@
 % the License.
 
 -module(couch_log).
--behaviour(gen_event).
+
+-behaviour(gen_server).
 
 % public API
 -export([start_link/0, stop/0]).
@@ -20,9 +21,10 @@
 -export([debug_on/1, info_on/1, warn_on/1, get_level/1, get_level_integer/1, set_level/2]).
 -export([read/2]).
 
-% gen_event callbacks
--export([init/1, handle_event/2, terminate/2, code_change/3]).
--export([handle_info/2, handle_call/2]).
+% gen_server callbacks
+-export([init/1, handle_call/3, handle_cast/2, handle_info/2,
+         terminate/2, code_change/3]).
+
 
 -define(LEVEL_ERROR, 4).
 -define(LEVEL_WARN, 3).
@@ -30,26 +32,22 @@
 -define(LEVEL_DEBUG, 1).
 
 -record(state, {
-    fd,
+    log_file,
     level,
     sasl
 }).
 
 debug(Format, Args) ->
-    {ConsoleMsg, FileMsg} = get_log_messages(self(), debug, Format, Args),
-    gen_event:sync_notify(error_logger, {couch_debug, ConsoleMsg, FileMsg}).
+    lager:debug(Format, Args).
 
 info(Format, Args) ->
-    {ConsoleMsg, FileMsg} = get_log_messages(self(), info, Format, Args),
-    gen_event:sync_notify(error_logger, {couch_info, ConsoleMsg, FileMsg}).
+    lager:info(Format, Args).
 
 warn(Format, Args) ->
-    {ConsoleMsg, FileMsg} = get_log_messages(self(), warn, Format, Args),
-    gen_event:sync_notify(error_logger, {couch_warn, ConsoleMsg, FileMsg}).
+    lager:warning(Format, Args).
 
 error(Format, Args) ->
-    {ConsoleMsg, FileMsg} = get_log_messages(self(), error, Format, Args),
-    gen_event:sync_notify(error_logger, {couch_error, ConsoleMsg, FileMsg}).
+    lager:error(Format, Args).
 
 
 level_integer(error)    -> ?LEVEL_ERROR;
@@ -63,54 +61,6 @@ level_atom(?LEVEL_WARN) -> warn;
 level_atom(?LEVEL_INFO) -> info;
 level_atom(?LEVEL_DEBUG) -> debug.
 
-
-start_link() ->
-    couch_event_sup:start_link({local, couch_log}, error_logger, couch_log, []).
-
-stop() ->
-    couch_event_sup:stop(couch_log).
-
-init([]) ->
-    % read config and register for configuration changes
-
-    % just stop if one of the config settings change. couch_sup
-    % will restart us and then we will pick up the new settings.
-    ok = couch_config:register(
-        fun("log", "file") ->
-            ?MODULE:stop();
-        ("log", "level") ->
-            ?MODULE:stop();
-        ("log", "include_sasl") ->
-            ?MODULE:stop();
-        ("log_level_by_module", _) ->
-            ?MODULE:stop()
-        end),
-
-    Filename = couch_config:get("log", "file", "couchdb.log"),
-    Level = level_integer(list_to_atom(couch_config:get("log", "level", "info"))),
-    Sasl = couch_config:get("log", "include_sasl", "true") =:= "true",
-    LevelByModule = couch_config:get("log_level_by_module"),
-
-    case ets:info(?MODULE) of
-    undefined -> ets:new(?MODULE, [named_table]);
-    _ -> ok
-    end,
-    ets:insert(?MODULE, {level, Level}),
-    lists:foreach(fun({Module, ModuleLevel}) ->
-        ModuleLevelInteger = level_integer(list_to_atom(ModuleLevel)),
-        ets:insert(?MODULE, {Module, ModuleLevelInteger})
-    end, LevelByModule),
-
-
-    case file:open(Filename, [append]) of
-    {ok, Fd} ->
-        {ok, #state{fd = Fd, level = Level, sasl = Sasl}};
-    {error, Reason} ->
-        ReasonStr = file:format_error(Reason),
-        io:format("Error opening log file ~s: ~s", [Filename, ReasonStr]),
-        {stop, {error, ReasonStr, Filename}}
-    end.
-
 debug_on() ->
     get_level_integer() =< ?LEVEL_DEBUG.
 
@@ -163,55 +113,96 @@ set_level_integer(Int) ->
 set_level_integer(Module, Int) ->
     gen_event:call(error_logger, couch_log, {set_level_integer, Module, Int}).
 
-handle_event({couch_error, ConMsg, FileMsg}, State) ->
-    log(State, ConMsg, FileMsg),
-    {ok, State};
-handle_event({couch_warn, ConMsg, FileMsg}, State) ->
-    log(State, ConMsg, FileMsg),
-    {ok, State};
-handle_event({couch_info, ConMsg, FileMsg}, State) ->
-    log(State, ConMsg, FileMsg),
-    {ok, State};
-handle_event({couch_debug, ConMsg, FileMsg}, State) ->
-    log(State, ConMsg, FileMsg),
-    {ok, State};
-handle_event({error_report, _, {Pid, _, _}}=Event, #state{sasl = true} = St) ->
-    {ConMsg, FileMsg} = get_log_messages(Pid, error, "~p", [Event]),
-    log(St, ConMsg, FileMsg),
-    {ok, St};
-handle_event({error, _, {Pid, Format, Args}}, #state{sasl = true} = State) ->
-    {ConMsg, FileMsg} = get_log_messages(Pid, error, Format, Args),
-    log(State, ConMsg, FileMsg),
-    {ok, State};
-handle_event(_Event, State) ->
-    {ok, State}.
 
-handle_call({set_level_integer, NewLevel}, State) ->
+
+start_link() ->
+    gen_server:start_link({local, couch_log}, couch_log, [], []).
+
+stop() ->
+    couch_event_sup:stop(couch_log).
+
+init([]) ->
+    % read config and register for configuration changes
+    ok = couch_config:register(fun
+                ("log", "file") ->
+                    gen_server:cast(?MODULE, config_update);
+                ("log", "level") ->
+                    gen_server:cast(?MODULE, config_update);
+                ("log", "include_sasl") ->
+                    gen_server:cast(?MODULE, {config_update, include_sasl});
+                ("log_level_by_module", _) ->
+                    gen_server:cast(?MODULE,
+                                    {config_update, log_level_by_module})
+            end),
+
+
+    Filename = log_file(),
+    ALevel = list_to_atom(couch_config:get("log", "level", "info")),
+    Level = level_integer(ALevel),
+    Sasl = couch_config:get("log", "include_sasl", "true") =:= "true",
+    LevelByModule = couch_config:get("log_level_by_module"),
+
+    %% initialise the ets table if needed
+    case ets:info(?MODULE) of
+        undefined -> ets:new(?MODULE, [named_table]);
+        _ -> ok
+    end,
+
+    %% set the default level
+    ets:insert(?MODULE, {level, Level}),
+
+    %% initialise the log level by modules
+    lists:foreach(fun({Module, ModuleLevel}) ->
+        ModuleLevelInteger = level_integer(list_to_atom(ModuleLevel)),
+        ets:insert(?MODULE, {Module, ModuleLevelInteger})
+    end, LevelByModule),
+
+    %% set default log level
+    set_loglevel(Filename, ALevel),
+
+    {ok, #state{log_file=Filename, level = Level, sasl = Sasl}}.
+
+handle_call({set_level_integer, NewLevel}, _From, State) ->
     ets:insert(?MODULE, {level, NewLevel}),
     {ok, ok, State#state{level = NewLevel}};
 
-handle_call({set_level_integer, Module, NewLevel}, State) ->
+handle_call({set_level_integer, Module, NewLevel}, _From, State) ->
     ets:insert(?MODULE, {Module, NewLevel}),
     {ok, ok, State#state{level = NewLevel}}.
 
+handle_cast(config_update, State) ->
+    Filename = log_file(),
+    ALevel = list_to_atom(couch_config:get("log", "level", "info")),
+    Level = level_integer(ALevel),
+
+    %% set default module
+    ets:insert(?MODULE, {level, Level}),
+
+    %% set log level
+    set_loglevel(Filename, ALevel),
+
+    {noreply, State#state{log_file=Filename, level = Level}};
+
+handle_cast({config_update, include_sasl}, State) ->
+    Sasl = couch_config:get("log", "include_sasl", "true") =:= "true",
+    {noreply, State#state{sasl=Sasl}};
+handle_cast({config_update, log_level_by_module}, State) ->
+    LevelByModule = couch_config:get("log_level_by_module"),
+    lists:foreach(fun({Module, ModuleLevel}) ->
+        ModuleLevelInteger = level_integer(list_to_atom(ModuleLevel)),
+        ets:insert(?MODULE, {Module, ModuleLevelInteger})
+    end, LevelByModule),
+
+    {noreply, State}.
+
 handle_info(_Info, State) ->
     {ok, State}.
 
 code_change(_OldVsn, State, _Extra) ->
     {ok, State}.
 
-terminate(_Arg, #state{fd = Fd}) ->
-    file:close(Fd).
-
-log(#state{fd = Fd}, ConsoleMsg, FileMsg) ->
-    ok = io:put_chars(ConsoleMsg),
-    ok = io:put_chars(Fd, FileMsg).
-
-get_log_messages(Pid, Level, Format, Args) ->
-    ConsoleMsg = unicode:characters_to_binary(io_lib:format(
-        "[~s] [~p] " ++ Format ++ "~n", [Level, Pid | Args])),
-    FileMsg = ["[", couch_util:rfc1123_date(), "] ", ConsoleMsg],
-    {ConsoleMsg, iolist_to_binary(FileMsg)}.
+terminate(_Arg, _State) ->
+    ok.
 
 
 % Read Bytes bytes from the end of log file, jumping Offset bytes towards
@@ -231,7 +222,7 @@ get_log_messages(Pid, Level, Format, Args) ->
 % |__________| 100
 
 read(Bytes, Offset) ->
-    LogFileName = couch_config:get("log", "file"),
+    LogFileName = log_file(),
     LogFileSize = filelib:file_size(LogFileName),
     MaxChunkSize = list_to_integer(
         couch_config:get("httpd", "log_max_chunk_size", "1000000")),
@@ -252,3 +243,25 @@ read(Bytes, Offset) ->
     {ok, Chunk} = file:pread(Fd, Start, Bytes),
     ok = file:close(Fd),
     Chunk.
+
+set_loglevel(Filename, ALevel) ->
+    %% set default log level
+    lager:set_loglevel(lager_console_backend, ALevel),
+    lager:set_loglevel(lager_file_backend, Filename, ALevel),
+
+    %% set the log level for other handlers
+    case application:get_env(lager, handlers) of
+        undefined -> ok;
+        {ok, Handlers} ->
+            lists:foreach(fun(Handler) ->
+                        lager:set_loglevel(Handler, ALevel)
+                end, Handlers)
+    end.
+
+
+log_file() ->
+    DefaultLogFile = case application:get_env(couch, log_file) of
+        undefined -> "couchdb.log";
+        FName -> FName
+    end,
+    couch_config:get("log", "file", DefaultLogFile).
diff --git a/etc/couchdb/app.config b/etc/couchdb/app.config
index 15e16c608..b6d247c7a 100644
--- a/etc/couchdb/app.config
+++ b/etc/couchdb/app.config
@@ -7,8 +7,24 @@
         {config_files, [
                 "{{platform_etc_dir}}/couch.ini",
                 "{{platform_etc_dir}}/local.ini"
-                ]}
-        ]},
+                ]},
+        {log_file, "{{platform_log_dir}}/couchdb.log"}
+    ]},
+
+
+{lager, [{handlers, [
+          {lager_console_backend, [info,
+                                   {lager_default_formatter,
+                                          ["[", pid, "] [", severity, "] ",
+                                           message, "\n"]}]},
+
+          {lager_file_backend, [{file, "{{platform_log_dir}}/couchdb.log"},
+                                 {level, info},
+                                 {formatter, lager_default_formatter},
+                                 {formatter_config,
+                                  ["[", time, "] [", pid, "] [", severity, "] ",
+                                   message, "\n"]}]}
+                    ]}]},
 
  %% os_mon config
  {os_mon, [
diff --git a/rebar.config b/rebar.config
index cc1178986..f3d5b147e 100644
--- a/rebar.config
+++ b/rebar.config
@@ -4,7 +4,8 @@
 {cover_enabled, true}.
 {eunit_opts, [{report,{eunit_surefire,[{dir,"."}]}}]}.
 {edoc_opts, [{preprocess, true}]}.
-{erl_opts, [debug_info, fail_on_warning]}.
+{erl_opts, [debug_info, fail_on_warning,
+            {parse_transform, lager_transform}]}.
 
 {require_otp_vsn, "R14B04|R15|R16"}.
 
@@ -30,7 +31,10 @@
                    {branch, "refuge"}}},
 
     %% json module, encode/decode module
-    {jiffy, ".*", {git, "git://github.com/refuge/jiffy.git", "master"}}
+    {jiffy, ".*", {git, "git://github.com/refuge/jiffy.git", "master"}},
+
+    %% lager logging module
+    {lager, ".*", {git, "git://github.com/refuge/lager.git", "master"}}
 ]}.
 
 
diff --git a/rel/reltool.config.script b/rel/reltool.config.script
index ecdf60f83..c4135577c 100644
--- a/rel/reltool.config.script
+++ b/rel/reltool.config.script
@@ -48,6 +48,7 @@ CouchJSName = proplists:get_value(couchjs_name, Cfg, "couchjs"),
                 [
                     kernel,
                     stdlib,
+                    lager,
                     sasl,
                     public_key,
                     ssl,
@@ -97,6 +98,8 @@ CouchJSName = proplists:get_value(couchjs_name, Cfg, "couchjs"),
             {app, jiffy, [{incl_cond, include}]},
             {app, snappy, [{incl_cond, include}]},
             {app, ibrowse, [{incl_cond, include}]},
+            {app, goldrush, [{incl_cond, include}]},
+            {app, lager, [{incl_cond, include}]},
 
             %% couchdb
             {app, couch, [{incl_cond, include}]},