diff options
Diffstat (limited to 'lib/observer')
| -rw-r--r-- | lib/observer/doc/src/ttb.xml | 233 | ||||
| -rw-r--r-- | lib/observer/doc/src/ttb_ug.xml | 385 | ||||
| -rw-r--r-- | lib/observer/src/ttb.erl | 711 | ||||
| -rw-r--r-- | lib/observer/test/Makefile | 3 | ||||
| -rw-r--r-- | lib/observer/test/client.erl | 28 | ||||
| -rw-r--r-- | lib/observer/test/server.erl | 43 | ||||
| -rw-r--r-- | lib/observer/test/ttb_SUITE.erl | 748 | ||||
| -rw-r--r-- | lib/observer/test/ttb_helper.erl | 157 |
8 files changed, 1914 insertions, 394 deletions
diff --git a/lib/observer/doc/src/ttb.xml b/lib/observer/doc/src/ttb.xml index 2c80891925..4e63aecbf2 100644 --- a/lib/observer/doc/src/ttb.xml +++ b/lib/observer/doc/src/ttb.xml @@ -25,11 +25,12 @@ <title>ttb</title> <prepared>Siri hansen</prepared> + <prepared>Bartlomiej Puzon</prepared> <responsible></responsible> <docno>1</docno> <approved></approved> <checked></checked> - <date>2002-02-25</date> + <date>2010-08-13</date> <rev>PA1</rev> <file>ttb.sgml</file> </header> @@ -43,6 +44,35 @@ </description> <funcs> <func> + <name>start_trace(Nodes, Patterns, FlagSpec, Opts) -> Result</name> + <fsummary>Start a trace port on each given node.</fsummary> + <type> + <v>Result = see p/2</v> + <v>Nodes = see tracer/2</v> + <v>Patterns = [tuple()]</v> + <v>FlagSpec = {Procs, Flags}</v> + <v>Proc = see p/2</v> + <v>Flags = see p/2</v> + <v>Opts = see tracer/2</v> + </type> + <desc> + <p>This function is a shortcut allowing to start a trace with one command. Each + tuple in <c>Patterns</c> is converted to list which is in turn passed to + <c>ttb:tpl</c>. + The call:<code type="none"> +ttb:start_trace([Node, OtherNode], +[{mod, foo, []}, {mod, bar, 2}], +{all, call}, +[{file, File}, {handler,{fun myhandler/4, S}}])</code> + is equivalent to <code type="none"> +ttb:start_trace([Node, OtherNode], [{file, File}, {handler,{fun myhandler/4, S}}]), +ttb:tpl(mod, foo, []), +ttb:tpl(mod, bar, 2, []), +ttb:p(all, call)</code> + </p> + </desc> + </func> + <func> <name>tracer() -> Result</name> <fsummary>This is equivalent to tracer(node()).</fsummary> <desc> @@ -50,6 +80,17 @@ </desc> </func> <func> + <name>tracer(Shortcut) -> Result</name> + <fsummary>Handy shortcuts for common tracing settings</fsummary> + <type> + <v>Shortcut = shell | dbg</v> + </type> + <desc> + <p><c>shell</c> is equivalent to <c>tracer(node(),[{file, {local, "ttb"}}, shell])</c>.</p> + <p><c>dbg</c> is equivalent to <c>tracer(node(),[{shell, only}])</c>.</p> + </desc> + </func> + <func> <name>tracer(Nodes) -> Result</name> <fsummary>This is equivalent to tracer(Nodes,[]).</fsummary> <desc> @@ -62,14 +103,21 @@ <type> <v>Result = {ok, ActivatedNodes} | {error,Reason}</v> <v>Nodes = atom() | [atom()] | all | existing | new</v> - <v>Opts = [Opt]</v> - <v>Opt = {file,Client} | {handler, FormatHandler} | {process_info,PI}</v> + <v>Opts = Opt | [Opt]</v> + <v>Opt = {file,Client} | {handler, FormatHandler} | {process_info,PI} | + shell | {shell, ShellSpec} | {timer, TimerSpec} | {overload, {MSec, Module, Function}} + | {flush, MSec} | resume | {resume, FetchTimeout}</v> + <v>TimerSpec = MSec | {MSec, StopOpts}</v> + <v>MSec = FetchTimeout = integer()</v> + <v>Module = Function = atom() </v> + <v>StopOpts = see stop/2</v> <v>Client = File | {local, File}</v> <v>File = Filename | Wrap</v> <v>Filename = string()</v> <v>Wrap = {wrap,Filename} | {wrap,Filename,Size,Count}</v> <v>FormatHandler = See format/2</v> <v>PI = true | false </v> + <v>ShellSpec = true | false | only</v> </type> <desc> <p>This function starts a file trace port on all given nodes @@ -96,7 +144,70 @@ is the process' registered name its globally registered name, or its initial function. It is possible to turn off this functionality by setting <c>PI = false</c>. - </p> + </p> + <p>The <c>{shell, ShellSpec}</c> option indicates that the trace messages should + be printed on the console as they are received by the tracing + process. This implies <c>{local, File}</c> trace client. If the ShellSpec + is <c>only</c> (instead of <c>true</c>), no trace logs are stored. + </p> + <p>The <c>shell</c> option is a shortcut for <c>{shell, true}</c>.</p> + <p>The <c>timer</c> option indicates that the trace should be + automatically stopped after <c>MSec</c> milliseconds. <c>StopOpts</c> + are passed to <c>ttb:stop/2</c> command if specified (default is <c>[]</c>). + Note that the timing is approximate, as delays related to + network communication are always present. The timer starts after + <c>ttb:p/2</c> is issued, so you can set up your trace patterns before. + </p> + <p>The <c>overload</c> option allows to enable overload + checking on the nodes under trace. <c>Module:Function(check)</c> + is performed each <c>MSec</c> milliseconds. If the check returns + <c>true</c>, the tracing is disabled on a given node.<br/> + <c>Module:Function</c> should be able to handle at least three + atoms: <c>init</c>, <c>check</c> and <c>stop</c>. <c>init</c> and + <c>stop</c> give the user a possibility to initialize and clean + up the check environment.<br/> + When a node gets overloaded, it is not possible to issue <c>ttb:p</c> + nor any command from the <c>ttb:tp</c> family, as it would lead to + inconsistent tracing state (different trace specifications on + different node). + </p> + <p>The <c>flush</c> option periodically flushes all file trace + port clients (see <c>dbg:flush_trace_port/1</c>). When enabled, + the buffers are freed each <c>MSec</c> milliseconds. This option is + not allowed with <c>{file, {local, File}}</c> tracing. + </p> + <p><c>{resume, FetchTimeout}</c> enables the autoresume feature. + Whenever enabled, remote nodes try to reconnect to the controlling node + in case they were restarted. The feature requires <c>runtime_tools</c> + application to be started (so it has to be present in the <c>.boot</c> + scripts if the traced nodes run with embedded erlang). If this is + not possible, resume may be performed manually by starting + <c>runtime_tools</c> remotely using <c>rpc:call/4</c>.<br/> + <c>ttb</c> tries to fetch all logs from a reconnecting node before + reinitializing the trace. This has to finish within FetchTimeout milliseconds + or is aborted<br/> + By default, autostart information is stored in a file called + <c>ttb_autostart.bin</c> on each node. If this is not desired + (i.e. on diskless nodes), a custom module to handle autostart + information storage and retrieval can be provided by specifying + <c>ttb_autostart_module</c> environment variable for the <c>runtime_tools</c> + application. The module has to respond to the following API: + <taglist> + <tag><c>write_config(Data) -> ok</c></tag> + <item>Store the provided data for further retrieval. It is + important to realize that the data storage used must not + be affected by the node crash.</item> + <tag><c>read_config() -> {ok, Data} | {error, Error}</c></tag> + <item>Retrieve configuration stored with <c>write_config(Data)</c>.</item> + <tag><c>delete_config() -> ok</c></tag> + <item>Delete configuration stored with <c>write_config(Data)</c>. + Note that after this call any subsequent calls to <c>read_config</c> + must return <c>{error, Error}</c>. + </item> + </taglist> + </p> + <p>The <c>resume</c> option implies the default <c>FetchTimeout</c>, which is + 10 seconds</p> </desc> </func> <func> @@ -110,7 +221,7 @@ </type> <desc> <p>This function sets the given trace flags on the given - processes. + processes. The <c>timestamp</c> flag is always turned on. </p> <p>Please turn to the Reference manual for module <c>dbg</c> for details about the possible trace flags. The parameter @@ -119,6 +230,9 @@ registered names or process identifiers. If a registered name is given, the flags are set on processes with this name on all active nodes.</p> + <p>Issuing this command starts the timer for this trace if + <c>timer</c> option was specified with <c>tracer/2</c>. + </p> </desc> </func> <func> @@ -155,6 +269,18 @@ <tag><c>ctpg</c></tag> <item>Clear trace pattern on global function calls</item> </taglist> + <p>With <c>tp</c> and <c>tpl</c> one of match specification shortcuts + may be used (example: <c>ttb:tp(foo_module, caller)</c>). The shortcuts are: + <taglist> + <item><c>return</c> - for <c>[{'_',[],[{return_trace}]}]</c> + (report the return value)</item> + <item><c>caller</c> - for <c>[{'_',[],[{message,{caller}}]}]</c> + (report the calling function)</item> + <item><c>{codestr, Str}</c> - for <c>dbg:fun2ms/1</c> arguments + passed as strings (example: <c>"fun(_) -> return_trace() end"</c>) + </item> + </taglist> + </p> </desc> </func> <func> @@ -189,7 +315,7 @@ </desc> </func> <func> - <name>write_config(ConfigFile,Config,Opt) -> ok | {error,Reason}</name> + <name>write_config(ConfigFile,Config,Opts) -> ok | {error,Reason}</name> <fsummary>Creates a config file.</fsummary> <type> <v>ConfigFile = string()</v> @@ -197,7 +323,8 @@ <v>Mod = atom()</v> <v>Func = atom()</v> <v>Args = [term()]</v> - <v>Opt = [] | [append]</v> + <v>Opts = Opt | [Opt]</v> + <v>Opt = append</v> </type> <desc> <p>This function creates or extends a config file which can be @@ -213,9 +340,9 @@ should be a list of integers pointing out the entries to be stored. </p> - <p>If <c>Opt</c> is not given or if it is <c>[]</c>, + <p>If <c>Opts</c> is not given or if it is <c>[]</c>, <c>ConfigFile</c> is deleted and a new file is created. If - <c>Opt = [append]</c>, <c>ConfigFile</c> will not be deleted. + <c>Opts = [append]</c>, <c>ConfigFile</c> will not be deleted. The new information will be appended at the end of the file.</p> </desc> </func> @@ -226,7 +353,9 @@ <v>ConfigFile = string()</v> </type> <desc> - <p>Executes all entries in the given config file.</p> + <p>Executes all entries in the given config file. Note that the history + of the last trace is always available in the file named + <c>ttb_last_config</c>.</p> </desc> </func> <func> @@ -243,6 +372,9 @@ </p> <p>The content of a config file can be listed with <c>list_config/1</c>.</p> + <p> Note that the history + of the last trace is always available in the file named + <c>ttb_last_config</c>.</p> </desc> </func> <func> @@ -334,29 +466,51 @@ </desc> </func> <func> - <name>stop(Opts) -> stopped</name> + <name>stop(Opts) -> stopped | {stopped, Dir}</name> <fsummary>Stop tracing and fetch/format logs from all nodes</fsummary> <type> - <v>Opts = [Opt]</v> - <v>Opt = fetch | format</v> + <v>Opts = Opt | [Opt]</v> + <v>Opt = nofetch | {fetch_dir, Dir} | format | {format, FormatOpts} | return_fetch_dir</v> + <v>Dir = string()</v> + <v>FormatOpts = see format/2</v> </type> <desc> - <p>Stops tracing on all nodes. - </p> - <p>The <c>fetch</c> option indicates that trace logs shall be - collected from all nodes after tracing is stopped. This option - is useful if nodes on remote machines are traced. Logs and - trace information files are then sent to the trace control + <p>Stops tracing on all nodes. Logs and + trace information files are sent to the trace control node and stored in a directory named - <c>ttb_upload-Timestamp</c>, where <c>Timestamp</c> is on the + <c>ttb_upload_FileName-Timestamp</c>, where <c>Filename</c> is + the one provided with <c>{file, File}</c> during trace setup + and <c>Timestamp</c> is of the form <c>yyyymmdd-hhmmss</c>. Even logs from nodes on the same machine as the trace control node are moved to this directory. - </p> + The history list is saved to a file named <c>ttb_last_config</c> + for further reference (as it will be not longer accessible + through history and configuration management functions (like + <c>ttb:list_history/0</c>). + </p> + <p>The <c>nofetch</c> option indicates that trace logs shall not be + collected after tracing is stopped. + </p> + <p>The <c>{fetch, Dir}</c> option allows to specify the directory + to fetch the data to. If the directory already exists, an + error is thrown. + </p> <p>The <c>format</c> option indicates that the trace logs - shall be formatted after tracing is stopped. Note that this - option also implies the <c>fetch</c> option, i.e. logs are - collected in a new directory on the trace control node before - formatting. All logs in the directory will be merged.</p> + shall be formatted after tracing is stopped. All logs in the fetch directory will be merged. + You may use <c>{format, FormatOpts}</c> to pass additional + arguments to <c>format/2</c>.</p> + <p>The <c>return_fetch_dir</c> option indicates that the return value + should be <c>{stopped, Dir}</c> and not just <c>stopped</c>. + This implies <c>fetch</c>. + </p> + </desc> + </func> + <func> + <name>get_et_handler()</name> + <fsummary>Returns <c>et</c> handler.</fsummary> + <desc> + <p>The <c>et</c> handler returned by the function may be used with <c>format/2</c> + or <c>tracer/2</c>. Example: <c>ttb:format(Dir, [{handler, ttb:get_et_handler()}])</c>.</p> </desc> </func> <func> @@ -372,37 +526,40 @@ <type> <v>File = string() | [string()]</v> <d>This can be the name of a binary log, a list of such logs or the name of a directory containing one or more binary logs.</d> - <v>Options = [Opt]</v> - <v>Opt = {out,Out} | {handler,FormatHandler}</v> + <v>Options = Opt | [Opt]</v> + <v>Opt = {out,Out} | {handler,FormatHandler} | disable_sort</v> <v>Out = standard_io | string()</v> - <v>FormatHandler = {Function, InitialState} | et</v> + <v>FormatHandler = {Function, InitialState}</v> <v>Function = fun(Fd,Trace,TraceInfo,State) -> State</v> <v>Fd = standard_io | FileDescriptor</v> <d>This is the file descriptor of the destination file <c>Out</c></d> <v>Trace = tuple()</v> <d>This is the trace message. Please turn to the Reference manual for the <c>erlang</c>module for details.</d> <v>TraceInfo = [{Key,ValueList}]</v> - <d>This includes the keys <c>flags</c>, <c>client</c>and <c>node</c>, and if <c>handler</c>is given as option to the tracer function, this is also included. In addition all information written with the <c>write_trace_info/2</c>function is included. </d> + <d>This includes the keys <c>flags</c>, <c>client</c> and <c>node</c>, and if <c>handler</c> is given as option to the tracer function, this is also included. In addition all information written with the <c>write_trace_info/2</c>function is included. </d> </type> <desc> - <p>Reads the given binary trace log(s). If a directory or a - list of logs is given and the <c>timestamp</c> flag was set - during tracing, the trace messages from the different logs are - merged according to the timestamps. - </p> + <p>Reads the given binary trace log(s). The logs are processed + in the order of their timestamp as long as <c>disable_sort</c> + option is not given. + </p> <p>If <c>FormatHandler = {Function,InitialState}</c>, <c>Function</c> will be called for each trace message. If - <c>FormatHandler = et</c>, <c>et_viewer</c> in the <em>Event Tracer</em> application (<c>et</c>) is used for presenting the - trace log graphically. <c>ttb</c> provides a few different + <c>FormatHandler = get_et_handler()</c>, <c>et_viewer</c> in + the <em>Event Tracer</em> application (<c>et</c>) is used for presenting + the trace log graphically. <c>ttb</c> provides a few different filters which can be selected from the Filter menu in the <c>et_viewer</c>. If <c>FormatHandler</c> is not given, a default handler is used which presents each trace message as a line of text. </p> + <p>The state returned from each call of <c>Function</c> is passed to the next call, + even if next call is to format a message from another log file. + </p> <p>If <c>Out</c> is given, <c>FormatHandler</c> gets the - filedescriptor to <c>Out</c> as the first parameter. + file descriptor to <c>Out</c> as the first parameter. </p> - <p><c>Out</c> is ignored if <c>FormatHandler = et</c>. + <p><c>Out</c> is ignored if <c>et</c> format handler is used. </p> <p>Wrap logs can be formatted one by one or all in one go. To format one of the wrap logs in a set, give the exact name of diff --git a/lib/observer/doc/src/ttb_ug.xml b/lib/observer/doc/src/ttb_ug.xml index 44b7b08fd3..4f2b55a22a 100644 --- a/lib/observer/doc/src/ttb_ug.xml +++ b/lib/observer/doc/src/ttb_ug.xml @@ -4,7 +4,7 @@ <chapter> <header> <copyright> - <year>2002</year><year>2009</year> + <year>2002</year><year>2010</year> <holder>Ericsson AB. All Rights Reserved.</holder> </copyright> <legalnotice> @@ -48,11 +48,13 @@ <item>Formatting of binary trace logs and merging of logs from multiple nodes.</item> </list> - <p>Even though the intention of the Trace Tool Builder is to serve - as a base for tailor made trace tools, it is of course possible - to use it directly from the erlang shell. The application only - allows the use of file port tracer, so if you would like would - like to use other types of trace clients you will be better off + <p>The intention of the Trace Tool Builder is to serve + as a base for tailor made trace tools, but you may use it directly + from the erlang shell (it may mimic <c>dbg</c> behaviour while + still providing useful additions like match specification shortcuts). + The application only + allows the use of file port tracer, so if you would like + to use other types of trace clients you will be better off using <c>dbg</c> directly instead.</p> </section> @@ -64,14 +66,15 @@ trace flags on the processes you want to trace with <c>ttb:p/2</c>. Then, when the tracing is completed, you must stop the tracer with <c>ttb:stop/0/1</c> and format the trace log with - <c>ttb:format/1/2</c>. + <c>ttb:format/1/2</c> (as long as there is anything to format, of + course). </p> - <p><c>ttb:tracer/0/1/2</c> opens a file trace port on each node - that shall be traced. All trace messages will be written to this - port and end up in a binary file (the binary trace log). + <p><c>ttb:tracer/0/1/2</c> opens a trace port on each node + that shall be traced. By default, trace messages are written + to binary files on remote nodes(the binary trace log). </p> - <p><c>ttb:p/2</c> specifies which processes that shall be - traced. Trace flags given in this call specifies what to trace on + <p><c>ttb:p/2</c> specifies which processes shall be + traced. Trace flags given in this call specify what to trace on each process. You can call this function several times if you like different trace flags to be set on different processes. </p> @@ -105,14 +108,15 @@ -export([f/0]). f() -> receive - From when pid(From) -> + From when is_pid(From) -> Now = erlang:now(), From ! {self(),Now} end. </code> <p>The following example shows the basic use of <c>ttb</c> from the erlang shell. Default options are used both for starting the - tracer and for formatting. This gives a trace log named - <c>Node-ttb</c>, where <c>Node</c> is the name of the node. The + tracer and for formatting (the custom fetch dir is however provided). + This gives a trace log named <c>Node-ttb</c> in the newly-created + directory, where <c>Node</c> is the name of the node. The default handler prints the formatted trace messages in the shell.</p> <code type="none"><![CDATA[ @@ -131,11 +135,11 @@ f() -> (tiger@durin)50> (tiger@durin)50> %% Here I set a trace pattern on erlang:now/0 (tiger@durin)50> %% The trace pattern is a simple match spec -(tiger@durin)50> %% generated by dbg:fun2ms/1. It indicates that -(tiger@durin)50> %% the return value shall be traced. -(tiger@durin)50> MS = dbg:fun2ms(fun(_) -> return_trace() end). -[{'_',[],[{return_trace}]}] -(tiger@durin)51> ttb:tp(erlang,now,MS). +(tiger@durin)50> %% indicating that the return value should be +(tiger@durin)50> %% traced. Refer to the reference_manual for +(tiger@durin)50> %% the full list of match spec shortcuts +(tiger@durin)50> %% available. +(tiger@durin)51> ttb:tp(erlang,now,return). {ok,[{matched,tiger@durin,1},{saved,1}]} (tiger@durin)52> (tiger@durin)52> %% I run my test (i.e. send a message to @@ -145,11 +149,11 @@ f() -> (tiger@durin)53> (tiger@durin)53> %% And then I have to stop ttb in order to flush (tiger@durin)53> %% the trace port buffer -(tiger@durin)53> ttb:stop(). -stopped +(tiger@durin)53> ttb:stop([return, {fetch_dir, "fetch"}]). +{stopped, "fetch"} (tiger@durin)54> (tiger@durin)54> %% Finally I format my trace log -(tiger@durin)54> ttb:format("tiger@durin-ttb"). +(tiger@durin)54> ttb:format("fetch"). ({<0.125.0>,{m,f,0},tiger@durin}) call erlang:now() ({<0.125.0>,{m,f,0},tiger@durin}) returned from erlang:now/0 -> {1031,133451,667611} @@ -166,11 +170,9 @@ ok ]]></code> -module(mydebug). -export([start/0,trc/1,stop/0,format/1]). -export([print/4]). - %% Include ms_transform.hrl so that I can use dbg:fun2ms/2 to %% generate match specifications. -include_lib("stdlib/include/ms_transform.hrl"). - %%% -------------Tool API------------- %%% ---------------------------------- %%% Star the "mydebug" tool @@ -180,28 +182,28 @@ start() -> %% module shall be used as format handler ttb:tracer(all,[{file,"debug_log"},{handler,{{?MODULE,print},0}}]), %% All processes (existing and new) shall trace function calls - %% and include a timestamp in each trace message - ttb:p(all,[call,timestamp]). + %% We want trace messages to be sorted upon format, which requires + %% timestamp flag. The flag is however enabled by default in ttb. + ttb:p(all,call). %%% Set trace pattern on function(s) -trc(M) when atom(M) -> +trc(M) when is_atom(M) -> trc({M,'_','_'}); -trc({M,F}) when atom(M), atom(F) -> +trc({M,F}) when is_atom(M), is_atom(F) -> trc({M,F,'_'}); -trc({M,F,_A}=MFA) when atom(M), atom(F) -> - %% This match spec specifies that return values shall - %% be traced. NOTE that ms_transform.hrl must be included - %% if dbg:fun2ms/1 shall be used! +trc({M,F,_A}=MFA) when is_atom(M), is_atom(F) -> + %% This match spec shortcut specifies that return values shall + %% be traced. MatchSpec = dbg:fun2ms(fun(_) -> return_trace() end), ttb:tpl(MFA,MatchSpec). %%% Format a binary trace log -format(File) -> - ttb:format(File). +format(Dir) -> + ttb:format(Dir). %%% Stop the "mydebug" tool stop() -> - ttb:stop(). + ttb:stop(return). %%% --------Internal functions-------- %%% ---------------------------------- @@ -226,9 +228,9 @@ do_print(Out,{trace_ts,P,return_from,{M,F,A},R,Ts},N) -> [N,Ts,P,M,F,A,R]). ]]></code> <p>To distinguish trace logs produced with this tool from other logs, the <c>file</c> option is used in <c>tracer/2</c>. The - logs will therefore be named <c>Node-debug_log</c>, where - <c>Node</c> is the name of the node where the log is produced. - </p> + logs will therefore be fetched to a directory named + <c>ttb_upload_debug_log-YYYYMMDD-HHMMSS</c> + </p> <p>By using the <c>handler</c> option when starting the tracer, the information about how to format the file is stored in the trace information file (<c>.ti</c>). This is not necessary, as @@ -278,13 +280,157 @@ do_print(Out,{trace_ts,P,return_from,{M,F,A},R,Ts},N) -> must be given to the <c>tracer/2</c> function with the value <c>{local, File}</c>, e.g.</p> <code type="none"> -(trace_control@durin)1> ttb:tracer(mynode@diskless,[{file,{local, -{wrap,"mytrace"}}}]). +(trace_control@durin)1> ttb:tracer(mynode@diskless,{file,{local, +{wrap,"mytrace"}}}). {ok,[mynode@diskless]} </code> </section> </section> <section> + <title>Additional tracing options</title> + <p>When setting up a trace, several features may be turned on:</p> + <list type="bulleted"> + <item>time-constrained tracing,</item> + <item>overload protection,</item> + <item>autoresuming.</item> + </list> + <section> + <title>Time-constrained tracing</title> + <p>Sometimes, it may be helpful to enable trace for a + given period of time (i.e. to monitor a system for 24 hours + or half of a second). This may be done by issuing additional + <c>{timer, TimerSpec}</c> option. If <c>TimerSpec</c> has the + form of <c>MSec</c>, the trace is stopped after <c>MSec</c> + milliseconds using <c>ttb:stop/0</c>. If any additional options + are provided (<c>TimerSpec = {MSec, Opts}</c>), <c>ttb:stop/1</c> + is called instead with <c>Opts</c> as the arguments. The timer + is started with <c>ttb:p/2</c>, so any trace patterns should + be set up before. <c>ttb:start_trace/4</c> + always sets up all pattern before invoking <c>ttb:p/2</c>. + Note that due to network and processing delays the the period + of tracing is approximate. + The example below shows how to set up a trace which will be + automatically stopped and formatted after 5 seconds + </p><code> +(tiger@durin)1>ttb:start_trace([node()], + [{erlang, now,[]}], + {all, call}, + [{timer, {5000, format}}]). +</code> + </section> + <section> + <label>Overload protection</label> + <p>When tracing live systems, special care needs to be always taken + not to overload a node with too heavy tracing. <c>ttb</c> provides + the <c>overload</c> option to help to address the problem.</p> + <p><c>{overload, MSec, Module, Function}</c> instructs the ttb backend + (called <c>observer_backend</c>, part of the <c>runtime_tools</c> + application) to perform overload check every <c>MSec</c> milliseconds. + If the check (namely <c>Module:Function(check)</c>) returns + <c>true</c>, tracing is disabled on the selected node.</p> + <p>Overload protection activated on one node does not + affect other nodes, where the tracing continues as normal. + <c>ttb:stop/0/1</c> fetches data from all clients, including everything + that has been collected before overload protection was activated. + Note that + changing trace details (with <c>ttb:p</c> and <c>ttb:tp/tpl...</c>) + once overload protection gets activated in one of the traced + nodes is not permitted in order not to allow trace setup + to be inconsistent between nodes. + </p> + <p><c>Module:Function</c> provided with the <c>overload</c> option must + handle three calls: <c>init</c>, <c>check</c> and <c>stop</c>. <c>init</c> + and <c>stop</c> allows to perform some setup and teardown required by + the check. An overload check module could look like this (note that + <c>check</c> is always called by the same process, so <c>put</c> and + <c>get</c> are possible). + </p><code> +-module(overload). +-export([check/1]). + +check(init) -> + Pid = sophisticated_module:start(), + put(pid, Pid); +check(check) -> + get(pid) ! is_overloaded, + receive + Reply -> + Reply + after 5000 -> + true + end; +check(stop) -> + get(pid) ! stop.</code> + </section> + <section> + <title>Autoresume</title> + <p>It is possible that a node (probably a buggy one, hence traced) + crashes. In order to automatically resume tracing on the node + as soon as it gets back, <c>resume</c> has to be used. When + it is, the failing node tries to reconnect + to trace control node as soon as <c>runtime tools</c> is started. + This implies that <c>runtime_tools</c> must be included in + other node's startup chain (if it is not, one could still + resume tracing by starting <c>runtime_tools</c> manually, + i.e. by an RPC call).</p> + <p>In order not to loose the data that the failing node stored + up to the point of crash, the control node will try to fetch + it before restarting trace. This must happen within the allowed + time frame or is aborted (default is 10 seconds, can be customized with + <c>{resume, MSec}</c>). The data fetched this way is then + merged with all other traces.</p> + <p>Autostart feature requires additional data to be stored on + traced nodes. By default, the data is stored automatically + to the file called "ttb_autostart.bin" in the traced node's cwd. + Users may decide to change this behaviour (i.e. on diskless + nodes) by specifying their own module to handle autostart data + storage and retrieval (<c>ttb_autostart_module</c> + environment variable of <c>runtime_tools</c>). Please see the + ttb's reference manual to see the module's API. This example + shows the default handler</p> + <code> +-module(ttb_autostart). +-export([read_config/0, + write_config/1, + delete_config/0]). + +-define(AUTOSTART_FILENAME, "ttb_autostart.bin"). + +delete_config() -> + file:delete(?AUTOSTART_FILENAME). + +read_config() -> + case file:read_file(?AUTOSTART_FILENAME) of + {ok, Data} -> {ok, binary_to_term(Data)}; + Error -> Error + end. + +write_config(Data) -> + file:write_file(?AUTOSTART_FILENAME, term_to_binary(Data)). + </code> + <p>Remember that file trace ports buffer the data + by default. If the node crashes, trace messages are not + flushed to the binary log. If the chance of failure is + high, it might be a good idea to automatically flush + the buffers every now and then. Passing <c>{flush, MSec}</c> + as one of <c>ttb:tracer/2</c> option flushes all buffers + every <c>MSec</c> milliseconds.</p> + </section> + <section> + <title>dbg mode</title> + <p>The <c>{shell, ShellType}</c> option allows to make <c>ttb</c> + operation similar to <c>dbg</c>. Using <c>{shell, true}</c> + displays all trace messages in the shell before storing them. + <c>{shell, only}</c> additionally disables message storage + (so that the tool behaves exactly like dbg). This is allowed + only with ip trace ports (<c>{trace, {local, File}}</c>). + </p> + <p>The command <c>ttb:tracer(dbg)</c> is a shortcut for the pure-dbg + mode (<c>{shell, only}</c>).</p> + </section> + </section> + + <section> <marker id="trace_info"></marker> <title>Trace Information and the .ti File</title> <p>In addition to the trace log file(s), a file with the extension @@ -292,13 +438,9 @@ do_print(Out,{trace_ts,P,return_from,{M,F,A},R,Ts},N) -> is the trace information file. It is a binary file, and it contains the process information, trace flags used, the name of the node to which it belongs and all information written with the - <c>write_trace_info/2</c> function. - </p> - <p>To be able to use all this information during formatting, it is - important that the trace information file exists in the same - directory as the trace log, and that it has the same name as the - trace log with the additional extension <c>.ti</c>. - </p> + <c>write_trace_info/2</c> function. .ti files are always fetched + with other logs when the trace is stopped. + </p> <p>Except for the process information, everything in the trace information file is passed on to the handler function when formatting. The <c>TI</c> parameter is a list of @@ -327,7 +469,12 @@ do_print(Out,{trace_ts,P,return_from,{M,F,A},R,Ts},N) -> each log. <c>ttb</c> will create a new binary log each time a log reaches the maximum size. When the the maximum number of logs are reached, the oldest log is deleted before a new one is created. - </p> + </p> + <p>Note that the overall size of data generated by ttb may be greater + than the wrap specification would suggest - if a traced node restarts + and autoresume is enabled, old wrap log is always stored and + a new one is created. + </p> <p>Wrap logs can be formatted one by one or all at once. See <seealso marker="#format">Formatting</seealso>. </p> @@ -348,12 +495,10 @@ do_print(Out,{trace_ts,P,return_from,{M,F,A},R,Ts},N) -> present the trace log graphically (see <seealso marker="#et_viewer">Presenting trace logs with Event Tracer</seealso>). </p> <p>The first argument to <c>ttb:format/1/2</c> specifies which - binary log(s) to format. This can be the name of one binary log, a - list of such logs or the name of a directory containing one or - more binary logs. If this argument indicates more than one log, - and the <c>timestamp</c> flag was set when tracing, the trace - messages from the different logs will be merged according to the - timestamps in each message. + binary log(s) to format. This is usually the name of a directory + that ttb created during log fetch. Unless there is the <c>disable_sort</c> + option provided, the logs from different files are always sorted + according to timestamp in traces. </p> <p>The second argument to <c>ttb:format/2</c> is a list of options. The <c>out</c> option specifies the destination where the @@ -363,7 +508,10 @@ do_print(Out,{trace_ts,P,return_from,{M,F,A},R,Ts},N) -> option is not given, the <c>handler</c> option given when starting the tracer is used. If the <c>handler</c> option was not given when starting the tracer either, a default handler is used, which - prints each trace message as a line of text. + prints each trace message as a line of text. The <c>disable_sort</c> + option indicates that there logs should not be merged according to + timestamp, but processed one file after another (this might be + a bit faster). </p> <p>A format handler is a fun taking four arguments. This fun will be called for each trace message in the binary log(s). A simple @@ -396,10 +544,24 @@ end </code> <c>handle_gc/4</c> in the module <c>multitrace.erl</c> which can be found in the <c>src</c> directory of the Observer application. </p> - <p>By giving the format handler <c>et</c>, you can have the trace + <p>The actual trace message is passed as the second argument (<c>Trace</c>). + The possible values of <c>Trace</c> are:</p> + <list type="bulleted"> + <item>all trace messages described in <c>erlang:trace/3</c> documentation, + </item> + <item><c>{drop, N}</c> if ip tracer is used (see <c>dbg:trace_port/2</c>), + </item> + <item><c>end_of_trace</c> received once when all trace messages have + been processed.</item> + </list> + <p>By giving the format handler <c>ttb:get_et_handler()</c>, you can have the trace log presented graphically with <c>et_viewer</c> in the Event Tracer application (see <seealso marker="#et_viewer">Presenting trace logs with Event Tracer</seealso>). - </p> + </p> + <p>You may always decide not to format the whole trace data contained + in the fetch directory, but analyze single files instead. In order + to do so, a single file (or list of files) have to be passed as + the first argument to <c>format/1/2</c>.</p> <p>Wrap logs can be formatted one by one or all in one go. To format one of the wrap logs in a set, give the exact name of the file. To format the whole set of wrap logs, give the name with '*' @@ -407,7 +569,7 @@ end </code> </p> <p>Start tracing:</p> <code type="none"> -(tiger@durin)1> ttb:tracer(node(),[{file,{wrap,"trace"}}]). +(tiger@durin)1> ttb:tracer(node(),{file,{wrap,"trace"}}). {ok,[tiger@durin]} (tiger@durin)2> ttb:p(...) ... </code> @@ -443,7 +605,7 @@ ok to the User's Guide and Reference Manuals for the <c>et</c> application. </p> - <p>By giving the format handler <c>et</c>, you can have the + <p>By giving the format handler <c>ttb:get_et_handler()</c>, you can have the trace log presented graphically with <c>et_viewer</c> in the Event Tracer application. <c>ttb</c> provides a few different filters which can be selected from the Filter menu in the @@ -495,9 +657,23 @@ ok filters respectively, except that each module or function can have several vertical lines, one for each process it resides on. </p> - <p>As an example this module is used, and the function - <c>bar:f1()</c> is called from another module <c>foo</c>.</p> + <p>In the next example, modules <c>foo</c> and <c>bar</c> are used:</p> <code type="none"> +-module(foo). +-export([start/0,go/0]). + +start() -> + spawn(?MODULE, go, []). + +go() -> + receive + stop -> + ok; + go -> + bar:f1(), + go() + end. +</code><code type="none"> -module(bar). -export([f1/0,f3/0]). f1() -> @@ -506,12 +682,23 @@ f1() -> f2() -> spawn(?MODULE,f3,[]). f3() -> - ok. </code> - <p>The <c>call</c> and <c>return_to</c> flags are used, and - trace pattern is set on local calls in module <c>bar</c>. - </p> - <p><c>ttb:format("tiger@durin-ttb", [{handler, et}])</c> gives the - following result: + ok.</code> + + <p>Now let's set up the trace.</p> +<code> +(tiger@durin)1>%%First we retrieve the Pid to limit traced processes set +(tiger@durin)1>Pid = foo:start(). +(tiger@durin)2>%%Now we set up tracing +(tiger@durin)2>ttb:tracer(). +(tiger@durin)3>ttb:p(Pid, [call, return_to, procs, set_on_spawn]). +(tiger@durin)4>ttb:tpl(bar, []). +(tiger@durin)5>%%Invoke our test function and see output with et viewer +(tiger@durin)5>Pid ! go. +(tiger@durin)6>ttb:stop({format, {handler, ttb:get_et_handler()}}). +</code> + + <p>This shoud render a result similar to the + following: </p> <p></p> <image file="et_processes.gif"> @@ -520,25 +707,37 @@ f3() -> <image file="et_modsprocs.gif"> <icaption>Filter: "mods_and_procs"</icaption> </image> + + <p>Note, that we can use <c>ttb:start_trace/4</c> function to help + us here:</p> +<code> +(tiger@durin)1>Pid = foo:start(). +(tiger@durin)2>ttb:start_trace([node()], + [{bar,[]}], + {Pid, [call, return_to, procs, set_on_spawn]} + {handler, ttb:get_et_handler()}). +(tiger@durin)3>Pid ! go. +(tiger@durin)4>ttb:stop(format). +</code> + </section> </section> <section> <marker id="fetch_format"></marker> <title>Automatically collect and format logs from all nodes</title> - <p>If the option <c>fetch</c> is given to the <c>ttb:stop/1</c> - function, trace logs and trace information files are fetched - from all nodes after tracing is stopped. The logs are stored in a - new directory named <c>ttb_upload-Timestamp</c> under the working - directory of the trace control node. + <p>By default <c>ttb:stop/1</c> fetches trace logs and + trace information files from all nodes. The logs are stored in a + new directory named <c>ttb_upload-Filename-Timestamp</c> under the working + directory of the trace control node. Fetching may be disabled by + providing the <c>nofetch</c> option to <c>ttb:stop/1</c>. User can + specify a fetch directory of his choice passing the + <c>{fetch_dir, Dir}</c> option. </p> <p>If the option <c>format</c> is given to <c>ttb:stop/1</c>, the trace logs are automatically formatted after tracing is - stopped. Note that <c>format</c> also implies <c>fetch</c>, - i.e. the trace logs will be collected from all nodes as for the - <c>fetch</c> option before they are formatted. All logs in the - upload directory are merged during formatting. - </p> + stopped. + </p> </section> <section> @@ -546,13 +745,18 @@ f3() -> <p>For the tracing functionality, <c>dbg</c> could be used instead of the <c>ttb</c> for setting trace flags on processes and trace patterns for call trace, i.e. the functions <c>p</c>, <c>tp</c>, - <c>tpl</c>, <c>ctp</c>, <c>ctpl</c> and <c>ctpg</c>. The only - thing added by <c>ttb</c> for these functions is that all calls - are stored in the history buffer and can be recalled and stored in - a configuration file. This makes it easy to setup the same trace - environment e.g. if you want to compare two test runs. It also - reduces the amount of typing when using <c>ttb</c> from the erlang - shell. + <c>tpl</c>, <c>ctp</c>, <c>ctpl</c> and <c>ctpg</c>. There are only + two things added by <c>ttb</c> for these functions: + <list type="bulleted"> + <item>all calls are stored in the history buffer and can be + recalled and stored in a configuration file. This makes it + easy to setup the same trace environment e.g. if you want to + compare two test runs. It also reduces the amount of + typing when using <c>ttb</c> from the erlang shell;</item> + <item>shortcuts are provided for the most common match + specifications (in order not to force the user to use + <c>dbg:fun2ms</c> continually</item>). + </list> </p> <p>Use <c>list_history/0</c> to see the content of the history buffer, and <c>run_history/1</c> to re-execute one of the entries. @@ -574,7 +778,8 @@ f3() -> selected entries from the history by calling <c>ttb:write_config(ConfigFile,NumList)</c>, where <c>NumList</c> is a list of integers pointing out the history - entries to write. + entries to write. Moreover, the history buffer is always dumped + to <c>ttb_last_config</c> when <c>ttb:stop/0/1</c> is called. </p> <p>User defined entries can also be written to a config file by calling the function @@ -720,9 +925,7 @@ ok {ok,[{matched,1},{saved,1}]} (tiger@durin)113> dbg:get_tracer(), seq_trace:reset_trace(). true -(tiger@durin)114> ttb:stop(). -ok -(tiger@durin)115> ttb:format("tiger@durin-ttb"). +(tiger@durin)114> ttb:stop(format). ({<0.158.0>,{shell,evaluator,3},tiger@durin}) call dbg:get_tracer() SeqTrace [0]: ({<0.158.0>,{shell,evaluator,3},tiger@durin}) {<0.237.0>,dbg,tiger@durin} ! {<0.158.0>,{get_tracer,tiger@durin}} @@ -743,9 +946,7 @@ ok (tiger@durin)117> seq_trace:set_token(send,true), dbg:get_tracer(), seq_trace:reset_trace(). true -(tiger@durin)118> ttb:stop(). -ok -(tiger@durin)119> ttb:format("tiger@durin-ttb"). +(tiger@durin)118> ttb:stop(format). SeqTrace [0]: ({<0.158.0>,{shell,evaluator,3},tiger@durin}) {<0.246.0>,dbg,tiger@durin} ! {<0.158.0>,{get_tracer,tiger@durin}} [Serial: {0,1}] diff --git a/lib/observer/src/ttb.erl b/lib/observer/src/ttb.erl index 221b71df6a..072aa165e7 100644 --- a/lib/observer/src/ttb.erl +++ b/lib/observer/src/ttb.erl @@ -18,9 +18,11 @@ %% -module(ttb). -author('[email protected]'). +-author('[email protected]'). %% API --export([tracer/0,tracer/1,tracer/2,p/2,stop/0,stop/1]). +-export([tracer/0,tracer/1,tracer/2,p/2,stop/0,stop/1,start_trace/4]). +-export([get_et_handler/0]). -export([tp/2, tp/3, tp/4, ctp/0, ctp/1, ctp/2, ctp/3, tpl/2, tpl/3, tpl/4, ctpl/0, ctpl/1, ctpl/2, ctpl/3, ctpg/0, ctpg/1, ctpg/2, ctpg/3]). -export([seq_trigger_ms/0,seq_trigger_ms/1]). @@ -34,24 +36,38 @@ -include_lib("kernel/include/file.hrl"). -define(meta_time,5000). +-define(fetch_time, 10000). -define(history_table,ttb_history_table). -define(seq_trace_flags,[send,'receive',print,timestamp]). --define(upload_dir,"ttb_upload"). +-define(upload_dir(Logname),"ttb_upload_"++Logname). +-define(last_config, "ttb_last_config"). +-define(partial_dir, "ttb_partial_result"). -ifdef(debug). --define(get_status,;get_status -> erlang:display(dict:to_list(NodeInfo)),loop(NodeInfo)). +-define(get_status,;get_status -> erlang:display(dict:to_list(NodeInfo),loop(NodeInfo, TraceInfo)). -else. -define(get_status,). -endif. %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% +%%% Shortcut +start_trace(Nodes, Patterns, {Procs, Flags}, Options) -> + {ok, _} = tracer(Nodes, Options), + [{ok, _} = apply(?MODULE, tpl, tuple_to_list(Args)) || Args <- Patterns], + {ok, _} = p(Procs, Flags). + + +%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Open a trace port on all given nodes and create the meta data file tracer() -> tracer(node()). +tracer(shell) -> tracer(node(), shell); +tracer(dbg) -> tracer(node(), {shell, only}); tracer(Nodes) -> tracer(Nodes,[]). tracer(Nodes,Opt) -> - start(), - store(tracer,[Nodes,Opt]), {PI,Client,Traci} = opt(Opt), - do_tracer(Nodes,PI,Client,Traci). + %%We use initial Traci as SessionInfo for loop/2 + Pid = start(Traci), + store(tracer,[Nodes,Opt]), + do_tracer(Nodes,PI,Client,[{ttb_control, Pid}|Traci]). do_tracer(Nodes0,PI,Client,Traci) -> Nodes = nods(Nodes0), @@ -59,9 +75,14 @@ do_tracer(Nodes0,PI,Client,Traci) -> do_tracer(Clients,PI,Traci). do_tracer(Clients,PI,Traci) -> + ShellOutput = proplists:get_value(shell, Traci, false), {ClientSucc,Succ} = lists:foldl( fun({N,{local,File},TF},{CS,S}) -> + TF2 = case ShellOutput of + only -> none; + _ -> TF + end, [_Sname,Host] = string:tokens(atom_to_list(N),"@"), case catch dbg:tracer(N,port,dbg:trace_port(ip,0)) of {ok,N} -> @@ -69,8 +90,8 @@ do_tracer(Clients,PI,Traci) -> {ok,T} = dbg:get_tracer(N), rpc:call(N,seq_trace,set_system_tracer,[T]), dbg:trace_client(ip,{Host,Port}, - {fun ip_to_file/2,{file,File}}), - {[{N,{local,File,Port},TF}|CS], [N|S]}; + {fun ip_to_file/2,{{file,File}, ShellOutput}}), + {[{N,{local,File,Port},TF2}|CS], [N|S]}; Other -> display_warning(N,{cannot_open_ip_trace_port, Host, @@ -98,17 +119,54 @@ do_tracer(Clients,PI,Traci) -> {ok,Succ} end. +opt(Opt) when is_list(Opt) -> + opt(Opt,{true,?MODULE,[]}); opt(Opt) -> - opt(Opt,{true,?MODULE,[]}). + opt([Opt]). opt([{process_info,PI}|O],{_,Client,Traci}) -> opt(O,{PI,Client,Traci}); opt([{file,Client}|O],{PI,_,Traci}) -> - opt(O,{PI,Client,Traci}); + opt(O,{PI,Client,[{logfile,get_logname(Client)}|Traci]}); opt([{handler,Handler}|O],{PI,Client,Traci}) -> opt(O,{PI,Client,[{handler,Handler}|Traci]}); +opt([{timer, {MSec, StopOpts}}|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{timer,{MSec, StopOpts}}|Traci]}); +opt([{timer, MSec}|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{timer,{MSec, []}}|Traci]}); +opt([{overload_check, {MSec,M,F}}|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{overload_check,{MSec,M,F}}|Traci]}); +opt([shell|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{shell, true}|Traci]}); +opt([{shell,Type}|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{shell, Type}|Traci]}); +opt([resume|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{resume, {true, ?fetch_time}}|Traci]}); +opt([{resume,MSec}|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{resume, {true, MSec}}|Traci]}); +opt([{flush,MSec}|O],{PI,Client,Traci}) -> + opt(O,{PI,Client,[{flush, MSec}|Traci]}); opt([],Opt) -> - Opt. + ensure_opt(Opt). + +ensure_opt({PI,Client,Traci}) -> + case {proplists:get_value(flush, Traci), Client} of + {undefined, _} -> ok; + {_, {local, _}} -> exit(flush_unsupported_with_ip_trace_port); + {_,_} -> ok + end, + NeedIpTracer = proplists:get_value(shell, Traci, false) /= false, + case {NeedIpTracer, Client} of + {false, _} -> {PI, Client, Traci}; + {true, ?MODULE} -> {PI, {local, ?MODULE}, Traci}; + {true, {local, File}} -> {PI, {local, File}, Traci}; + {true, _} -> exit(local_client_required_on_shell_tracing) + end. + +get_logname({local, F}) -> get_logname(F); +get_logname({wrap, F}) -> filename:basename(F); +get_logname({wrap, F, _, _}) -> filename:basename(F); +get_logname(F) -> filename:basename(F). nods(all) -> Nodes1 = remove_active([node()|nodes()]), @@ -205,17 +263,29 @@ run_history([H|T]) -> ok -> run_history(T); {error,not_found} -> {error,{not_found,H}} end; + +run_history(all) -> + CurrentHist = ets:tab2list(?history_table), + ets:delete_all_objects(?history_table), + [run_printed(MFA,true) || {_, MFA} <- CurrentHist]; +run_history(all_silent) -> + CurrentHist = ets:tab2list(?history_table), + ets:delete_all_objects(?history_table), + [run_printed(MFA,false) || {_, MFA} <- CurrentHist]; run_history([]) -> ok; run_history(N) -> case catch ets:lookup(?history_table,N) of [{N,{M,F,A}}] -> - print_func(M,F,A), - R = apply(M,F,A), - print_result(R); + run_printed({M,F,A},true); _ -> {error, not_found} end. + +run_printed({M,F,A},Verbose) -> + Verbose andalso print_func(M,F,A), + R = apply(M,F,A), + Verbose andalso print_result(R). write_config(ConfigFile,all) -> write_config(ConfigFile,['_']); @@ -223,6 +293,8 @@ write_config(ConfigFile,Config) -> write_config(ConfigFile,Config,[]). write_config(ConfigFile,all,Opt) -> write_config(ConfigFile,['_'],Opt); +write_config(ConfigFile,Config,Opt) when not(is_list(Opt)) -> + write_config(ConfigFile,Config,[Opt]); write_config(ConfigFile,Nums,Opt) when is_list(Nums), is_integer(hd(Nums)); Nums=:=['_'] -> F = fun(N) -> ets:select(?history_table, @@ -313,6 +385,7 @@ arg_list([A1|A],Acc) -> %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Set trace flags on processes p(Procs0,Flags0) -> + ensure_no_overloaded_nodes(), store(p,[Procs0,Flags0]), no_store_p(Procs0,Flags0). no_store_p(Procs0,Flags0) -> @@ -327,11 +400,12 @@ no_store_p(Procs0,Flags0) -> {error,Reason} -> display_warning(P,Reason), {PMatched,Ps} - end + end end,{[],[]},Procs) of {[],[]} -> {error, no_match}; {SuccMatched,Succ} -> no_store_write_trace_info(flags,{Succ,Flags}), + ?MODULE ! trace_started, {ok,SuccMatched} end end. @@ -339,7 +413,7 @@ no_store_p(Procs0,Flags0) -> transform_flags([clear]) -> [clear]; transform_flags(Flags) -> - dbg:transform_flags(Flags). + dbg:transform_flags([timestamp | Flags]). procs(Procs) when is_list(Procs) -> @@ -365,24 +439,30 @@ proc({global,Name}) -> %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Trace pattern tp(A,B) -> - store(tp,[A,B]), - dbg:tp(A,B). + ensure_no_overloaded_nodes(), + store(tp,[A,ms(B)]), + dbg:tp(A,ms(B)). tp(A,B,C) -> - store(tp,[A,B,C]), - dbg:tp(A,B,C). + ensure_no_overloaded_nodes(), + store(tp,[A,B,ms(C)]), + dbg:tp(A,B,ms(C)). tp(A,B,C,D) -> - store(tp,[A,B,C,D]), - dbg:tp(A,B,C,D). + ensure_no_overloaded_nodes(), + store(tp,[A,B,C,ms(D)]), + dbg:tp(A,B,C,ms(D)). tpl(A,B) -> - store(tpl,[A,B]), - dbg:tpl(A,B). + ensure_no_overloaded_nodes(), + store(tpl,[A,ms(B)]), + dbg:tpl(A,ms(B)). tpl(A,B,C) -> - store(tpl,[A,B,C]), - dbg:tpl(A,B,C). + ensure_no_overloaded_nodes(), + store(tpl,[A,B,ms(C)]), + dbg:tpl(A,B,ms(C)). tpl(A,B,C,D) -> - store(tpl,[A,B,C,D]), - dbg:tpl(A,B,C,D). + ensure_no_overloaded_nodes(), + store(tpl,[A,B,C,ms(D)]), + dbg:tpl(A,B,C,ms(D)). ctp() -> store(ctp,[]), @@ -423,6 +503,56 @@ ctpg(A,B,C) -> store(ctpg,[A,B,C]), dbg:ctpg(A,B,C). +ms(return) -> + [{'_',[],[{return_trace}]}]; +ms(caller) -> + [{'_',[],[{message,{caller}}]}]; +ms({codestr, FunStr}) -> + {ok, MS} = string2ms(FunStr), + MS; +ms(Other) -> + Other. + +ensure_no_overloaded_nodes() -> + Overloaded = case whereis(?MODULE) of + undefined -> + []; + _ -> + ?MODULE ! {get_overloaded, self()}, + receive O -> O end + end, + case Overloaded of + [] -> ok; + Overloaded -> exit({error, overload_protection_active, Overloaded}) + end. + +-spec string2ms(string()) -> {ok, list()} | {error, fun_format}. +string2ms(FunStr) -> + case erl_scan:string(fix_dot(FunStr)) of + {ok, Tokens, _} -> + case erl_parse:parse_exprs(Tokens) of + {ok, [Expression]} -> + case Expression of + {_, _, {clauses, Clauses}} -> + {ok, ms_transform:transform_from_shell(dbg, Clauses, [])}; + _ -> + {error, fun_format} + end; + _ -> + {error, fun_format} + end; + _ ->{error, fun_format} + end. + +-spec fix_dot(string()) -> string(). +fix_dot(FunStr) -> + [H | Rest] = lists:reverse(FunStr), + case H of + $. -> + FunStr; + H -> + lists:reverse([$., H | Rest]) + end. %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Support for sequential trace @@ -457,66 +587,109 @@ no_store_write_trace_info(Key,What) -> %%% Stop tracing on all nodes stop() -> stop([]). -stop(Opts) -> +stop(Opts) when is_list(Opts) -> Fetch = stop_opts(Opts), - case whereis(?MODULE) of - undefined -> ok; - Pid when is_pid(Pid) -> - ?MODULE ! {stop,Fetch,self()}, - receive {?MODULE,stopped} -> ok end + Result = + case whereis(?MODULE) of + undefined -> ok; + Pid when is_pid(Pid) -> + ?MODULE ! {stop,Fetch,self()}, + receive {?MODULE,R} -> R end + end, + case {Fetch, Result} of + {nofetch, _} -> + ok; + {_, {stopped, _}} -> + %% Printout moved out of the ttb loop to avoid occasional deadlock + io:format("Stored logs in ~s~n", [element(2, Result)]); + {_, _} -> + ok end, - stopped. + stop_return(Result,Opts); +stop(Opts) -> + stop([Opts]). stop_opts(Opts) -> - case lists:member(format,Opts) of - true -> - format; % format implies fetch - false -> - case lists:member(fetch,Opts) of - true -> fetch; - false -> nofetch - end + FetchDir = proplists:get_value(fetch_dir, Opts), + ensure_fetch_dir(FetchDir), + FormatData = case proplists:get_value(format, Opts) of + undefined -> false; + true -> {format, []}; + FOpts -> {format, FOpts} + end, + case {FormatData, lists:member(return_fetch_dir, Opts)} of + {false, true} -> + {fetch, FetchDir}; % if we specify return_fetch_dir, the data should be fetched + {false, false} -> + case lists:member(nofetch,Opts) of + false -> {fetch, FetchDir}; + true -> nofetch + end; + {FormatData, _} -> + {FormatData, FetchDir} + end. + +ensure_fetch_dir(undefined) -> ok; +ensure_fetch_dir(Dir) -> + case filelib:is_file(Dir) of + true -> + throw({error, exists, Dir}); + false -> + ok + end. + +stop_return(R,Opts) -> + case {lists:member(return_fetch_dir,Opts),R} of + {true,_} -> + R; + {false,{stopped,_}} -> + stopped; + {false,_} -> + %% Anything other than 'stopped' would not be bw compatible... + stopped end. %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Process implementation -start() -> +start(SessionInfo) -> case whereis(?MODULE) of undefined -> Parent = self(), - Pid = spawn(fun() -> init(Parent) end), - receive {started,Pid} -> ok end; + Pid = spawn(fun() -> init(Parent, SessionInfo) end), + receive {started,Pid} -> ok end, + Pid; Pid when is_pid(Pid) -> - ok + Pid end. - -init(Parent) -> +init(Parent, SessionInfo) -> register(?MODULE,self()), ets:new(?history_table,[ordered_set,named_table,public]), Parent ! {started,self()}, - loop(dict:new()). + NewSessionInfo = [{partials, 0}, {dead_nodes, []} | SessionInfo], + try_send_flush_tick(NewSessionInfo), + loop(dict:new(), NewSessionInfo). -loop(NodeInfo) -> +loop(NodeInfo, SessionInfo) -> receive {init_node,Node,MetaFile,PI,Traci} -> erlang:monitor_node(Node,true), - MetaPid = + {AbsoluteMetaFile, MetaPid} = case rpc:call(Node, observer_backend, ttb_init_node, [MetaFile,PI,Traci]) of - {ok,MP} -> - MP; + {ok,MF,MP} -> + {MF,MP}; {badrpc,nodedown} -> %% We will get a nodedown message - undefined + {MetaFile,undefined} end, - loop(dict:store(Node,{MetaFile,MetaPid},NodeInfo)); + loop(dict:store(Node,{AbsoluteMetaFile,MetaPid},NodeInfo), SessionInfo); {get_nodes,Sender} -> Sender ! {?MODULE,dict:fetch_keys(NodeInfo)}, - loop(NodeInfo); + loop(NodeInfo, SessionInfo); {write_trace_info,Key,What} -> dict:fold(fun(Node,{_MetaFile,MetaPid},_) -> rpc:call(Node,observer_backend, @@ -524,55 +697,121 @@ loop(NodeInfo) -> end, ok, NodeInfo), - loop(NodeInfo); + loop(NodeInfo, SessionInfo); {nodedown,Node} -> - loop(dict:erase(Node,NodeInfo)); - {stop,nofetch,Sender} -> - dict:fold( - fun(Node,{_,MetaPid},_) -> - rpc:call(Node,observer_backend,ttb_stop,[MetaPid]) - end, - ok, - NodeInfo), - dbg:stop_clear(), - ets:delete(?history_table), - Sender ! {?MODULE,stopped}; - {stop,FetchOrFormat,Sender} -> - Localhost = host(node()), - Dir = ?upload_dir++ts(), - file:make_dir(Dir), - %% The nodes are traversed twice here because - %% the meta tracing in observer_backend must be - %% stopped before dbg is stopped, and dbg must - %% be stopped before the trace logs are moved orelse - %% windows complains. - AllNodesAndMeta = - dict:fold( - fun(Node,{MetaFile,MetaPid},Nodes) -> - rpc:call(Node,observer_backend,ttb_stop,[MetaPid]), - [{Node,MetaFile}|Nodes] - end, - [], - NodeInfo), - dbg:stop_clear(), - AllNodes = - lists:map( - fun({Node,MetaFile}) -> - spawn(fun() -> fetch(Localhost,Dir,Node,MetaFile) end), - Node - end, - AllNodesAndMeta), - ets:delete(?history_table), - wait_for_fetch(AllNodes), - io:format("Stored logs in ~s~n",[filename:absname(Dir)]), - case FetchOrFormat of - format -> format(Dir); - fetch -> ok + NewState = make_node_dead(Node, NodeInfo, SessionInfo), + loop(dict:erase(Node,NodeInfo), NewState); + {noderesumed,Node,Reporter} -> + {MetaFile, CurrentSuffix, NewState} = make_node_alive(Node, SessionInfo), + fetch_partial_result(Node, MetaFile, CurrentSuffix), + spawn(fun() -> resume_trace(Reporter) end), + loop(NodeInfo, NewState); + {timeout, StopOpts} -> + spawn(?MODULE, stop, [StopOpts]), + loop(NodeInfo, SessionInfo); + {node_overloaded, Node} -> + io:format("Overload check activated on node: ~p.~n", [Node]), + {Overloaded, SI} = {proplists:get_value(overloaded, SessionInfo, []), + lists:keydelete(overloaded, 1, SessionInfo)}, + loop(NodeInfo, [{overloaded, [Node|Overloaded]} | SI]); + {get_overloaded, Pid} -> + Pid ! proplists:get_value(overloaded, SessionInfo, []), + loop(NodeInfo, SessionInfo); + trace_started -> + case proplists:get_value(timer, SessionInfo) of + undefined -> ok; + {MSec, StopOpts} -> erlang:send_after(MSec, self(), {timeout, StopOpts}) end, - Sender ! {?MODULE,stopped} - ?get_status + loop(NodeInfo, SessionInfo); + flush_timeout -> + [ dbg:flush_trace_port(Node) || Node <- dict:fetch_keys(NodeInfo) ], + try_send_flush_tick(SessionInfo), + loop(NodeInfo, SessionInfo); + {stop,nofetch,Sender} -> + do_stop(nofetch, Sender, NodeInfo, SessionInfo); + {stop,FetchSpec,Sender} -> + case proplists:get_value(shell, SessionInfo, false) of + only -> do_stop(nofetch, Sender, NodeInfo, SessionInfo); + _ -> do_stop(FetchSpec, Sender, NodeInfo, SessionInfo) + end + end. + +do_stop(nofetch, Sender, NodeInfo, _) -> + write_config(?last_config, all), + dict:fold( + fun(Node,{_,MetaPid},_) -> + rpc:call(Node,observer_backend,ttb_stop,[MetaPid]) + end, + ok, + NodeInfo), + dbg:stop_clear(), + ets:delete(?history_table), + Sender ! {?MODULE, stopped}; + +do_stop({FetchOrFormat, UserDir}, Sender, NodeInfo, SessionInfo) -> + write_config(?last_config, all), + Localhost = host(node()), + Dir = get_fetch_dir(UserDir, proplists:get_value(logfile, SessionInfo)), + file:make_dir(Dir), + %% The nodes are traversed twice here because + %% the meta tracing in observer_backend must be + %% stopped before dbg is stopped, and dbg must + %% be stopped before the trace logs are moved orelse + %% windows complains. + AllNodesAndMeta = + dict:fold( + fun(Node,{MetaFile,MetaPid},Nodes) -> + rpc:call(Node,observer_backend,ttb_stop,[MetaPid]), + [{Node,MetaFile}|Nodes] + end, + [], + NodeInfo), + dbg:stop_clear(), + AllNodes = + lists:map( + fun({Node,MetaFile}) -> + spawn(fun() -> fetch_report(Localhost,Dir,Node,MetaFile) end), + Node + end, + AllNodesAndMeta), + ets:delete(?history_table), + wait_for_fetch(AllNodes), + copy_partials(Dir, proplists:get_value(partials, SessionInfo)), + Absname = filename:absname(Dir), + case FetchOrFormat of + fetch -> ok; + {format, Opts} -> format(Dir, Opts) + end, + Sender ! {?MODULE,{stopped,Absname}}. + +make_node_dead(Node, NodeInfo, SessionInfo) -> + {MetaFile,_} = dict:fetch(Node, NodeInfo), + NewDeadNodes = [{Node, MetaFile} | proplists:get_value(dead_nodes, SessionInfo)], + [{dead_nodes, NewDeadNodes} | lists:keydelete(dead_nodes, 1, SessionInfo)]. + +make_node_alive(Node, SessionInfo) -> + DeadNodes = proplists:get_value(dead_nodes, SessionInfo), + Partials = proplists:get_value(partials, SessionInfo), + {value, {_, MetaFile}, Dn2} = lists:keytake(Node, 1, DeadNodes), + SessionInfo2 = lists:keyreplace(dead_nodes, 1, SessionInfo, {dead_nodes, Dn2}), + {MetaFile, Partials + 1, lists:keyreplace(partials, 1, SessionInfo2, {partials, Partials + 1})}. + +try_send_flush_tick(State) -> + case proplists:get_value(flush, State) of + undefined -> + ok; + MSec -> + erlang:send_after(MSec, self(), flush_timeout) end. +get_fetch_dir(undefined,undefined) -> ?upload_dir(?MODULE_STRING) ++ ts(); +get_fetch_dir(undefined,Logname) -> ?upload_dir(Logname) ++ ts(); +get_fetch_dir(Dir,_) -> Dir. + +resume_trace(Reporter) -> + ?MODULE:run_history(all_silent), + Reporter ! trace_resumed. + get_nodes() -> ?MODULE ! {get_nodes,self()}, receive {?MODULE,Nodes} -> Nodes end. @@ -582,19 +821,40 @@ ts() -> io_lib:format("-~4.4.0w~2.2.0w~2.2.0w-~2.2.0w~2.2.0w~2.2.0w", [Y,M,D,H,Min,S]). +copy_partials(_, 0) -> + ok; +copy_partials(Dir, Num) -> + PartialDir = ?partial_dir ++ integer_to_list(Num), + file:rename(PartialDir, filename:join(Dir,PartialDir)), + copy_partials(Dir, Num - 1). + +fetch_partial_result(Node,MetaFile,Current) -> + DirName = ?partial_dir ++ integer_to_list(Current), + case file:list_dir(DirName) of + {error, enoent} -> + ok; + {ok, Files} -> + [ file:delete(filename:join(DirName, File)) || File <- Files ], + file:del_dir(DirName) + end, + file:make_dir(DirName), + fetch(host(node()), DirName, Node, MetaFile). +fetch_report(Localhost, Dir, Node, MetaFile) -> + fetch(Localhost,Dir,Node,MetaFile), + ?MODULE ! {fetch_complete,Node}. fetch(Localhost,Dir,Node,MetaFile) -> - case host(Node) of - Localhost -> % same host, just move the files - Files = rpc:call(Node,observer_backend,ttb_get_filenames,[MetaFile]), + case (host(Node) == Localhost) orelse is_local(MetaFile) of + true -> % same host, just move the files + Files = get_filenames(Node,MetaFile), lists:foreach( - fun(File0) -> - File = filename:join(Dir,filename:basename(File0)), - file:rename(File0,File) - end, - Files); - _Otherhost -> + fun(File0) -> + Dest = filename:join(Dir,filename:basename(File0)), + file:rename(File0, Dest) + end, + Files); + false -> {ok, LSock} = gen_tcp:listen(0, [binary,{packet,2},{active,false}]), {ok,Port} = inet:port(LSock), rpc:cast(Node,observer_backend,ttb_fetch, @@ -603,8 +863,17 @@ fetch(Localhost,Dir,Node,MetaFile) -> receive_files(Dir,Sock,undefined), ok = gen_tcp:close(LSock), ok = gen_tcp:close(Sock) - end, - ?MODULE ! {fetch_complete,Node}. + end. + +is_local({local, _, _}) -> + true; +is_local(_) -> + false. + +get_filenames(_N, {local,F,_}) -> + observer_backend:ttb_get_filenames(F); +get_filenames(N, F) -> + rpc:call(N, observer_backend,ttb_get_filenames,[F]). receive_files(Dir,Sock,Fd) -> case gen_tcp:recv(Sock, 0) of @@ -646,9 +915,16 @@ wait_for_fetch(Nodes) -> %%% - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - write_info(Nodes,PI,Traci) -> - lists:foreach(fun({N,{local,C,_},F}) -> - MetaFile = F ++ ".ti", - file:delete(MetaFile), + {ok, Cwd} = file:get_cwd(), + lists:foreach(fun({N,{local,C,_},F}) -> + MetaFile = case F of + none -> + none; + F -> + AbsFile = filename:join(Cwd, F) ++ ".ti", + file:delete(AbsFile), + AbsFile + end, Traci1 = [{node,N},{file,C}|Traci], {ok,Port} = dbg:get_tracer(N), ?MODULE ! @@ -662,38 +938,35 @@ write_info(Nodes,PI,Traci) -> %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Format binary trace logs +get_et_handler() -> + {fun ttb_et:handler/4, initial}. + format(Files) -> format(Files,[]). format(Files,Opt) -> - {Out,Handler} = format_opt(Opt), + {Out,Handler,DisableSort} = format_opt(Opt), ets:new(?MODULE,[named_table]), - format(Files,Out,Handler). -format(File,Out,Handler) when is_list(File), is_integer(hd(File)) -> + format(Files,Out,Handler, DisableSort). +format(File,Out,Handler,DisableSort) when is_list(File), is_integer(hd(File)) -> Files = case filelib:is_dir(File) of true -> % will merge all files in the directory - MetaFiles = filelib:wildcard(filename:join(File,"*.ti")), - lists:map(fun(M) -> - Sub = string:left(M,length(M)-3), - case filelib:is_file(Sub) of - true -> Sub; - false -> Sub++".*.wrp" - end - end, - MetaFiles); + List = filelib:wildcard(filename:join(File, ?partial_dir++"*")), + lists:append(collect_files([File | List])); false -> % format one file [File] end, - format(Files,Out,Handler); -format(Files,Out,Handler) when is_list(Files), is_list(hd(Files)) -> + format(Files,Out,Handler,DisableSort); +format(Files,Out,Handler,DisableSort) when is_list(Files), is_list(hd(Files)) -> StopDbg = case whereis(dbg) of undefined -> true; _ -> false end, - Details = lists:foldl(fun(File,Acc) -> [prepare(File,Handler)|Acc] end, + Details = lists:foldl(fun(File,Acc) -> [prepare(File)|Acc] end, [],Files), Fd = get_fd(Out), - R = do_format(Fd,Details), + RealHandler = get_handler(Handler, Files), + R = do_format(Fd,Details,DisableSort,RealHandler), file:close(Fd), ets:delete(?MODULE), case StopDbg of @@ -702,7 +975,30 @@ format(Files,Out,Handler) when is_list(Files), is_list(hd(Files)) -> end, R. -prepare(File,Handler) -> +collect_files(Dirs) -> + lists:map(fun(Dir) -> + MetaFiles = filelib:wildcard(filename:join(Dir,"*.ti")), + lists:map(fun(M) -> + Sub = string:left(M,length(M)-3), + case filelib:is_file(Sub) of + true -> Sub; + false -> Sub++".*.wrp" + end + end, + MetaFiles) + end, Dirs). + +get_handler(undefined, Files) -> + %%We retrieve traci from the first available file + {Traci, _} = read_traci(hd(Files)), + case dict:find(handler, Traci) of + error -> {fun defaulthandler/4, initial}; + {ok, [Handler]} -> Handler + end; +get_handler(Handler, _) -> + Handler. + +prepare(File) -> {Traci,Proci} = read_traci(File), Node = get_node(Traci), lists:foreach(fun({Pid,PI}) -> @@ -714,19 +1010,21 @@ prepare(File,Handler) -> ets:insert(?MODULE,{Pid,PI,Node}) end,Proci), FileOrWrap = get_file(File,Traci), - Handler1 = get_handler(Handler,Traci), - {FileOrWrap,Traci,Handler1}. + {FileOrWrap,Traci}. -format_opt(Opt) -> +format_opt(Opt) when is_list(Opt) -> Out = case lists:keysearch(out,1,Opt) of {value,{out,O}} -> O; _ -> standard_io end, Handler = case lists:keysearch(handler,1,Opt) of - {value,{handler,H}} -> H; - _ -> undefined + {value,{handler,H}} -> H; + _ -> undefined end, - {Out,Handler}. + DisableSort = proplists:get_value(disable_sort, Opt, false), + {Out,Handler,DisableSort}; +format_opt(Opt) -> + format_opt([Opt]). read_traci(File) -> @@ -800,75 +1098,61 @@ check_client(Client,File) when is_tuple(Client),element(2,Client)==wrap -> check_exists(File) -> case file:read_file_info(File) of {ok,#file_info{type=regular}} -> File; - _ -> + _ -> exit({error,no_file}) end. - -get_handler(Handler,Traci) -> - case Handler of - undefined -> - case dict:find(handler,Traci) of - {ok,[H]} -> H; - error -> undefined - end; - _ -> - Handler - end. -do_format(Fd,Details) -> - Clients = lists:foldl(fun({FileOrWrap,Traci,Handler},Acc) -> - [start_client(FileOrWrap,Traci,Handler) - |Acc] +do_format(Fd,Details,DisableSort,Handler) -> + Clients = lists:foldl(fun({FileOrWrap,Traci},Acc) -> + [start_client(FileOrWrap,Traci)|Acc] end,[],Details), - init_collector(Fd,Clients). - - -start_client(FileOrWrap,Traci,et) -> - dbg:trace_client(file, FileOrWrap, - {fun handler/2, - {dict:to_list(Traci),{{ttb_et,handler},initial}}}); -start_client(FileOrWrap,Traci,undefined) -> - dbg:trace_client(file, FileOrWrap, - {fun handler/2, - {dict:to_list(Traci),{fun defaulthandler/4,initial}}}); -start_client(FileOrWrap,Traci,Handler) -> - dbg:trace_client(file, FileOrWrap, - {fun handler/2, {dict:to_list(Traci),Handler}}). - -handler(Trace,State) -> - %% State here is only used for the initial state. The accumulated - %% State is maintained by collector!!! - receive - {get,Collector} -> Collector ! {self(),{Trace,State}}; + init_collector(Fd,Clients,DisableSort,Handler). + +start_client(FileOrWrap,Traci) -> + dbg:trace_client(file, FileOrWrap, + {fun handler/2, dict:to_list(Traci)}). + +handler(Trace,Traci) -> + %%We return our own Traci so that it not necesarry to look it up + %%This may take time if something huge has been written to it + receive + {get,Collector} -> Collector ! {self(),{Trace,Traci}}; done -> ok end, - State. + Traci. -handler1(Trace,{Fd,{Traci,{Fun,State}}}) when is_function(Fun) -> - {Traci,{Fun,Fun(Fd,Trace,Traci,State)}}; -handler1(Trace,{Fd,{Traci,{{M,F},State}}}) when is_atom(M), is_atom(F) -> - {Traci,{{M,F},M:F(Fd,Trace,Traci,State)}}. +%%Used to handle common state (the same for all clients) +handler2(Trace,{Fd,Traci,{Fun,State}}) when is_function(Fun) -> + {Fun, Fun(Fd, Trace, Traci, State)}; +handler2(Trace,{Fd,Traci,{{M,F},State}}) when is_atom(M), is_atom(F) -> + {{M,F}, M:F(Fd, Trace, Traci, State)}. defaulthandler(Fd,Trace,_Traci,initial) -> dbg:dhandler(Trace,Fd); defaulthandler(_Fd,Trace,_Traci,State) -> dbg:dhandler(Trace,State). -init_collector(Fd,Clients) -> +init_collector(Fd,Clients,DisableSort,Handler) -> Collected = get_first(Clients), - collector(Fd,sort(Collected)). + case DisableSort of + true -> collector(Fd,Collected, DisableSort, Handler); + false -> collector(Fd,sort(Collected), DisableSort, Handler) + end. -collector(Fd,[{_,{Client,{Trace,State}}}|Rest]) -> +collector(Fd,[{_,{Client,{Trace,Traci}}} |Rest], DisableSort, CommonState) -> Trace1 = update_procinfo(Trace), - State1 = handler1(Trace1,{Fd,State}), - case get_next(Client,State1) of - end_of_trace -> - handler1(end_of_trace,{Fd,State1}), - collector(Fd,Rest); - Next -> collector(Fd,sort([Next|Rest])) + CommonState2 = handler2(Trace1, {Fd, Traci, CommonState}), + case get_next(Client) of + end_of_trace -> + collector(Fd,Rest,DisableSort, CommonState2); + Next -> case DisableSort of + false -> collector(Fd,sort([Next|Rest]), DisableSort, CommonState2); + true -> collector(Fd,[Next|Rest], DisableSort, CommonState2) + end end; -collector(_Fd,[]) -> +collector(Fd,[], _, CommonState) -> + handler2(end_of_trace, {Fd, end_of_trace, CommonState}), ok. update_procinfo({drop,_N}=Trace) -> @@ -895,7 +1179,7 @@ update_procinfo(Trace) -> ProcInfo = get_procinfo(Pid), setelement(2,Trace,ProcInfo). -get_procinfo(Pid) when is_pid(Pid) -> +get_procinfo(Pid) when is_pid(Pid); is_port(Pid) -> case ets:lookup(?MODULE,Pid) of [PI] -> PI; [] -> Pid @@ -913,21 +1197,21 @@ get_procinfo({Name,Node}) when is_atom(Name) -> get_first([Client|Clients]) -> Client ! {get,self()}, - receive - {Client,{end_of_trace,_}} -> + receive + {Client,{end_of_trace,_}} -> get_first(Clients); - {Client,{Trace,_State}}=Next -> + {Client,{Trace,_}}=Next -> [{timestamp(Trace),Next}|get_first(Clients)] end; get_first([]) -> []. -get_next(Client,State) when is_pid(Client) -> +get_next(Client) when is_pid(Client) -> Client ! {get,self()}, - receive - {Client,{end_of_trace,_}} -> + receive + {Client,{end_of_trace,_}} -> end_of_trace; - {Client,{Trace,_OldState}} -> - {timestamp(Trace),{Client,{Trace,State}}} % inserting new state!! + {Client,{Trace, Traci}} -> + {timestamp(Trace),{Client,{Trace,Traci}}} end. sort(List) -> @@ -971,19 +1255,34 @@ display_warning(Item,Warning) -> %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% Trace client which reads an IP port and puts data directly to a file. %%% This is used when tracing remote nodes with no file system. -ip_to_file(Trace,{file,File}) -> +ip_to_file({metadata,_,_},{_, only} = State) -> + State; +ip_to_file(Trace, {_, only} = State) -> + dbg:dhandler(Trace, standard_io), + State; +ip_to_file(Trace,{{file,File}, ShellOutput}) -> Fun = dbg:trace_port(file,File), %File can be a filename or a wrap spec Port = Fun(), - ip_to_file(Trace,Port); -ip_to_file({metadata,MetaFile,MetaData},Port) -> + case Trace of + {metadata, _, _} -> ok; + Trace -> show_trace(Trace, ShellOutput) + end, + ip_to_file(Trace,{Port,ShellOutput}); +ip_to_file({metadata,MetaFile,MetaData},State) -> {ok,MetaFd} = file:open(MetaFile,[write,raw,append]), file:write(MetaFd,MetaData), file:close(MetaFd), - Port; -ip_to_file(Trace,Port) -> + State; +ip_to_file(Trace,{Port, ShellOutput}) -> + show_trace(Trace, ShellOutput), B = term_to_binary(Trace), erlang:port_command(Port,B), - Port. + {Port, ShellOutput}. + +show_trace(Trace, true) -> + dbg:dhandler(Trace, standard_io); +show_trace(_, _) -> + ok. %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %%% For debugging @@ -996,5 +1295,3 @@ dump_ti(<<>>,Acc) -> dump_ti(B,Acc) -> {Term,Rest} = get_term(B), dump_ti(Rest,[Term|Acc]). - - diff --git a/lib/observer/test/Makefile b/lib/observer/test/Makefile index 6073e6ea00..bf99f07081 100644 --- a/lib/observer/test/Makefile +++ b/lib/observer/test/Makefile @@ -22,7 +22,10 @@ MODULES = \ observer_SUITE \ crashdump_viewer_SUITE \ etop_SUITE \ + ttb_helper \ ttb_SUITE \ + client \ + server \ crashdump_helper ERL_FILES= $(MODULES:%=%.erl) diff --git a/lib/observer/test/client.erl b/lib/observer/test/client.erl new file mode 100644 index 0000000000..e756f9d6e8 --- /dev/null +++ b/lib/observer/test/client.erl @@ -0,0 +1,28 @@ +-module(client). +-compile(export_all). + +init(Node) -> + application:start(runtime_tools), + net_kernel:connect_node(Node). + +init() -> + init(server_node()). + +restart() -> + init:restart(). + +server_node() -> + {ok,HostName} = inet:gethostname(), + list_to_atom("server@" ++ HostName). + +get() -> + erlang:send({server,server_node()}, {get,self()}), + receive Data -> Data + after 1000 -> no_reply + end. + +put(Thing) -> + erlang:send({server,server_node()}, {put,self(),Thing}), + receive ok -> ok + after 1000 -> no_reply + end. diff --git a/lib/observer/test/server.erl b/lib/observer/test/server.erl new file mode 100644 index 0000000000..c1b1fea562 --- /dev/null +++ b/lib/observer/test/server.erl @@ -0,0 +1,43 @@ +-module(server). +-compile(export_all). + +start() -> + application:start(runtime_tools), + Pid = spawn(?MODULE,loop,[[], 0]), + register(server,Pid). + +stop() -> + case lists:member(server, registered()) of + true -> + server ! stop; + false -> + ok + end. + +loop(Data, Num) -> + receive + {put,From,Ting} -> From ! ok, + received(From,Ting), + loop([Ting|Data], Num+1); + {get,From} -> From ! Data, + loop(Data, Num+1); + stop -> stopped; + clear -> loop([], Num+1); + {cnt, From} -> From ! Num, + loop(Data, Num) + end. + +counter() -> + server ! {cnt, self()}, + receive + Num -> + Num + end. + +received(From, Thing) -> + case Thing of + never_send_this_atom -> + loop(Thing, 0); + _ -> + {return, 27, Thing, From} + end. diff --git a/lib/observer/test/ttb_SUITE.erl b/lib/observer/test/ttb_SUITE.erl index 24b4a22aa9..1fd8b4c892 100644 --- a/lib/observer/test/ttb_SUITE.erl +++ b/lib/observer/test/ttb_SUITE.erl @@ -1,7 +1,7 @@ -%% %% %CopyrightBegin% %% -%% Copyright Ericsson AB 2002-2011. All Rights Reserved. +%% +%% Copyright Ericsson AB 2002-2010. All Rights Reserved. %% %% The contents of this file are subject to the Erlang Public License, %% Version 1.1, (the "License"); you may not use this file except in @@ -33,9 +33,17 @@ -include_lib("test_server/include/test_server.hrl"). -define(default_timeout, ?t:minutes(1)). +-define(OUTPUT, "handler_output"). +-define(FNAME, "temptest"). +-define(DIRNAME, "ddtemp"). init_per_testcase(_Case, Config) -> ttb:stop(), + os:cmd("rm -rf " ++ ?OUTPUT), + os:cmd("rm -rf ttb_upload*"), + os:cmd("rm -rf " ++ ?DIRNAME), + os:cmd("rm -rf *@*"), + os:cmd("rm -rf ttb_last_config"), ?line Dog=test_server:timetrap(?default_timeout), [{watchdog, Dog}|Config]. end_per_testcase(_Case, Config) -> @@ -49,7 +57,25 @@ all() -> [file, file_no_pi, file_fetch, wrap, wrap_merge, wrap_merge_fetch_format, write_config1, write_config2, write_config3, history, write_trace_info, seq_trace, - diskless, otp_4967_1, otp_4967_2]. + diskless, diskless_wrap, otp_4967_1, otp_4967_2, + fetch_when_no_option_given, basic_ttb_run_ip_port, basic_ttb_run_file_port, + return_fetch_dir_implies_fetch, logfile_name_in_fetch_dir, upload_to_my_logdir, + upload_to_my_existing_logdir, fetch_with_options_not_as_list, + error_when_formatting_multiple_files_4393, format_on_trace_stop, + trace_to_remote_files_on_localhost_with_different_pwd, + trace_to_local_files_on_localhost_with_different_pwd, + trace_to_remote_files_on_localhost_with_different_pwd_abs, + changing_cwd_on_control_node, changing_cwd_on_remote_node, + changing_cwd_on_control_node_with_local_trace, + one_command_trace_setup, dbg_style_fetch, shell_tracing_init, + only_one_state_for_format_handler, only_one_state_with_default_format_handler, + only_one_state_with_initial_format_handler, run_trace_with_shortcut1, + run_trace_with_shortcut2, run_trace_with_shortcut3, run_trace_with_shortcut4, + cant_specify_local_and_flush, trace_sorted_by_default,disable_sorting, + trace_resumed_after_node_restart, trace_resumed_after_node_restart_ip, + trace_resumed_after_node_restart_wrap, + trace_resumed_after_node_restart_wrap_mult +]. groups() -> []. @@ -92,15 +118,15 @@ file(Config) when is_list(Config) -> ?line {ok,[{matched,_,1},{matched,_,1}]} = ttb:tp(?MODULE,foo,[]), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format(filename:join(Privdir,atom_to_list(Node)++"-file")), ?line ok = ttb:format(filename:join(Privdir, atom_to_list(OtherNode)++"-file")), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ok. @@ -123,15 +149,15 @@ file_no_pi(Config) when is_list(Config) -> ?line {ok,[{matched,_,1},{matched,_,1}]} = ttb:tp(?MODULE,foo,[]), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format(filename:join(Privdir,atom_to_list(Node)++"-file")), ?line ok = ttb:format(filename:join(Privdir, atom_to_list(OtherNode)++"-file")), - ?line [{trace,LocalProc,call,{?MODULE,foo,[]}}, + ?line [{trace_ts,LocalProc,call,{?MODULE,foo,[]}, {_,_,_}}, end_of_trace, - {trace,RemoteProc,call,{?MODULE,foo,[]}}, + {trace_ts,RemoteProc,call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ?line true = is_pid(LocalProc), ?line true = is_pid(RemoteProc), @@ -170,7 +196,7 @@ file_fetch(Config) when is_list(Config) -> ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), ?line ?t:capture_start(), - ?line ttb:stop([fetch]), + ?line ttb:stop([return_fetch_dir]), ?line ?t:capture_stop(), ?line [StoreString] = ?t:capture_get(), ?line UploadDir = @@ -194,9 +220,9 @@ file_fetch(Config) when is_list(Config) -> ?line ok = ttb:format(filename:join(UploadDir, atom_to_list(OtherNode)++"-file_fetch")), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ?line ok = file:set_cwd(Cwd), @@ -224,19 +250,19 @@ wrap(Config) when is_list(Config) -> ?line rpc:call(OtherNode,?MODULE,foo,[]), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format(filename:join(Privdir, atom_to_list(Node)++"-wrap.*.wrp")), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, - {trace,{S,_,Node},call,{?MODULE,foo,[]}}, - {trace,{S,_,Node},call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ?line ok = ttb:format(filename:join(Privdir, atom_to_list(OtherNode)++"-wrap.*.wrp")), - ?line [{trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), %% Check that merge does not crash even if the timestamp flag is not on. @@ -244,14 +270,13 @@ wrap(Config) when is_list(Config) -> [filename:join(Privdir, atom_to_list(Node)++"-wrap.*.wrp"), filename:join(Privdir, - atom_to_list(OtherNode)++"-wrap.*.wrp")]), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, - {trace,{S,_,Node},call,{?MODULE,foo,[]}}, - {trace,{S,_,Node},call,{?MODULE,foo,[]}}, - end_of_trace, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, - {trace,{_,_,OtherNode},call,{?MODULE,foo,[]}}, + atom_to_list(OtherNode)++"-wrap.*.wrp")],[{disable_sort,true}]), + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ok. @@ -277,7 +302,7 @@ wrap_merge(Config) when is_list(Config) -> ?line rpc:call(OtherNode,?MODULE,foo,[]), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format( [filename:join(Privdir, @@ -289,7 +314,6 @@ wrap_merge(Config) when is_list(Config) -> {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},_}, {trace_ts,_,call,{?MODULE,foo,[]},_}, {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},_}, - end_of_trace, {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},_}, end_of_trace] = flush(), ok. @@ -330,7 +354,6 @@ wrap_merge_fetch_format(Config) when is_list(Config) -> {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},_}, {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},_}, {trace_ts,{S,_,Node},call,{?MODULE,foo,[]},_}, - end_of_trace, {trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},_}, end_of_trace] = flush(), @@ -360,16 +383,15 @@ write_config1(Config) when is_list(Config) -> ?line ok = ttb:run_config(File), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format( [filename:join(Privdir, atom_to_list(Node)++"-write_config1"), filename:join(Privdir, atom_to_list(OtherNode)++"-write_config1")]), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, - end_of_trace, - {trace,Other,call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,Other,call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), case metatest(Other,OtherNode,Privdir,"-write_config1.ti") of @@ -410,16 +432,15 @@ write_config2(Config) when is_list(Config) -> ?line ok = ttb:run_config(File), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format( [filename:join(Privdir, atom_to_list(Node)++"-write_config2"), filename:join(Privdir, atom_to_list(OtherNode)++"-write_config2")]), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, - end_of_trace, - {trace,Other,call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,Other,call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), case metatest(Other,OtherNode,Privdir,"-write_config2.ti") of @@ -455,18 +476,18 @@ write_config3(Config) when is_list(Config) -> ?line {ok,[{all,[{matched,_,_},{matched,_,_}]}]} = ttb:p(all,call), ?line {ok,[{matched,_,1},{matched,_,1}]} = ttb:tp(?MODULE,foo,[]), ?line ok = ttb:write_config(File,[1,2]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line [_,_] = ttb:list_config(File), ?line ok = ttb:run_config(File), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ok = ttb:format( [filename:join(Privdir, atom_to_list(Node)++"-write_config3"), filename:join(Privdir, atom_to_list(OtherNode)++"-write_config3")]), - ?line [] = flush(), %foo is not traced + ?line [end_of_trace] = flush(), %foo is not traced ?line ok = ttb:write_config(File,[{ttb,tp,[?MODULE,foo,[]]}], [append]), @@ -474,16 +495,15 @@ write_config3(Config) when is_list(Config) -> ?line ok = ttb:run_config(File), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format( [filename:join(Privdir, atom_to_list(Node)++"-write_config3"), filename:join(Privdir, atom_to_list(OtherNode)++"-write_config3")]), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, - end_of_trace, - {trace,Other,call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, + {trace_ts,Other,call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), case metatest(Other,OtherNode,Privdir,"-write_config3.ti") of @@ -531,12 +551,12 @@ history(Config) when is_list(Config) -> ?line ?MODULE:foo(), ?line ok = ttb:run_history([3,4]), ?line ?MODULE:foo(), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format( [filename:join(Privdir,atom_to_list(Node)++"-history"), filename:join(Privdir,atom_to_list(OtherNode)++"-history")]), - ?line [{trace,{S,_,Node},call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ok. @@ -561,17 +581,16 @@ write_trace_info(Config) when is_list(Config) -> ?line ok = ttb:write_trace_info(mytraceinfo,fun() -> node() end), ?line ?MODULE:foo(), ?line rpc:call(OtherNode,?MODULE,foo,[]), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(OtherNode), ?line ok = ttb:format( [filename:join(Privdir,atom_to_list(Node)++"-write_trace_info"), filename:join(Privdir, atom_to_list(OtherNode)++"-write_trace_info")], [{handler,{fun otherhandler/4,S}}]), - ?line [{{trace,{S,_,Node},call,{?MODULE,foo,[]}},[Node]}, - {end_of_trace,[Node]}, - {{trace,{_,_,OtherNode},call,{?MODULE,foo,[]}},[OtherNode]}, - {end_of_trace,[OtherNode]}] = flush(), + ?line [{{trace_ts,{S,_,Node},call,{?MODULE,foo,[]},{_,_,_}},[Node]}, + {{trace_ts,{_,_,OtherNode},call,{?MODULE,foo,[]},{_,_,_}},[OtherNode]}, + end_of_trace] = flush(), ok. @@ -593,10 +612,10 @@ seq_trace(Config) when is_list(Config) -> ?line Start = spawn(fun() -> seq() end), ?line timer:sleep(300), - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ok = ttb:format( [filename:join(Privdir,atom_to_list(Node)++"-seq_trace")]), - ?line [{trace,StartProc,call,{?MODULE,seq,[]}}, + ?line [{trace_ts,StartProc,call,{?MODULE,seq,[]},{_,_,_}}, {seq_trace,0,{send,{0,1},StartProc,P1Proc,{Start,P2}}}, {seq_trace,0,{send,{1,2},P1Proc,P2Proc,{P1,Start}}}, {seq_trace,0,{send,{2,3},P2Proc,StartProc,{P2,P1}}}, @@ -660,15 +679,41 @@ diskless(Config) when is_list(Config) -> ?line rpc:call(RemoteNode,?MODULE,foo,[]), ?line timer:sleep(500), % needed for the IP port to flush - ?line ttb:stop(), + ?line ttb:stop([nofetch]), ?line ?t:stop_node(RemoteNode), ?line ok = ttb:format(filename:join(Privdir, atom_to_list(RemoteNode)++"-diskless")), - ?line [{trace,{_,_,RemoteNode},call,{?MODULE,foo,[]}}, + ?line [{trace_ts,{_,_,RemoteNode},call,{?MODULE,foo,[]},{_,_,_}}, end_of_trace] = flush(), ok. +diskless_wrap(suite) -> + []; +diskless_wrap(doc) -> + ["Start tracing on diskless remote node, save to local wrapped file"]; +diskless_wrap(Config) when is_list(Config) -> + ?line {ok,RemoteNode} = ?t:start_node(node2,slave,[]), + ?line c:nl(?MODULE), + ?line S = self(), + ?line Privdir=?config(priv_dir, Config), + ?line File = filename:join(Privdir,"diskless"), + ?line {ok,[RemoteNode]} = + ttb:tracer([RemoteNode],[{file, {local, {wrap,File,200,3}}}, + {handler,{fun myhandler/4, S}}]), + ?line {ok,[{all,[{matched,RemoteNode,_}]}]} = ttb:p(all,call), + ?line {ok,[{matched,RemoteNode,1}]} = ttb:tp(?MODULE,foo,[]), + + ?line rpc:call(RemoteNode,?MODULE,foo,[]), + ?line timer:sleep(500), % needed for the IP port to flush + ?line ttb:stop([nofetch]), + ?line ?t:stop_node(RemoteNode), + ?line ok = ttb:format(filename:join(Privdir, + atom_to_list(RemoteNode)++"-diskless.*.wrp")), + + ?line [{trace_ts,{_,_,RemoteNode},call,{?MODULE,foo,[]},{_,_,_}}, + end_of_trace] = flush(), + ok. otp_4967_1(suite) -> []; @@ -715,7 +760,7 @@ otp_4967_2(Config) when is_list(Config) -> io:format("11: ~p",[now()]), ?line true = lists:member(heihopp,Msgs), % the heihopp message itself io:format("13: ~p",[now()]), - ?line {value,{trace,_,send,heihopp,{_,otp_4967,Node}}} = + ?line {value,{trace_ts,_,send,heihopp,{_,otp_4967,Node},{_,_,_}}} = lists:keysearch(heihopp,4,Msgs), % trace trace of the heihopp message io:format("14: ~p",[now()]), ?line end_of_trace = lists:last(Msgs), % end of the trace @@ -728,6 +773,30 @@ myhandler(_Fd,Trace,_,Relay) -> Relay ! Trace, Relay. +simple_call_handler() -> + {fun(A, {trace_ts, _, call, _, _} ,_,_) -> io:format(A, "ok.~n", []); + (_, end_of_trace, _, _) -> ok end, []}. + +marking_call_handler() -> + {fun(_, _, _, initial) -> file:write_file("HANDLER_OK", []); + (_,_,_,_) -> ok end, initial}. + +counter_call_handler() -> + {fun(_, {trace_ts, _, call, _, _} ,_,State) -> State + 1; + (A, end_of_trace, _, State) -> io:format(A,"~p.~n", [State]) end, 0}. + +ret_caller_call_handler() -> + {fun(A, {trace_ts, _, call, _, _, _} ,_,_) -> io:format(A, "ok.~n", []); + (A, {trace_ts, _, return_from, _, _, _}, _, _) -> io:format(A, "ok.~n", []); + (_, _, _, _) -> ok end, []}. + +node_call_handler() -> + {fun(A, {trace_ts, {_,_,Node}, call, _, _} ,_,_) -> io:format(A, "~p.~n", [Node]); + (_, end_of_trace, _, _) -> ok end, []}. + +otherhandler(_Fd,_,end_of_trace,Relay) -> + Relay ! end_of_trace, + Relay; otherhandler(_Fd,Trace,TI,Relay) -> {value,{mytraceinfo,I}} = lists:keysearch(mytraceinfo,1,TI), Relay ! {Trace,I}, @@ -794,3 +863,568 @@ check_gone(Dir,File) -> false -> ok end. + +start_client_and_server() -> + ?line {ok,ClientNode} = ?t:start_node(client,slave,[]), + ?line ok = ttb_helper:c(code, add_paths, [code:get_path()]), + ?line {ok,ServerNode} = ?t:start_node(server,slave,[]), + ?line ok = ttb_helper:s(code, add_paths, [code:get_path()]), + ?line ttb_helper:clear(), + {ServerNode, ClientNode}. + +begin_trace(ServerNode, ClientNode, Dest) -> + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, Dest}]), + ?line ttb:p(all, call), + ?line ttb:tp(server, received, []), + ?line ttb:tp(client, put, []), + ?line ttb:tp(client, get, []). + +begin_trace_local(ServerNode, ClientNode, Dest) -> + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, Dest}]), + ?line ttb:p(all, call), + ?line ttb:tpl(server, received, []), + ?line ttb:tpl(client, put, []), + ?line ttb:tpl(client, get, []). + +check_size(N, Dest, Output, ServerNode, ClientNode) -> + ?line begin_trace(ServerNode, ClientNode, Dest), + ?line case Dest of + {local, _} -> + ?line ttb_helper:msgs_ip(N); + _ -> + ?line ttb_helper:msgs(N) + end, + ?line {_, D} = ttb:stop([fetch, return_fetch_dir]), + ?line ttb:format(D, [{out, Output}, {handler, simple_call_handler()}]), + ?line {ok, Ret} = file:consult(Output), + ?line true = (N + 1 == length(Ret)). + +fetch_when_no_option_given(suite) -> + []; +fetch_when_no_option_given(doc) -> + ["Fetch when no option given"]; +fetch_when_no_option_given(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line {ok, Privdir} = file:get_cwd(), + ?line [] = filelib:wildcard(filename:join(Privdir,"ttb_upload_temptest*")), + begin_trace(ServerNode, ClientNode, ?FNAME), + ?line ttb_helper:msgs(4), + ?line stopped = ttb:stop(), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line [_] = filelib:wildcard(filename:join(Privdir,"ttb_upload_temptest*")). + +basic_ttb_run_ip_port(suite) -> + []; +basic_ttb_run_ip_port(doc) -> + ["Basic ttb run ip port"]; +basic_ttb_run_ip_port(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line check_size(1, {local, ?FNAME}, ?OUTPUT, ServerNode, ClientNode), + ?line check_size(2, {local, ?FNAME}, ?OUTPUT, ServerNode, ClientNode), + ?line check_size(10, {local, ?FNAME}, ?OUTPUT, ServerNode, ClientNode), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +basic_ttb_run_file_port(suite) -> + []; +basic_ttb_run_file_port(doc) -> + ["Basic ttb run file port"]; +basic_ttb_run_file_port(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line check_size(1, ?FNAME, ?OUTPUT, ServerNode, ClientNode), + ?line check_size(2, ?FNAME, ?OUTPUT, ServerNode, ClientNode), + ?line check_size(10, ?FNAME, ?OUTPUT, ServerNode, ClientNode), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +return_fetch_dir_implies_fetch(suite) -> + []; +return_fetch_dir_implies_fetch(doc) -> + ["Return_fetch_dir implies fetch"]; +return_fetch_dir_implies_fetch(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, ?FNAME), + ?line ttb_helper:msgs(2), + ?line {_,_} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +logfile_name_in_fetch_dir(suite) -> + []; +logfile_name_in_fetch_dir(doc) -> + ["Logfile name in fetch dir"]; +logfile_name_in_fetch_dir(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, {local, ?FNAME}), + ?line {_,Dir} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line P1 = lists:nth(3, string:tokens(filename:basename(Dir), "_")), + ?line P2 = hd(string:tokens(P1, "-")), + ?line _File = P2. + +upload_to_my_logdir(suite) -> + []; +upload_to_my_logdir(doc) -> + ["Upload to my logdir"]; +upload_to_my_logdir(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, ?FNAME}]), + ?line {stopped,_} = ttb:stop([return_fetch_dir, {fetch_dir, ?DIRNAME}]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line true = filelib:is_file(?DIRNAME), + ?line [] = filelib:wildcard("ttb_upload_"++?FNAME). + +upload_to_my_existing_logdir(suite) -> + []; +upload_to_my_existing_logdir(doc) -> + ["Upload to my existing logdir"]; +upload_to_my_existing_logdir(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line ok = file:make_dir(?DIRNAME), + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, ?FNAME}]), + ?line {error,_,_} = (catch ttb:stop([return_fetch_dir, {fetch_dir, ?DIRNAME}])), + ?line {stopped,_} = ttb:stop(return_fetch_dir), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +fetch_with_options_not_as_list(suite) -> + []; +fetch_with_options_not_as_list(doc) -> + ["Fetch with options not as list"]; +fetch_with_options_not_as_list(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, ?FNAME}]), + ?line {stopped, D} = ttb:stop(return_fetch_dir), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line false = filelib:is_file(?OUTPUT), + ?line ttb:format(D, {out, ?OUTPUT}), + ?line true = filelib:is_file(?OUTPUT). + +error_when_formatting_multiple_files_4393(suite) -> + []; +error_when_formatting_multiple_files_4393(doc) -> + ["Error when formatting multiple files"]; +error_when_formatting_multiple_files_4393(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, ?FNAME), + ?line ttb_helper:msgs(2), + ?line {_, Dir} = ttb:stop(return_fetch_dir), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line Files = [filename:join(Dir, atom_to_list(ttb_helper:get_node(server)) ++ "-" ++ ?FNAME), + filename:join(Dir, atom_to_list(ttb_helper:get_node(client)) ++ "-" ++ ?FNAME)], + ?line ok = ttb:format(Files). + +format_on_trace_stop(suite) -> + []; +format_on_trace_stop(doc) -> + ["Format on trace stop"]; +format_on_trace_stop(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, {local, ?FNAME}), + ?line ttb_helper:msgs_ip(2), + ?line file:delete("HANDLER_OK"), + ?line {_,_} = ttb:stop([fetch, return_fetch_dir, {format, {handler, marking_call_handler()}}]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line true = filelib:is_file("HANDLER_OK"), + ?line ok = file:delete("HANDLER_OK"). + +%% The following three tests are for the issue "fixes fetch fail when nodes on the same host +%% have different cwd" +trace_to_remote_files_on_localhost_with_different_pwd(suite) -> + []; +trace_to_remote_files_on_localhost_with_different_pwd(doc) -> + ["Trace to remote files on localhost with different pwd"]; +trace_to_remote_files_on_localhost_with_different_pwd(Config) when is_list(Config) -> + ?line {ok, OldDir} = file:get_cwd(), + ?line ok = file:set_cwd(".."), + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line check_size(2, ?FNAME, ?OUTPUT, ServerNode, ClientNode), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ok = file:set_cwd(OldDir). + +trace_to_local_files_on_localhost_with_different_pwd(suite) -> + []; +trace_to_local_files_on_localhost_with_different_pwd(doc) -> + ["Trace to local files on localhost with different pwd"]; +trace_to_local_files_on_localhost_with_different_pwd(Config) when is_list(Config) -> + ?line {ok, OldDir} = file:get_cwd(), + ?line ok = file:set_cwd(".."), + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line check_size(2, {local, ?FNAME}, ?OUTPUT, ServerNode, ClientNode), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ok = file:set_cwd(OldDir). + +trace_to_remote_files_on_localhost_with_different_pwd_abs(suite) -> + []; +trace_to_remote_files_on_localhost_with_different_pwd_abs(doc) -> + ["Trace to remote files on localhost with different pwd abs"]; +trace_to_remote_files_on_localhost_with_different_pwd_abs(Config) when is_list(Config) -> + ?line {ok, OldDir} = file:get_cwd(), + ?line ok = file:set_cwd(".."), + ?line {ok, Path} = file:get_cwd(), + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line File = filename:join(Path, ?FNAME), + ?line check_size(2, File, ?OUTPUT, ServerNode, ClientNode), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ok = file:set_cwd(OldDir). + +%% Trace is not affected by changes of cwd on control node or remote nodes during tracing +%% (three tests) +changing_cwd_on_control_node(suite) -> + []; +changing_cwd_on_control_node(doc) -> + ["Changing cwd on control node during tracing is safe"]; +changing_cwd_on_control_node(Config) when is_list(Config) -> + ?line {ok, OldDir} = file:get_cwd(), + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, ?FNAME), + ?line NumMsgs = 3, + ?line ttb_helper:msgs(NumMsgs), + ?line ok = file:set_cwd(".."), + ?line ttb_helper:msgs(NumMsgs), + ?line {_, D} = ttb:stop([fetch, return_fetch_dir]), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, simple_call_handler()}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line true = (2*(NumMsgs + 1) == length(Ret)), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ok = file:set_cwd(OldDir). + +changing_cwd_on_control_node_with_local_trace(suite) -> + []; +changing_cwd_on_control_node_with_local_trace(doc) -> + ["Changing cwd on control node during local tracing is safe"]; +changing_cwd_on_control_node_with_local_trace(Config) when is_list(Config) -> + ?line {ok, OldDir} = file:get_cwd(), + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, {local, ?FNAME}), + ?line NumMsgs = 3, + ?line ttb_helper:msgs_ip(NumMsgs), + ?line ok = file:set_cwd(".."), + ?line ttb_helper:msgs_ip(NumMsgs), + ?line {_, D} = ttb:stop([fetch, return_fetch_dir]), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, simple_call_handler()}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line true = (2*(NumMsgs + 1) == length(Ret)), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ok = file:set_cwd(OldDir). + +changing_cwd_on_remote_node(suite) -> + []; +changing_cwd_on_remote_node(doc) -> + ["Changing cwd on remote node during tracing is safe"]; +changing_cwd_on_remote_node(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace(ServerNode, ClientNode, ?FNAME), + ?line NumMsgs = 2, + ?line ttb_helper:msgs(NumMsgs), + ?line ok = rpc:call(ClientNode, file, set_cwd, [".."]), + ?line ttb_helper:msgs(NumMsgs), + ?line {_, D} = ttb:stop([fetch, return_fetch_dir]), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, simple_call_handler()}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line true = (2*(NumMsgs + 1) == length(Ret)), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +one_command_trace_setup(suite) -> + []; +one_command_trace_setup(doc) -> + ["One command trace setup"]; +one_command_trace_setup(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line ttb:start_trace([ttb_helper:get_node(client), ttb_helper:get_node(server)], + [{server, received, '_', []}, + {client, put, 1, []}, + {client, get, '_', []}], + {all, call}, + [{file, ?FNAME}]), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop(return_fetch_dir), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, simple_call_handler()}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line 5 = length(Ret). + +dbg_style_fetch(suite) -> + []; +dbg_style_fetch(doc) -> + ["Dbg style fetch"]; +dbg_style_fetch(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line DirSize = length(element(2, file:list_dir("."))), + ?line ttb:start_trace([ttb_helper:get_node(client), ttb_helper:get_node(server)], + [{server, received, '_', []}, + {client, put, 1, []}, + {client, get, '_', []}], + {all, call}, + [{shell, only}]), + ?line DirSize = length(element(2, file:list_dir("."))), + ?line ttb_helper:msgs(2), + ?line DirSize = length(element(2, file:list_dir("."))), + ?line stopped, ttb:stop(format), + %%+1 -> ttb_last_trace + ?line true = (DirSize + 1 == length(element(2, file:list_dir(".")))), + ?line {ok,[{all, [{matched,_,_}, {matched,_,_}]}]} = + ttb:start_trace([ttb_helper:get_node(client), ttb_helper:get_node(server)], + [{server, received, '_', []}, + {client, put, 1, []}, + {client, get, '_', []}], + {all, call}, + [{shell, only}]), + ?line ttb:stop(), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +shell_tracing_init(suite) -> + []; +shell_tracing_init(doc) -> + ["Shell tracing init"]; +shell_tracing_init(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line ttb:tracer([ttb_helper:get_node(client), ttb_helper:get_node(server)], shell), + ?line ttb:stop(), + ?line ttb:tracer([ttb_helper:get_node(client), ttb_helper:get_node(server)], + [{file, {local, ?FNAME}}, shell]), + ?line ttb:stop(), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line local_client_required_on_shell_tracing = try ttb:tracer([ttb_helper:get_node(client), ttb_helper:get_node(server)], + [{file, ?FNAME}, shell]) + catch + exit:local_client_required_on_shell_tracing -> + local_client_required_on_shell_tracing + end. + +only_one_state_for_format_handler(suite) -> + []; +only_one_state_for_format_handler(doc) -> + ["Only one state for format handler"]; +only_one_state_for_format_handler(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_local(ServerNode, ClientNode, ?FNAME), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, counter_call_handler()}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line [5] = Ret. + +only_one_state_with_default_format_handler(suite) -> + []; +only_one_state_with_default_format_handler(doc) -> + ["Only one state with default format handler"]; +only_one_state_with_default_format_handler(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_local(ServerNode, ClientNode, ?FNAME), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}]), + ?line true = filelib:is_file(?OUTPUT). + +only_one_state_with_initial_format_handler(suite) -> + []; +only_one_state_with_initial_format_handler(doc) -> + ["Only one state with initial format handler"]; +only_one_state_with_initial_format_handler(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, ?FNAME}, {handler, counter_call_handler()}]), + ?line ttb:p(all, call), + ?line ttb:tpl(server, received, []), + ?line ttb:tpl(client, put, []), + ?line ttb:tpl(client, get, []), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line [5] = Ret. + +run_trace_with_shortcut(Shortcut, Ret, F) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line {ok, _} = + ttb:tracer([ServerNode,ClientNode],[{file, ?FNAME}]), + ?line ttb:p(all, call), + ?line ttb:F(client, put, Shortcut), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, ret_caller_call_handler()}]), + ?line {ok, Ret} =file:consult(?OUTPUT), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +fun_for(return) -> + {codestr, "fun(_) -> return_trace() end"}; +fun_for(msg_false) -> + {codestr, "fun(_) -> message(false) end"}. + +run_trace_with_shortcut1(suite) -> + []; +run_trace_with_shortcut1(doc) -> + ["Run trace with shortcut 1"]; +run_trace_with_shortcut1(Config) when is_list(Config) -> + ?line run_trace_with_shortcut(caller, [ok,ok], tp), + ?line run_trace_with_shortcut(caller, [ok,ok], tpl). + +run_trace_with_shortcut2(suite) -> + []; +run_trace_with_shortcut2(doc) -> + ["Run trace with shortcut 2"]; +run_trace_with_shortcut2(Config) when is_list(Config) -> + ?line run_trace_with_shortcut(return, [ok,ok], tp), + ?line run_trace_with_shortcut(return, [ok,ok], tpl). + +run_trace_with_shortcut3(suite) -> + []; +run_trace_with_shortcut3(doc) -> + ["Run trace with shortcut 3"]; +run_trace_with_shortcut3(Config) when is_list(Config) -> + ?line run_trace_with_shortcut(fun_for(return), [ok,ok], tp), + ?line run_trace_with_shortcut(fun_for(return), [ok,ok], tpl). + +run_trace_with_shortcut4(suite) -> + []; +run_trace_with_shortcut4(doc) -> + ["Run trace with shortcut 4"]; +run_trace_with_shortcut4(Config) when is_list(Config) -> + ?line run_trace_with_shortcut(fun_for(msg_false), [], tp), + ?line run_trace_with_shortcut(fun_for(msg_false), [], tpl). + +cant_specify_local_and_flush(suite) -> + []; +cant_specify_local_and_flush(doc) -> + ["Can't specify local and flush"]; +cant_specify_local_and_flush(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line flush_unsupported_with_ip_trace_port = try ttb:tracer([ServerNode, ClientNode], [{flush, 1000}, {file, {local, ?FNAME}}]) + catch + exit:flush_unsupported_with_ip_trace_port -> + flush_unsupported_with_ip_trace_port + end, + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode). + +trace_sorted_by_default(suite) -> + []; +trace_sorted_by_default(doc) -> + ["Trace sorted by default"]; +trace_sorted_by_default(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_local(ServerNode, ClientNode, ?FILE), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, node_call_handler()}, {disable_sort, false}]), + {ok, Ret} = file:consult(?OUTPUT), + ?line [ClientNode,ServerNode,ClientNode,ServerNode,ServerNode] = Ret. + +disable_sorting(suite) -> + []; +disable_sorting(doc) -> + ["Disable sorting"]; +disable_sorting(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_local(ServerNode, ClientNode, ?FILE), + ?line ttb_helper:msgs(2), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ServerNode), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, node_call_handler()}, {disable_sort, true}]), + {ok, Ret} = file:consult(?OUTPUT), + ?line [ClientNode,ClientNode,ServerNode,ServerNode,ServerNode] = Ret. + +%% ----------------------------------------------------------------------------- +%% tests for autoresume of tracing +%% ----------------------------------------------------------------------------- + +trace_resumed_after_node_restart(suite) -> + []; +trace_resumed_after_node_restart(doc) -> + ["Test trace resumed after node restart, trace to files on remote node."]; +trace_resumed_after_node_restart(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_with_resume(ServerNode, ClientNode, ?FNAME), + ?line logic(2,6,file). + +trace_resumed_after_node_restart_ip(suite) -> + []; +trace_resumed_after_node_restart_ip(doc) -> + ["Test trace resumed after node restart, trace via tcp/ip to local node."]; +trace_resumed_after_node_restart_ip(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_with_resume(ServerNode, ClientNode, {local, ?FNAME}), + ?line logic(2,6,local). + +trace_resumed_after_node_restart_wrap(suite) -> + []; +trace_resumed_after_node_restart_wrap(doc) -> + ["Test trace resumed after node restart, wrap option."]; +trace_resumed_after_node_restart_wrap(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_with_resume(ServerNode, ClientNode, {wrap, ?FNAME, 10, 4}), + ?line logic(1,4,file). + +trace_resumed_after_node_restart_wrap_mult(suite) -> + []; +trace_resumed_after_node_restart_wrap_mult(doc) -> + ["Test trace resumed after node restart, wrap option, multiple files."]; +trace_resumed_after_node_restart_wrap_mult(Config) when is_list(Config) -> + ?line {ServerNode, ClientNode} = start_client_and_server(), + ?line begin_trace_with_resume(ServerNode, ClientNode, {wrap, ?FNAME, 10, 4}), + ?line logic(20,8,file). + +logic(N, M, TracingType) -> + helper_msgs(N, TracingType), + ?t:stop_node(ttb_helper:get_node(client)), + timer:sleep(2500), + ?line {ok,ClientNode} = ?t:start_node(client,slave,[]), + ?line ok = ttb_helper:c(code, add_paths, [code:get_path()]), + ?line ttb_helper:c(client, init, []), + ?line helper_msgs(N, TracingType), + ?line {_, D} = ttb:stop([return_fetch_dir]), + ?line ?t:stop_node(ttb_helper:get_node(server)), + ?line ?t:stop_node(ClientNode), + ?line ttb:format(D, [{out, ?OUTPUT}, {handler, ret_caller_call_handler2()}]), + ?line {ok, Ret} = file:consult(?OUTPUT), + ?line M = length(Ret). + +begin_trace_with_resume(ServerNode, ClientNode, Dest) -> + ?line {ok, _} = ttb:tracer([ServerNode,ClientNode], [{file, Dest}, resume]), + ?line ttb:p(all, [call, timestamp]), + ?line ttb:tp(server, received, []), + ?line ttb:tp(client, put, []), + ?line ttb:tp(client, get, []). + +ret_caller_call_handler2() -> + {fun(A, {trace_ts, _, call, _, _} ,_,_) -> io:format(A, "ok.~n", []); + (_, _, _, _) -> ok end, []}. + +helper_msgs(N, TracingType) -> + case TracingType of + local -> + ttb_helper:msgs_ip(N); + _ -> + ttb_helper:msgs(N) + end. diff --git a/lib/observer/test/ttb_helper.erl b/lib/observer/test/ttb_helper.erl new file mode 100644 index 0000000000..19fdc0e159 --- /dev/null +++ b/lib/observer/test/ttb_helper.erl @@ -0,0 +1,157 @@ +-module(ttb_helper). %%Nodes control +-compile(export_all). + +%%API +%%get() -> client:get() +%%put(X) -> client:put(X) +%%msgs(N) -> N times client:put(test_msg) +%%clear() -> restart server +%%ensure_running() / stop() -> start/stop nodes +%%get_node(atom) -> return atom@hostname + +-define(NODE_CMD(Name), + "erl -sname " ++ atom_to_list(Name) ++ + " -pa .. -pa . -detached -run ttb_helper send_ok"). +-define(REG_NAME, nc_testing). + +new_fun() -> + fun(_, end_of_trace, _, Dict) -> io:format("~p~n", [dict:to_list(Dict)]); + (_, T, _, Dict) -> case element(2, T) of + {Pid, _, _} -> + dict:update_counter(Pid, 1, Dict); + Pid -> + dict:update_counter(Pid, 1, Dict) + end + end. + +new_fun_2() -> + fun(_, end_of_trace, _, Dict) -> io:format("~p~n", [dict:to_list(Dict)]); + (_, T, _, Dict) -> case element(2, T) of + {_, Name, _} when is_atom(Name)-> + dict:update_counter(Name, 1, Dict); + Pid -> + dict:update_counter(Pid, 1, Dict) + end + + end. + + +ensure_running() -> + try_start_node(server), + try_start_node(client), + clear(). + +try_start_node(Node) -> + global:unregister_name(?REG_NAME), + global:register_name(?REG_NAME, self()), + global:sync(), + N = get_node(Node), + case net_adm:ping(N) of + pong -> + io:format("Node ~p already running~n", [N]); + _ -> + io:format("Starting node ~p... ~p ", [Node, os:cmd(?NODE_CMD(Node))]), + recv() + end. + +clear() -> + s(server, stop, []), + init(). + +stop() -> + s(init, stop, []), + c(init, stop, []). + +msgs(N) -> + [c(client, put, [test_msg]) || _ <- lists:seq(1, N)], + s(server, received, [a,b]), + [dbg:flush_trace_port(Node) || Node <- [get_node(client), get_node(server)]]. + +msgs_ip(N) -> + [c(client, put, [test_msg]) || _ <- lists:seq(1, N)], + s(server, received, [a,b]), + timer:sleep(100). %% allow trace messages to arrive over tcp/ip + +run() -> + ttb({local, "A"}), + msgs(2), + c(erlang, whereis, [ttbt]). + +get() -> c(client, get, []). +put(Thing) -> c(client, put, [Thing]). + +get_node(Node) -> + {ok, Host} = inet:gethostname(), + list_to_atom(atom_to_list(Node) ++ "@" ++ Host). + +trace_setup() -> + ttb:p(all, call), + ttb:tp(server, received, []), + ttb:tp(client, put, []), + ttb:tp(client, get, []). + +ttb() -> ttb("A"). +ttb(File) -> + ttb:tracer([get_node(client), get_node(server)], [{file, File}, resume]), + ttb:p(all, [call, timestamp]), + ttb:tp(client, put, []), + ttb:tp(client, get, []), + ttb:tp(server, received, []). + +tc() -> + TC = example_config_gen:create_trace_case("dummy comment"), + Patterns = example_config_gen:create_pattern(client, put, 1, return), + Flags = example_config_gen:create_flags(all, call), + Merge = example_config_gen:create_merge_conf(show_handler(), "dummy merge comment"), + Merge2 = example_config_gen:create_merge_conf(undefined, "dummy merge comment"), + TC2 = example_config_gen:add_pattern(Patterns, TC), + TC3 = example_config_gen:add_flags(Flags, TC2), + TC4 = example_config_gen:add_merge_conf(Merge, TC3), + TC5 = example_config_gen:add_merge_conf(Merge2, TC4), + example_config_gen:add_nodes([get_node(client), get_node(server)], TC5). + + +show(X) -> + io:format(user, "Showing: ~p~n", [X]). + +state_handler() -> + {fun(_,_,I,S) -> io:format(user, "Got from ~p: ~p~n", [I,S]), S+1 end, 0}. + +show_handler() -> + {fun(A,B,_,_) -> io:format(A, "~p~n", [B]) end, []}. + +opts() -> + [[get_node(client), get_node(server)], + [{server, received, '_', []}, + {client, put, '_', []}, + {client, get, '_', []}], + {all, call}, + [{file, "TEST"}]]. + +overload_check(check) -> + true; +overload_check(_) -> + ok. +%%%Internal +s(M, F, A) -> rpc:call(get_node(server), M, F, A). +c(M, F, A) -> rpc:call(get_node(client), M, F, A). + +send_ok() -> + pong = net_adm:ping(get_node(test)), + global:sync(), + global:send(?REG_NAME, node()). + +init() -> + True = s(server, start, []), + io:format("ok1: ~p~n", [True]), + true = c(client, init, [get_node(server)]). + +recv() -> + receive + Node -> + io:format("Node ~p ready.~n", [Node]), + ok + after 5000 -> + io:format("Startup failed~n",[]), + throw(startup_failed) + end. |