  @author   <  >
  @author   <  >
   2007 - 2008 Basho Technologies
%%
     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
%%
%%        -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(webmachine_logger).
-author('Justin Sheehy <>').
-author('Andy Gross <>').
-behaviour(gen_server).
-export([start_link/1]).
-export([init/1, handle_call/3, handle_cast/2, handle_info/2,
         terminate/2, code_change/3]).
-export([log_access/1, log_message/1, refresh/0, get_metadata/2]).

-include_lib("wm_reqdata.hrl").
-include_lib("webmachine_logger.hrl").

-record(state, {hourstamp, filename, handle}).

%%
%% Api
%%

alog_path(BaseDir) ->
    filename:join(BaseDir, "access.log").

start_link(BaseDir) ->
    gen_server:start_link({local, ?MODULE}, ?MODULE, [BaseDir], []).

refresh() ->
    refresh(os:timestamp()).

refresh(Time) ->
    gen_server:cast(?MODULE, {refresh, Time}).

log_access(#wm_log_data{}=D) ->
    gen_server:cast(?MODULE, {log_access, D}).

log_message(Msg) ->
    gen_server:cast(?MODULE, {log_message, Msg}).

%%
%% gen_server callbacks
%%

init([BaseDir]) ->
    defer_refresh(),
    FileName = alog_path(BaseDir),
    DateHour = datehour(),
    filelib:ensure_dir(FileName),
    Handle = log_open(FileName, DateHour),
    {ok, #state{filename=FileName, handle=Handle, hourstamp=DateHour}}.

handle_call(_Msg,_From,State) -> 
    {noreply,State}.

handle_cast({log_access, LogData}, State) ->
    Msg = format_req(LogData),
    {noreply, do_log(Msg, State)};

handle_cast({log_message, Msg}, State) ->
    {noreply, do_log(Msg, State)};

handle_cast({refresh, Time}, State) ->
    {noreply, maybe_rotate(State, Time)}.

handle_info({_Label, {From, MRef}, get_modules}, State) ->
    From ! {MRef, [?MODULE]},
    {noreply, State};
handle_info(_Info, State) ->
    {noreply, State}.

terminate(_Reason, _State) ->
    ok.

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

%%
%% Helpers
%%

log_open(FileName, DateHour) ->
    LogName = FileName ++ suffix(DateHour),
    webmachine_util:to_console("opening log file: ~p~n", [LogName]),
    {ok, FD} = file:open(LogName, [read, write, raw]),
    {ok, Location} = file:position(FD, eof),
    fix_log(FD, Location),
    file:truncate(FD),
    {?MODULE, LogName, FD}.

log_write({?MODULE, _Name, FD}, IoData) ->
    file:write(FD, lists:flatten(IoData)).

log_close({?MODULE, Name, FD}) ->
    webmachine_util:to_console("~p: closing log file: ~p~n", [?MODULE, Name]),
    file:close(FD).

do_log(Msg, State) ->
    NewState = maybe_rotate(State, os:timestamp()),
    log_write(NewState#state.handle, Msg),
    NewState.

maybe_rotate(State, Time) ->
    ThisHour = datehour(Time),
    if ThisHour == State#state.hourstamp ->
	    State;
       true ->
	    defer_refresh(),
	    log_close(State#state.handle),
	    Handle = log_open(State#state.filename, ThisHour),
	    State#state{hourstamp=ThisHour, handle=Handle}
    end.    

get_metadata(Key, #wm_log_data{metadata=MetaData}) ->
    case dict:find(Key, MetaData) of
        {ok, Value} -> Value;
        error -> undefined
    end.

format_req(#wm_log_data{req_id=ReqId,
                        method=Method, 
			headers=Headers, 
			peer=Peer, 
			path=Path,
			version=Version,
			response_code=ResponseCode,
			response_length=ResponseLength}) ->
    User = "-",
    Time = fmtnow(),
    Status = integer_to_list(ResponseCode),
    Length = case is_atom(ResponseLength) of 
        true -> atom_to_list(ResponseLength); 
        false -> integer_to_list(ResponseLength) 
    end,
    Referer = 
	case mochiweb_headers:get_value("Referer", Headers) of
	    undefined -> "";
	    R -> R
	end,
    UserAgent = 
	case mochiweb_headers:get_value("User-Agent", Headers) of
	    undefined -> "";
	    U -> U
	end,
    fmt_alog(Time, ReqId, Peer, User, webmachine_util:fmt_method(Method), Path, Version,
	     Status, Length, Referer, UserAgent).


%% Seek backwards to the last valid log entry
fix_log(_FD, 0) ->
    ok;
fix_log(FD, 1) ->
    {ok, 0} = file:position(FD, 0),
    ok;
fix_log(FD, Location) ->
    case file:pread(FD, Location - 1, 1) of
	{ok, [$\n | _]} ->
	    ok;
	{ok, _} ->
	    fix_log(FD, Location - 1)
    end.

defer_refresh() ->
    {_, {_, M, S}} = calendar:universal_time(),
    Time = 1000 * (3600 - ((M * 60) + S)),
    timer:apply_after(Time, ?MODULE, refresh, []).

datehour() ->
    datehour(os:timestamp()).

datehour(Now) ->
    {{Y, M, D}, {H, _, _}} = calendar:now_to_universal_time(Now),
    {Y, M, D, H}.

zeropad_str(NumStr, Zeros) when Zeros > 0 ->
    zeropad_str([$0 | NumStr], Zeros - 1);
zeropad_str(NumStr, _) ->
    NumStr.

zeropad(Num, MinLength) ->
    NumStr = integer_to_list(Num),
    zeropad_str(NumStr, MinLength - length(NumStr)).

suffix({Y, M, D, H}) ->
    YS = zeropad(Y, 4),
    MS = zeropad(M, 2),
    DS = zeropad(D, 2),
    HS = zeropad(H, 2),
    lists:flatten([$., YS, $_, MS, $_, DS, $_, HS]).

fmt_alog(Time, ReqId, Ip, User, Method, Path, {VM,Vm},
	 Status,  Length, Referrer, UserAgent) ->
    [fmt_ip(Ip), " - ", sanitize(User), [$\s], Time, [$\s, $"], sanitize(Method), " ", sanitize(Path),
     " HTTP/", integer_to_list(VM), ".", integer_to_list(Vm), [$",$\s],
     Status, [$\s], Length, [$\s,$"], sanitize(Referrer),
     [$",$\s,$"], sanitize(UserAgent), [$",$\s], integer_to_list(ReqId), [$\n]].

month(1) ->
    "Jan";
month(2) ->
    "Feb";
month(3) ->
    "Mar";
month(4) ->
    "Apr";
month(5) ->
    "May";
month(6) ->
    "Jun";
month(7) ->
    "Jul";
month(8) ->
    "Aug";
month(9) ->
    "Sep";
month(10) ->
    "Oct";
month(11) ->
    "Nov";
month(12) ->
    "Dec".
zone() ->
    Time = erlang:universaltime(),
    LocalTime = calendar:universal_time_to_local_time(Time),
    DiffSecs = calendar:datetime_to_gregorian_seconds(LocalTime) - calendar:datetime_to_gregorian_seconds(Time),
    zone((DiffSecs/3600)*100).

%% Ugly reformatting code to get times like +0000 and -1300

zone(Val) when Val < 0 ->
    io_lib:format("-~4..0w", [trunc(abs(Val))]);
zone(Val) when Val >= 0 ->
    io_lib:format("+~4..0w", [trunc(abs(Val))]).

fmt_ip(IP) when is_tuple(IP) ->
    inet_parse:ntoa(IP);
fmt_ip(undefined) ->
    "0.0.0.0";
fmt_ip(HostName) ->
    HostName.

fmtnow() ->
    {{Year, Month, Date}, {Hour, Min, Sec}} = calendar:local_time(),
    io_lib:format("[~2..0w/~s/~4..0w:~2..0w:~2..0w:~2..0w ~s]",
		  [Date,month(Month),Year, Hour, Min, Sec, zone()]).


% @doc Prevent escape characters to be shown in the log file.
  @seealso -bin/cvename.cgi?name=CVE-2009-4487
sanitize(S) ->
    sanitize(S, []).

sanitize([], Acc) ->
    lists:reverse(Acc);
sanitize([C|S], Acc) when C < 32 ->
    sanitize(S, [C+$A, $^ | Acc]);
sanitize([C|S], Acc) ->
    sanitize(S, [C|Acc]).


    you may not use this file except in compliance with the License.
    You may obtain a copy of the License at

        -2.0

    Unless required by applicable law or agreed to in writing, software
    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    limitations under the License.

 Api


 gen_server callbacks


 Helpers

 Seek backwards to the last valid log entry
 Ugly reformatting code to get times like +0000 and -1300
 @doc Prevent escape characters to be shown in the log file.
  @author   <  >
  @author   <  >
   2007 - 2008 Basho Technologies
     Licensed under the Apache License , Version 2.0 ( the " License " ) ;
     distributed under the License is distributed on an " AS IS " BASIS ,
     See the License for the specific language governing permissions and

-module(webmachine_logger).
-author('Justin Sheehy <>').
-author('Andy Gross <>').
-behaviour(gen_server).
-export([start_link/1]).
-export([init/1, handle_call/3, handle_cast/2, handle_info/2,
         terminate/2, code_change/3]).
-export([log_access/1, log_message/1, refresh/0, get_metadata/2]).

-include_lib("wm_reqdata.hrl").
-include_lib("webmachine_logger.hrl").

-record(state, {hourstamp, filename, handle}).


alog_path(BaseDir) ->
    filename:join(BaseDir, "access.log").

start_link(BaseDir) ->
    gen_server:start_link({local, ?MODULE}, ?MODULE, [BaseDir], []).

refresh() ->
    refresh(os:timestamp()).

refresh(Time) ->
    gen_server:cast(?MODULE, {refresh, Time}).

log_access(#wm_log_data{}=D) ->
    gen_server:cast(?MODULE, {log_access, D}).

log_message(Msg) ->
    gen_server:cast(?MODULE, {log_message, Msg}).


init([BaseDir]) ->
    defer_refresh(),
    FileName = alog_path(BaseDir),
    DateHour = datehour(),
    filelib:ensure_dir(FileName),
    Handle = log_open(FileName, DateHour),
    {ok, #state{filename=FileName, handle=Handle, hourstamp=DateHour}}.

handle_call(_Msg,_From,State) -> 
    {noreply,State}.

handle_cast({log_access, LogData}, State) ->
    Msg = format_req(LogData),
    {noreply, do_log(Msg, State)};

handle_cast({log_message, Msg}, State) ->
    {noreply, do_log(Msg, State)};

handle_cast({refresh, Time}, State) ->
    {noreply, maybe_rotate(State, Time)}.

handle_info({_Label, {From, MRef}, get_modules}, State) ->
    From ! {MRef, [?MODULE]},
    {noreply, State};
handle_info(_Info, State) ->
    {noreply, State}.

terminate(_Reason, _State) ->
    ok.

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


log_open(FileName, DateHour) ->
    LogName = FileName ++ suffix(DateHour),
    webmachine_util:to_console("opening log file: ~p~n", [LogName]),
    {ok, FD} = file:open(LogName, [read, write, raw]),
    {ok, Location} = file:position(FD, eof),
    fix_log(FD, Location),
    file:truncate(FD),
    {?MODULE, LogName, FD}.

log_write({?MODULE, _Name, FD}, IoData) ->
    file:write(FD, lists:flatten(IoData)).

log_close({?MODULE, Name, FD}) ->
    webmachine_util:to_console("~p: closing log file: ~p~n", [?MODULE, Name]),
    file:close(FD).

do_log(Msg, State) ->
    NewState = maybe_rotate(State, os:timestamp()),
    log_write(NewState#state.handle, Msg),
    NewState.

maybe_rotate(State, Time) ->
    ThisHour = datehour(Time),
    if ThisHour == State#state.hourstamp ->
	    State;
       true ->
	    defer_refresh(),
	    log_close(State#state.handle),
	    Handle = log_open(State#state.filename, ThisHour),
	    State#state{hourstamp=ThisHour, handle=Handle}
    end.    

get_metadata(Key, #wm_log_data{metadata=MetaData}) ->
    case dict:find(Key, MetaData) of
        {ok, Value} -> Value;
        error -> undefined
    end.

format_req(#wm_log_data{req_id=ReqId,
                        method=Method, 
			headers=Headers, 
			peer=Peer, 
			path=Path,
			version=Version,
			response_code=ResponseCode,
			response_length=ResponseLength}) ->
    User = "-",
    Time = fmtnow(),
    Status = integer_to_list(ResponseCode),
    Length = case is_atom(ResponseLength) of 
        true -> atom_to_list(ResponseLength); 
        false -> integer_to_list(ResponseLength) 
    end,
    Referer = 
	case mochiweb_headers:get_value("Referer", Headers) of
	    undefined -> "";
	    R -> R
	end,
    UserAgent = 
	case mochiweb_headers:get_value("User-Agent", Headers) of
	    undefined -> "";
	    U -> U
	end,
    fmt_alog(Time, ReqId, Peer, User, webmachine_util:fmt_method(Method), Path, Version,
	     Status, Length, Referer, UserAgent).


fix_log(_FD, 0) ->
    ok;
fix_log(FD, 1) ->
    {ok, 0} = file:position(FD, 0),
    ok;
fix_log(FD, Location) ->
    case file:pread(FD, Location - 1, 1) of
	{ok, [$\n | _]} ->
	    ok;
	{ok, _} ->
	    fix_log(FD, Location - 1)
    end.

defer_refresh() ->
    {_, {_, M, S}} = calendar:universal_time(),
    Time = 1000 * (3600 - ((M * 60) + S)),
    timer:apply_after(Time, ?MODULE, refresh, []).

datehour() ->
    datehour(os:timestamp()).

datehour(Now) ->
    {{Y, M, D}, {H, _, _}} = calendar:now_to_universal_time(Now),
    {Y, M, D, H}.

zeropad_str(NumStr, Zeros) when Zeros > 0 ->
    zeropad_str([$0 | NumStr], Zeros - 1);
zeropad_str(NumStr, _) ->
    NumStr.

zeropad(Num, MinLength) ->
    NumStr = integer_to_list(Num),
    zeropad_str(NumStr, MinLength - length(NumStr)).

suffix({Y, M, D, H}) ->
    YS = zeropad(Y, 4),
    MS = zeropad(M, 2),
    DS = zeropad(D, 2),
    HS = zeropad(H, 2),
    lists:flatten([$., YS, $_, MS, $_, DS, $_, HS]).

fmt_alog(Time, ReqId, Ip, User, Method, Path, {VM,Vm},
	 Status,  Length, Referrer, UserAgent) ->
    [fmt_ip(Ip), " - ", sanitize(User), [$\s], Time, [$\s, $"], sanitize(Method), " ", sanitize(Path),
     " HTTP/", integer_to_list(VM), ".", integer_to_list(Vm), [$",$\s],
     Status, [$\s], Length, [$\s,$"], sanitize(Referrer),
     [$",$\s,$"], sanitize(UserAgent), [$",$\s], integer_to_list(ReqId), [$\n]].

month(1) ->
    "Jan";
month(2) ->
    "Feb";
month(3) ->
    "Mar";
month(4) ->
    "Apr";
month(5) ->
    "May";
month(6) ->
    "Jun";
month(7) ->
    "Jul";
month(8) ->
    "Aug";
month(9) ->
    "Sep";
month(10) ->
    "Oct";
month(11) ->
    "Nov";
month(12) ->
    "Dec".
zone() ->
    Time = erlang:universaltime(),
    LocalTime = calendar:universal_time_to_local_time(Time),
    DiffSecs = calendar:datetime_to_gregorian_seconds(LocalTime) - calendar:datetime_to_gregorian_seconds(Time),
    zone((DiffSecs/3600)*100).


zone(Val) when Val < 0 ->
    io_lib:format("-~4..0w", [trunc(abs(Val))]);
zone(Val) when Val >= 0 ->
    io_lib:format("+~4..0w", [trunc(abs(Val))]).

fmt_ip(IP) when is_tuple(IP) ->
    inet_parse:ntoa(IP);
fmt_ip(undefined) ->
    "0.0.0.0";
fmt_ip(HostName) ->
    HostName.

fmtnow() ->
    {{Year, Month, Date}, {Hour, Min, Sec}} = calendar:local_time(),
    io_lib:format("[~2..0w/~s/~4..0w:~2..0w:~2..0w:~2..0w ~s]",
		  [Date,month(Month),Year, Hour, Min, Sec, zone()]).


  @seealso -bin/cvename.cgi?name=CVE-2009-4487
sanitize(S) ->
    sanitize(S, []).

sanitize([], Acc) ->
    lists:reverse(Acc);
sanitize([C|S], Acc) when C < 32 ->
    sanitize(S, [C+$A, $^ | Acc]);
sanitize([C|S], Acc) ->
    sanitize(S, [C|Acc]).
