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