Add couch_access_log module, a common log format logger.

This module introduces a new log file couch_access.log in the
spirit of Apache httpd's access.log.

The log format is specified here:

  http://en.wikipedia.org/wiki/Common_Log_Format

There is currently no way to configure a different log format, but
that can be added easily later.

This is a new module rather than an extension to the couch_log
module to allow easy addition to Apache CouchDB. Ideally, this
will be a plugin in the future.

A note for chunked responses, the response body length reported is
"chunked" rather than the number of bytes. The case is unspecified
in the format description. Maybe the fix is keeping track of bytes
sent in a chunked response, but I didn't want to make the first stab
at this more complicated that it has to be. I'm happy to adjust.

Change-Id: Ie314a861557dfa3eceedd3eb43d8753c6710e5db
Reviewed-on: http://review.couchbase.org/9063
Reviewed-by: Filipe David Borba Manana <fdmanana@gmail.com>
Tested-by: Filipe David Borba Manana <fdmanana@gmail.com>

etc/couchdb/default.ini.tpl.in

@@ -34,6 +34,21 @@ file = %localstatelogdir%/couch.log
 level = info
 include_sasl = true
 
+; Enable apache httpd-style access logging.
+; The default format is the "extended" or "combined" format that
+; includes:
+;   host ident authuser date request status bytes referer(sic) user-agent
+;
+; The alternative format is "common" that includes:
+;   host ident authuser date request status bytes
+;
+; If a value is not defined, the log entry will be " - " for that value.
+
+[access_log]
+enable = false
+format = extended
+file = %localstatelogdir%/couch_access.log
+
 [couch_httpd_auth]
 authentication_db = _users
 authentication_redirect = /_utils/session.html

src/couchdb/Makefile.am

@@ -56,6 +56,7 @@ source_files = \
 	couch_httpd_vhost.erl \
     couch_key_tree.erl \
     couch_log.erl \
+    couch_access_log.erl \
     couch_native_process.erl \
     couch_os_daemons.erl \
     couch_os_process.erl \
@@ -118,6 +119,7 @@ compiled_files = \
 	couch_httpd_vhost.beam \
     couch_key_tree.beam \
     couch_log.beam \
+    couch_access_log.beam \
     couch_native_process.beam \
     couch_os_daemons.beam \
     couch_os_process.beam \

src/couchdb/couch.app.tpl.in

@@ -9,6 +9,7 @@
         couch_external_manager,
         couch_httpd,
         couch_log,
+        couch_access_log,
         couch_primary_services,
         couch_query_servers,
         couch_rep_sup,

src/couchdb/couch_access_log.erl

@@ -0,0 +1,171 @@
+% Licensed 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(couch_access_log).
+-behaviour(gen_event).
+
+% public API
+-export([start_link/0, stop/0]).
+-export([log/3]).
+
+% gen_event callbacks
+-export([init/1, handle_event/2, terminate/2, code_change/3]).
+-export([handle_info/2, handle_call/2]).
+
+-define(DISK_LOGGER, couch_disk_access_logger).
+-define(DEFAULT_FORMAT, "extended").
+
+log(MochiReq, Code, Body) ->
+    case is_enabled() of
+    false -> ok;
+    _True ->
+        FileMsg = get_log_messages(MochiReq, Code, Body),
+        ok = disk_log:balog(?DISK_LOGGER, FileMsg)
+    end.
+
+start_link() ->
+    couch_event_sup:start_link({local, couch_access_log}, error_logger, couch_access_log, []).
+
+stop() ->
+    couch_event_sup:stop(couch_access_log).
+
+init([]) ->
+    % read config and register for configuration changes
+
+    % just stop if one of the config settings change. couch_server_sup
+    % will restart us and then we will pick up the new settings.
+    ok = couch_config:register(
+        fun("access_log", "enable") ->
+            ?MODULE:stop();
+        ("access_log", "file") ->
+            ?MODULE:stop();
+        ("access_log", "format") ->
+            ?MODULE:stop()
+        end),
+
+    Enable = couch_config:get("access_log", "enable", "false") =:= "true",
+    Format = couch_config:get("access_log", "format", ?DEFAULT_FORMAT),
+
+    case ets:info(?MODULE) of
+    undefined -> ets:new(?MODULE, [named_table]);
+    _ -> ok
+    end,
+    ets:insert(?MODULE, {enable, Enable}),
+    ets:insert(?MODULE, {format, Format}),
+
+    Filename = couch_config:get("access_log", "file", "couchdb_access.log"),
+    DiskLogOptions = [
+        {file, Filename}, {name, ?DISK_LOGGER},
+        {format, external}, {type, halt}, {notify, true}
+    ],
+    case disk_log:open(DiskLogOptions) of
+    {ok, ?DISK_LOGGER} ->
+        {ok, ok};
+    Error ->
+        {stop, Error}
+    end.
+
+is_enabled() ->
+    try
+        ets:lookup_element(?MODULE, enable, 2)
+    catch error:badarg ->
+        false
+    end.
+
+get_format() ->
+    try
+        ets:lookup_element(?MODULE, format, 2)
+    catch error:badarg ->
+        ?DEFAULT_FORMAT
+    end.
+
+
+handle_event({couch_access, ConMsg}, State) ->
+    ok = io:put_chars(ConMsg),
+    {ok, State};
+handle_event(_Event, State) ->
+    {ok, State}.
+
+handle_info({disk_log, _Node, _Log, {error_status, Status}}, _State) ->
+    io:format("Access Log disk logger error: ~p~n", [Status]),
+    % couch_event_sup will restart us.
+    remove_handler;
+handle_info(_Info, State) ->
+    {ok, State}.
+
+handle_call(_Args, State) ->
+    {ok, State}.
+
+code_change(_OldVsn, State, _Extra) ->
+    {ok, State}.
+
+terminate(_Arg, _State) ->
+    ok = disk_log:close(?DISK_LOGGER).
+
+get_date() ->
+    {{Year, Month, Day}, {Hour, Minute, Second}} = calendar:universal_time(),
+    io_lib:format("[~w/~w/~w:~w:~w:~w +00:00]", [Day, Month, Year, Hour, Minute, Second]).
+
+get_path_info(MochiReq) ->
+    "\""
+    ++ atom_to_list(MochiReq:get(method))
+    ++ " "
+    ++ MochiReq:get(path)
+    ++ " HTTP/"
+    ++ get_version(MochiReq) ++ "\"".
+
+get_version(MochiReq) ->
+    case MochiReq:get(version) of
+	{1, 0} -> "1.0";
+	{1, 1} -> "1.1"
+    end.
+
+get_auth_user(MochiReq) ->
+    case MochiReq:get_header_value("Authorization") of
+    undefined -> "-";
+    "Basic " ++ UserPass64 ->
+        UserPass = base64:decode(UserPass64),
+        [User, _Pass] = string:tokens(UserPass, ":"),
+	binary_to_list(User)
+    end.
+
+get_log_messages(MochiReq, Code, [_, Body, _, _]) ->
+    get_log_messages(MochiReq, Code, Body);
+get_log_messages(MochiReq, Code, Body) ->
+    BaseFormat = [
+      MochiReq:get(peer),
+      "-", % ident, later
+      get_auth_user(MochiReq),
+      get_date(),
+      get_path_info(MochiReq),
+      io_lib:format("~w", [Code]),
+      case Body of
+      chunked -> "chunked";
+      _Else -> io_lib:format("~w", [iolist_size(Body) + 1]) % +1 for \n, maybe
+      end
+      ],
+    Args = case get_format() of
+    "common" ->
+        BaseFormat;
+    _Extended ->
+        BaseFormat ++ [
+	    get_header_value2(MochiReq, "Referer"),
+	    get_header_value2(MochiReq, "User-agent")
+	]
+    end,
+    string:join(Args ++ ["\n"], " ").
+
+get_header_value2(MochiReq, Header) ->
+    case MochiReq:get_header_value(Header) of
+        undefined -> "-";
+        Value -> Value
+    end.

src/couchdb/couch_httpd.erl

@@ -541,6 +541,8 @@ log_request(#httpd{mochi_req=MochiReq,peer=Peer}, Code) ->
         couch_util:to_integer(Code)
     ]).
 
+access_log_request(MochiReq, Code, Body) ->
+    couch_access_log:log(MochiReq, Code, Body).
 
 start_response_length(#httpd{mochi_req=MochiReq}=Req, Code, Headers, Length) ->
     log_request(Req, Code),
@@ -604,11 +606,13 @@ send_chunk(Resp, Data) ->
     {ok, Resp}.
 
 last_chunk(Resp) ->
+    access_log_request(Resp:get(request), Resp:get(code), chunked),
     Resp:write_chunk([]),
     {ok, Resp}.
 
 send_response(#httpd{mochi_req=MochiReq}=Req, Code, Headers, Body) ->
     log_request(Req, Code),
+    access_log_request(MochiReq, Code, Body),
     couch_stats_collector:increment({httpd_status_codes, Code}),
     Headers2 = http_1_0_keep_alive(MochiReq, Headers),
     if Code >= 400 ->

src/couchdb/couch_server_sup.erl

@@ -149,6 +149,12 @@ start_primary_services() ->
                 brutal_kill,
                 worker,
                 [couch_log]},
+	     {couch_access_log,
+                {couch_access_log, start_link, []},
+                permanent,
+                brutal_kill,
+                worker,
+                [couch_access_log]},
             {couch_replication_supervisor,
                 {couch_rep_sup, start_link, []},
                 permanent,