1%%%% -*- erlang -*- 2%%%% This file is part of hackney released under the Apache 2 license. 3%%%% See the NOTICE for more information. 4-module(hackney_trace). 5 6-export([enable/2, disable/0, 7 set_level/1, 8 report_event/4]). 9 10-type trace_level() :: max | min | integer(). 11-type filename() :: string(). 12-type trace_type() :: io | filename() | port() | {fun(), any()}. 13 14 15-export_type([trace_level/0, 16 filename/0, 17 trace_type/0]). 18 19 20%% @doc start tracing 21%% start tracing at level Level and send the result either to the file File, 22%% the port Port or to a trace handler. 23%% 24%% Note: that it starts a tracer server. 25%% When Destination is the atom io (or the tuple {io, Verbosity}), 26%% %% all (printable) inets trace events (trace_ts events which has 27%% %% Severity within Limit) will be written to stdout using io:format. 28-spec enable(trace_level(), trace_type()) -> ok. 29enable(Level, File) when is_list(File) -> 30 case file:open(File, [write]) of 31 {ok, Fd} -> 32 HandleSpec = {fun handle_trace/2, {hackney, Fd}}, 33 do_enable(Level, process, HandleSpec); 34 Err -> 35 Err 36 end; 37enable(Level, Port) when is_integer(Port) -> 38 do_enable(Level, port, dbg:trace_port(ip, Port)); 39enable(Level, io) -> 40 HandleSpec = {fun handle_trace/2, {hackney, standard_io}}, 41 do_enable(Level, process, HandleSpec); 42enable(Level, {Fun, _Data}=HandleSpec) when is_function(Fun) -> 43 do_enable(Level, process, HandleSpec). 44 45do_enable(Level, Type, HandleSpec) -> 46 case dbg:tracer(Type, HandleSpec) of 47 {ok, _} -> 48 _ = set_level(Level), 49 ok; 50 Error -> 51 Error 52 end. 53 54%% @doc stop tracing 55-spec disable() -> ok. 56disable() -> 57 hackney_trace:report_event(100, "stop trace", stop_trace, [stop_trace]), 58 dbg:stop(). 59 60 61%% @doc change the trace level when tracing has already started. 62-spec set_level(trace_level()) -> ok | {error, term()}. 63set_level(Level) -> 64 Pat = make_pattern(?MODULE, Level), 65 change_pattern(Pat). 66 67make_pattern(Mod, Level) when is_atom(Mod) -> 68 case Level of 69 min -> 70 {Mod, hackney, []}; 71 max -> 72 Head = ['$1', '_', '_', '_'], 73 Body = [], 74 Cond = [], 75 {Mod, hackney, [{Head, Cond, Body}]}; 76 DetailLevel when is_integer(DetailLevel) -> 77 Head = ['$1', '_', '_', '_'], 78 Body = [], 79 Cond = [{ '=<', '$1', DetailLevel}], 80 {Mod, hackney, [{Head, Cond, Body}]}; 81 _ -> 82 exit({bad_level, Level}) 83 end. 84 85change_pattern({Mod, Service, Pattern}) 86 when is_atom(Mod) andalso is_atom(Service) -> 87 MFA = {Mod, report_event, 4}, 88 case Pattern of 89 [] -> 90 try 91 _ = error_to_exit(ctp, dbg:ctp(MFA)), 92 _ = error_to_exit(p, dbg:p(all, clear)), 93 ok 94 catch 95 exit:{Where, Reason} -> 96 {error, {Where, Reason}} 97 end; 98 List when is_list(List) -> 99 try 100 _ = error_to_exit(ctp, dbg:ctp(MFA)), 101 _ = error_to_exit(tp, dbg:tp(MFA, Pattern)), 102 _ = error_to_exit(p, dbg:p(all, [call, timestamp])), 103 ok 104 catch 105 exit:{Where, Reason} -> 106 {error, {Where, Reason}} 107 end 108 end. 109 110error_to_exit(_Where, {ok, _} = OK) -> 111 OK; 112error_to_exit(Where, {error, Reason}) -> 113 exit({Where, Reason}). 114 115 116report_event(Severity, Label, Service, Content) 117 when (is_integer(Severity) andalso 118 (Severity >= 0) andalso (100 >= Severity)) andalso 119 is_list(Label) andalso 120 is_atom(Service) andalso 121 is_list(Content) -> 122 hopefully_traced. 123 124 125handle_trace(_, closed_file = Fd) -> 126 Fd; 127handle_trace({trace_ts, _Who, call, 128 {?MODULE, report_event, 129 [_Sev, "stop trace", stop_trace, [stop_trace]]}, 130 Timestamp}, 131 {_, standard_io} = Fd) -> 132 (catch io:format(standard_io, "stop trace at ~s~n", [format_timestamp(Timestamp)])), 133 Fd; 134handle_trace({trace_ts, _Who, call, 135 {?MODULE, report_event, 136 [_Sev, "stop trace", stop_trace, [stop_trace]]}, 137 Timestamp}, 138 standard_io = Fd) -> 139 (catch io:format(Fd, "stop trace at ~s~n", [format_timestamp(Timestamp)])), 140 Fd; 141handle_trace({trace_ts, _Who, call, 142 {?MODULE, report_event, 143 [_Sev, "stop trace", stop_trace, [stop_trace]]}, 144 Timestamp}, 145 {_Service, Fd}) -> 146 (catch io:format(Fd, "stop trace at ~s~n", [format_timestamp(Timestamp)])), 147 (catch file:close(Fd)), 148 closed_file; 149handle_trace({trace_ts, _Who, call, 150 {?MODULE, report_event, 151 [_Sev, "stop trace", stop_trace, [stop_trace]]}, 152 Timestamp}, 153 Fd) -> 154 (catch io:format(Fd, "stop trace at ~s~n", [format_timestamp(Timestamp)])), 155 (catch file:close(Fd)), 156 closed_file; 157handle_trace({trace_ts, Who, call, 158 {?MODULE, report_event, 159 [Sev, Label, Service, Content]}, Timestamp}, 160 Fd) -> 161 (catch print_hackney_trace(Fd, Sev, Timestamp, Who, 162 Label, Service, Content)), 163 Fd; 164handle_trace(Event, Fd) -> 165 (catch print_trace(Fd, Event)), 166 Fd. 167 168 169print_hackney_trace({Service, Fd}, 170 Sev, Timestamp, Who, Label, Service, Content) -> 171 do_print_hackney_trace(Fd, Sev, Timestamp, Who, Label, Service, Content); 172print_hackney_trace({ServiceA, Fd}, 173 Sev, Timestamp, Who, Label, ServiceB, Content) 174 when (ServiceA =:= all) -> 175 do_print_hackney_trace(Fd, Sev, Timestamp, Who, Label, ServiceB, Content); 176print_hackney_trace({ServiceA, _Fd}, 177 _Sev, _Timestamp, _Who, _Label, ServiceB, _Content) 178 when ServiceA =/= ServiceB -> 179 ok; 180print_hackney_trace(Fd, Sev, Timestamp, Who, Label, Service, Content) -> 181 do_print_hackney_trace(Fd, Sev, Timestamp, Who, Label, Service, Content). 182 183do_print_hackney_trace(Fd, Sev, Timestamp, Who, Label, Service, Content) -> 184 Ts = format_timestamp(Timestamp), 185 io:format(Fd, "[~w trace ~w ~w ~s] ~s " 186 "~n Content: ~p" 187 "~n", 188 [Service, Sev, Who, Ts, Label, Content]). 189 190print_trace({_, Fd}, Event) -> 191 do_print_trace(Fd, Event); 192print_trace(Fd, Event) -> 193 do_print_trace(Fd, Event). 194 195do_print_trace(Fd, {trace, Who, What, Where}) -> 196 io:format(Fd, "[trace]" 197 "~n Who: ~p" 198 "~n What: ~p" 199 "~n Where: ~p" 200 "~n", [Who, What, Where]); 201 202do_print_trace(Fd, {trace, Who, What, Where, Extra}) -> 203 io:format(Fd, "[trace]" 204 "~n Who: ~p" 205 "~n What: ~p" 206 "~n Where: ~p" 207 "~n Extra: ~p" 208 "~n", [Who, What, Where, Extra]); 209 210do_print_trace(Fd, {trace_ts, Who, What, Where, When}) -> 211 Ts = format_timestamp(When), 212 io:format(Fd, "[trace ~s]" 213 "~n Who: ~p" 214 "~n What: ~p" 215 "~n Where: ~p" 216 "~n", [Ts, Who, What, Where]); 217 218do_print_trace(Fd, {trace_ts, Who, What, Where, Extra, When}) -> 219 Ts = format_timestamp(When), 220 io:format(Fd, "[trace ~s]" 221 "~n Who: ~p" 222 "~n What: ~p" 223 "~n Where: ~p" 224 "~n Extra: ~p" 225 "~n", [Ts, Who, What, Where, Extra]); 226 227do_print_trace(Fd, {seq_trace, What, Where}) -> 228 io:format(Fd, "[seq trace]" 229 "~n What: ~p" 230 "~n Where: ~p" 231 "~n", [What, Where]); 232 233do_print_trace(Fd, {seq_trace, What, Where, When}) -> 234 Ts = format_timestamp(When), 235 io:format(Fd, "[seq trace ~s]" 236 "~n What: ~p" 237 "~n Where: ~p" 238 "~n", [Ts, What, Where]); 239 240do_print_trace(Fd, {drop, Num}) -> 241 io:format(Fd, "[drop trace] ~p~n", [Num]); 242 243do_print_trace(Fd, Trace) -> 244 io:format(Fd, "[trace] " 245 "~n ~p" 246 "~n", [Trace]). 247 248 249format_timestamp({_N1, _N2, N3} = Now) -> 250 {Date, Time} = calendar:now_to_datetime(Now), 251 {YYYY,MM,DD} = Date, 252 {Hour,Min,Sec} = Time, 253 FormatDate = 254 io_lib:format("~.4w:~.2.0w:~.2.0w ~.2.0w:~.2.0w:~.2.0w 4~w", 255 [YYYY,MM,DD,Hour,Min,Sec,round(N3/1000)]), 256 lists:flatten(FormatDate). 257 258