1%%
2%% %CopyrightBegin%
3%%
4%% Copyright Ericsson AB 2012-2017. All Rights Reserved.
5%%
6%% Licensed under the Apache License, Version 2.0 (the "License");
7%% you may not use this file except in compliance with the License.
8%% You may obtain a copy of the License at
9%%
10%%     http://www.apache.org/licenses/LICENSE-2.0
11%%
12%% Unless required by applicable law or agreed to in writing, software
13%% distributed under the License is distributed on an "AS IS" BASIS,
14%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15%% See the License for the specific language governing permissions and
16%% limitations under the License.
17%%
18%% %CopyrightEnd%
19%%
20-module(ct_conn_log_h).
21
22%%%
23%%% A handler that can be connected to the error_logger event
24%%% handler. Writes all ct connection events. See comments in
25%%% cth_conn_log for more information.
26%%%
27
28-include("ct_util.hrl").
29
30-export([init/1,
31	 handle_event/2, handle_call/2, handle_info/2,
32	 terminate/2]).
33
34-record(state, {logs=[], default_gl}).
35
36-define(WIDTH,80).
37
38-define(now, os:timestamp()).
39
40%%%-----------------------------------------------------------------
41%%% Callbacks
42init({GL,ConnLogs}) ->
43    open_files(GL,ConnLogs,#state{default_gl=GL}).
44
45open_files(GL,[{ConnMod,{LogType,LogFiles}}|T],State=#state{logs=Logs}) ->
46    case do_open_files(LogFiles,[]) of
47	{ok,Fds} ->
48	    ConnInfo = proplists:get_value(GL,Logs,[]),
49	    Logs1 = [{GL,[{ConnMod,{LogType,Fds}}|ConnInfo]} |
50		     proplists:delete(GL,Logs)],
51	    open_files(GL,T,State#state{logs=Logs1});
52	Error ->
53	    Error
54    end;
55open_files(_GL,[],State) ->
56    {ok,State}.
57
58do_open_files([{Tag,File}|LogFiles],Acc) ->
59    case file:open(File, [write,append,{encoding,utf8}]) of
60	{ok,Fd} ->
61	    do_open_files(LogFiles,[{Tag,Fd}|Acc]);
62	{error,Reason} ->
63	    {error,{could_not_open_log,File,Reason}}
64    end;
65do_open_files([],Acc) ->
66    {ok,lists:reverse(Acc)}.
67
68handle_event({info_report,_,{From,update,{GL,ConnLogs}}},
69	     State) when node(GL) == node() ->
70    Result = open_files(GL,ConnLogs,State),
71    From ! {updated,GL},
72    Result;
73handle_event({_Type, GL, _Msg}, State) when node(GL) /= node() ->
74    {ok, State};
75handle_event({_Type,GL,{Pid,{ct_connection,Mod,Action,ConnName},Report}},
76	     State) ->
77    Info = conn_info(Pid,#conn_log{name=ConnName,action=Action,module=Mod}),
78    write_report(?now,Info,Report,GL,State),
79    {ok, State};
80handle_event({_Type,GL,{Pid,Info=#conn_log{},Report}}, State) ->
81    write_report(?now,conn_info(Pid,Info),Report,GL,State),
82    {ok, State};
83handle_event({error_report,GL,{Pid,_,[{ct_connection,ConnName}|R]}}, State) ->
84    %% Error reports from connection
85    write_error(?now,conn_info(Pid,#conn_log{name=ConnName}),R,GL,State),
86    {ok, State};
87handle_event(_What, State) ->
88    {ok, State}.
89
90handle_info(_What, State) ->
91    {ok, State}.
92
93handle_call(_Query, State) ->
94    {ok, {error, bad_query}, State}.
95
96terminate(_,#state{logs=Logs}) ->
97    lists:foreach(
98      fun({_GL,ConnLogs}) ->
99	      [file:close(Fd) || {_,{_,Fds}} <- ConnLogs, {_,Fd} <- Fds]
100      end, Logs),
101    ok.
102
103
104%%%-----------------------------------------------------------------
105%%% Writing reports
106write_report(_Time,#conn_log{header=false,module=ConnMod}=Info,Data,GL,State) ->
107    case get_log(Info,GL,State) of
108	{silent,_,_} ->
109	    ok;
110	{LogType,Dest,Fd} ->
111	    Str = if LogType == html, Dest == gl -> ["$tc_html","~n~ts"];
112		     true                        -> "~n~ts"
113		  end,
114	    io:format(Fd,Str,[format_data(ConnMod,LogType,Data)])
115    end;
116
117write_report(Time,#conn_log{module=ConnMod}=Info,Data,GL,State) ->
118    case get_log(Info,GL,State) of
119	{silent,_,_} ->
120	    ok;
121	{LogType,Dest,Fd} ->
122	    case format_data(ConnMod,LogType,Data) of
123		[] when Info#conn_log.action==send; Info#conn_log.action==recv ->
124		    ok;
125		FormattedData ->
126		    Str = if LogType == html, Dest == gl ->
127				  ["$tc_html","~n~ts~ts~ts"];
128			     true ->
129				  "~n~ts~ts~ts"
130			  end,
131		    io:format(Fd,Str,[format_head(ConnMod,LogType,Time),
132				      format_title(LogType,Info),
133				      FormattedData])
134	    end
135    end.
136
137write_error(Time,#conn_log{module=ConnMod}=Info,Report,GL,State) ->
138    case get_log(Info,GL,State) of
139	{LogType,_,_} when LogType==html; LogType==silent ->
140	    %% The error will anyway be written in the html log by the
141	    %% sasl error handler, so don't write it again.
142	    ok;
143	{LogType,Dest,Fd} ->
144	    Str = if LogType == html, Dest == gl -> ["$tc_html","~n~ts~ts~ts"];
145		     true                        -> "~n~ts~ts~ts"
146		  end,
147	    io:format(Fd,Str,[format_head(ConnMod,LogType,Time," ERROR"),
148			      format_title(LogType,Info),
149			      format_error(LogType,Report)])
150    end.
151
152get_log(Info,GL,State) ->
153    case proplists:get_value(GL,State#state.logs) of
154	undefined ->
155	    {html,gl,State#state.default_gl};
156	ConnLogs ->
157	    case proplists:get_value(Info#conn_log.module,ConnLogs) of
158		{html,_} ->
159		    {html,gl,GL};
160		{LogType,Fds} ->
161		    {LogType,file,get_fd(Info,Fds)};
162		undefined ->
163		    {html,gl,GL}
164	    end
165    end.
166
167get_fd(#conn_log{name=undefined},Fds) ->
168    proplists:get_value(default,Fds);
169get_fd(#conn_log{name=ConnName},Fds) ->
170    case proplists:get_value(ConnName,Fds) of
171	undefined ->
172	    proplists:get_value(default,Fds);
173	Fd ->
174	    Fd
175    end.
176
177%%%-----------------------------------------------------------------
178%%% Formatting
179format_head(ConnMod,LogType,Time) ->
180    format_head(ConnMod,LogType,Time,"").
181
182format_head(ConnMod,raw,Time,Text) ->
183    io_lib:format("~n~w, ~w~ts, ",[now_to_time(Time),ConnMod,Text]);
184format_head(ConnMod,_,Time,Text) ->
185    Head = pad_char_end(?WIDTH,pretty_head(now_to_time(Time),ConnMod,Text),$=),
186    io_lib:format("~n~ts",[Head]).
187
188format_title(raw,#conn_log{client=Client}=Info) ->
189    io_lib:format("Client ~tw ~s ~ts",[Client,actionstr(Info),serverstr(Info)]);
190format_title(_,Info) ->
191    Title = pad_char_end(?WIDTH,pretty_title(Info),$=),
192    io_lib:format("~n~ts", [Title]).
193
194format_data(_,_,NoData) when NoData == ""; NoData == <<>> ->
195    "";
196format_data(ConnMod,LogType,Data) ->
197    ConnMod:format_data(LogType,Data).
198
199format_error(raw,Report) ->
200    io_lib:format("~n~tp~n",[Report]);
201format_error(pretty,Report) ->
202    [io_lib:format("~n    ~tp: ~tp",[K,V]) || {K,V} <- Report].
203
204
205%%%-----------------------------------------------------------------
206%%% Helpers
207conn_info(LoggingProc, #conn_log{client=undefined} = ConnInfo) ->
208    conn_info(ConnInfo#conn_log{client=LoggingProc});
209conn_info(_, ConnInfo) ->
210    conn_info(ConnInfo).
211
212conn_info(#conn_log{client=Client, module=undefined} = ConnInfo) ->
213    case ets:lookup(ct_connections,Client) of
214	[#conn{address=Address,callback=Callback}] ->
215	    ConnInfo#conn_log{address=Address,module=Callback};
216	[] ->
217	    ConnInfo
218    end;
219conn_info(ConnInfo) ->
220    ConnInfo.
221
222
223now_to_time({_,_,MicroS}=Now) ->
224    {calendar:now_to_local_time(Now),MicroS}.
225
226pretty_head({{{Y,Mo,D},{H,Mi,S}},MicroS},ConnMod,Text0) ->
227    Text = string:uppercase(atom_to_list(ConnMod) ++ Text0),
228    io_lib:format("= ~s ==== ~s-~s-~w::~s:~s:~s,~s ",
229		  [Text,t(D),month(Mo),Y,t(H),t(Mi),t(S),
230		   micro2milli(MicroS)]).
231
232pretty_title(#conn_log{client=Client}=Info) ->
233    io_lib:format("= Client ~tw ~s ~ts ",
234		  [Client,actionstr(Info),serverstr(Info)]).
235
236actionstr(#conn_log{action=send}) -> "----->";
237actionstr(#conn_log{action=cmd}) -> "----->";
238actionstr(#conn_log{action=recv}) -> "<-----";
239actionstr(#conn_log{action=open}) -> "opened session to";
240actionstr(#conn_log{action=close}) -> "closed session to";
241actionstr(#conn_log{action=connect}) -> "connected to";
242actionstr(#conn_log{action=disconnect}) -> "disconnected from";
243actionstr(_) -> "<---->".
244
245serverstr(#conn_log{name=undefined,address={undefined,_}}) ->
246    io_lib:format("server",[]);
247serverstr(#conn_log{name=undefined,address=Address}) ->
248    io_lib:format("~tp",[Address]);
249serverstr(#conn_log{name=Alias,address={undefined,_}}) ->
250    io_lib:format("~tw",[Alias]);
251serverstr(#conn_log{name=Alias,address=Address}) ->
252    io_lib:format("~tw(~tp)",[Alias,Address]).
253
254month(1) -> "Jan";
255month(2) -> "Feb";
256month(3) -> "Mar";
257month(4) -> "Apr";
258month(5) -> "May";
259month(6) -> "Jun";
260month(7) -> "Jul";
261month(8) -> "Aug";
262month(9) -> "Sep";
263month(10) -> "Oct";
264month(11) -> "Nov";
265month(12) -> "Dec".
266
267micro2milli(X) ->
268    pad0(3,integer_to_list(X div 1000)).
269
270t(X) ->
271    pad0(2,integer_to_list(X)).
272
273pad0(N,Str) ->
274    M = length(Str),
275    lists:duplicate(N-M,$0) ++ Str.
276
277pad_char_end(N,Str,Char) ->
278    case string:length(Str) of
279	M when M<N -> Str ++ lists:duplicate(N-M,Char);
280	_ -> Str
281    end.
282