summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorBjoern Brandenburg <bbb@Serenity.local>2008-12-09 17:06:27 -0500
committerBjoern Brandenburg <bbb@Serenity.local>2008-12-09 17:06:27 -0500
commita905aa78240da26c2b03c1781a975399398ab2b5 (patch)
tree2861814ebf017a5e3d68b43d64fcd3b1817a37e4
parent7347702d06c7241816bc4c6bf14f6ca05c1c570c (diff)
provide documentation for tracing with LITMUS^RT
Diffstat
-rw-r--r--doc/tracing.html149
-rw-r--r--doc/tracing.text146
-rw-r--r--inc/format-doc.css7
-rw-r--r--index.html3
4 files changed, 254 insertions, 51 deletions
diff --git a/doc/tracing.html b/doc/tracing.html
index ba5b4e3..5d40ab7 100644
--- a/doc/tracing.html
+++ b/doc/tracing.html
@@ -8,14 +8,13 @@
8 <title>Tracing with LITMUS^RT</title> 8 <title>Tracing with LITMUS^RT</title>
9 </head> 9 </head>
10 <body> 10 <body>
11<!-- 11<!--
12
13 Note: DO NOT EDIT THE HTML FILES! 12 Note: DO NOT EDIT THE HTML FILES!
14 13
15 The documentation is written using the markdown text markup 14 The documentation is written using the markdown. The .html files are
16 language. The .html files are generated from the .text files. If you 15 generated from the .text files. If you want to update the
17 want to update the documentation you must edit the .text file and 16 documentation you must edit the .text file and re-generate the
18 re-generate the corresponding .html file. 17 corresponding .html file by executing make.
19 18
20 See 19 See
21 20
@@ -25,17 +24,17 @@
25 24
26 for further information. 25 for further information.
27 26
28--> 27 Note: PLEASE UPDATE THE CHANGE HISTORY AT THE END OF THE FILE WHEN YOU
28 UPDATE THIS FILE.
29 29
30<!-- 30# The following line is picked up bye the gen_html script.
31TITLE=Tracing with LITMUS^RT 31TITLE=Tracing with LITMUS^RT
32--> 32-->
33 33
34<h1>Tracing with LITMUS<sup>RT</sup></h1> 34<h1>Tracing with LITMUS<sup>RT</sup></h1>
35 35
36<div class="preamble"> 36<div class="preamble">
37This document is part of the documentation of the <a href="../index.html">LITMUS<sup>RT</sup> project</a>. <br/> 37This document is part of the documentation of the <a href="../index.html">LITMUS<sup>RT</sup> project</a>.
38Written by Bjoern B. Brandenburg (bbb at cs.unc.edu) on 12/09/2008.
39</div> 38</div>
40 39
41<p>As of version 2008.2, there are three tracing mechanisms available in LITMUS<sup>RT</sup>:</p> 40<p>As of version 2008.2, there are three tracing mechanisms available in LITMUS<sup>RT</sup>:</p>
@@ -44,13 +43,13 @@ Written by Bjoern B. Brandenburg (bbb at cs.unc.edu) on 12/09/2008.
44<li><p><code>litmus_log</code>: This trace contains text messages (created with the <code>TRACE()</code> 43<li><p><code>litmus_log</code>: This trace contains text messages (created with the <code>TRACE()</code>
45macro, see <code>litmus.h</code>) that convey information useful for debugging. There is one global 44macro, see <code>litmus.h</code>) that convey information useful for debugging. There is one global
46<code>litmus_log</code> buffer for the whole system. Debug tracing must be enabled at compile time. Note that debug tracing creates significant overhead because string formatting takes place.</p></li> 45<code>litmus_log</code> buffer for the whole system. Debug tracing must be enabled at compile time. Note that debug tracing creates significant overhead because string formatting takes place.</p></li>
47<li><p><code>ft_trace</code>: This trace contains binary-encoded time stamps. It is used for overhead tracing. There is one <code>ft_trace</code> buffer per processor. The "ft" stands for <a href="http://www.cs.unc.edu/~bbb/feather-trace">Feather-Trace</a>. Feather-Trace is designed to create only negligible overhead when event sources are disabled, and to incur only low overhead when recording time stamps.</p></li> 46<li><p><code>ft_trace</code>: This trace contains binary-encoded time stamps. It is used for overhead tracing. There is one global <code>ft_trace</code> buffer for the whole system. The "ft" stands for <a href="http://www.cs.unc.edu/~bbb/feather-trace">Feather-Trace</a>. Feather-Trace is designed to create only negligible overhead when event sources are disabled, and to incur only low overhead when recording time stamps.</p></li>
48<li><p><code>sched_trace</code>: This trace contains binary-encoded scheduling event information, <em>e.g.</em>, an event can be recorded whenever a task got scheduled, a job was released, a job completed, etc. There is one <code>sched_trace</code> buffer per processor. <code>sched_trace</code> is also based on Feather-Trace and hence incurs only neglible overhead when event sources are disabled.</p></li> 47<li><p><code>sched_trace</code>: This trace contains binary-encoded scheduling event information, <em>e.g.</em>, an event can be recorded whenever a task got scheduled, a job was released, a job completed, etc. There is one <code>sched_trace</code> buffer per processor. <code>sched_trace</code> is also based on Feather-Trace and hence incurs only neglible overhead when event sources are disabled.</p></li>
49</ol> 48</ol>
50 49
51<h2>Accessing Trace Buffers</h2> 50<h2>Accessing Trace Buffers</h2>
52 51
53<p>Currently, all three traces are exported to user space through character device drivers. You can discover the major numbers allocated by the drivers by looking at <code>/proc/devices</code>. Usually, the major numbers are 251, 252, and 253 respectively.</p> 52<p>Currently, all three traces are exported to user space through character device drivers. The major numbers allocated by the drivers can be discovered by looking at <code>/proc/devices</code>. Usually, the major numbers are 251, 252, and 253 respectively.</p>
54 53
55<p>The per-processor buffers are accessible via the minor numbers of the drivers. Hence, proper device files can be created with the following script.</p> 54<p>The per-processor buffers are accessible via the minor numbers of the drivers. Hence, proper device files can be created with the following script.</p>
56 55
@@ -60,17 +59,18 @@ LITMUS_LOG_MAJOR=`grep litmus_log /proc/devices | awk '{print $1}'`
60FT_TRACE_MAJOR=`grep ft_trace /proc/devices | awk '{print $1}'` 59FT_TRACE_MAJOR=`grep ft_trace /proc/devices | awk '{print $1}'`
61SCHED_TRACE_MAJOR=`grep sched_trace /proc/devices | awk '{print $1}'` 60SCHED_TRACE_MAJOR=`grep sched_trace /proc/devices | awk '{print $1}'`
62 61
62mknod litmus_log c $LITMUS_LOG_MAJOR 0
63mknod ft_trace c $FT_TRACE_MAJOR 0
64
63NUM_PROCS=$((`grep 'processor' /proc/cpuinfo | wc -l` - 1)) 65NUM_PROCS=$((`grep 'processor' /proc/cpuinfo | wc -l` - 1))
64 66
65mknod litmus_log c $LITMUS_LOG_MAJOR 0
66for P in `seq 0 $NUM_PROCS` 67for P in `seq 0 $NUM_PROCS`
67do 68do
68 mknod "ft_trace$P" c $FT_TRACE_MAJOR $P
69 mknod "sched_trace$P" c $SCHED_TRACE_MAJOR $P 69 mknod "sched_trace$P" c $SCHED_TRACE_MAJOR $P
70done 70done
71</code></pre> 71</code></pre>
72 72
73<p>Alternatively, you can setup <code>udev</code> rules to create the devices on demand. This, however, is beyond the scope of this document.</p> 73<p>Alternatively, one can setup <code>udev</code> rules to create the devices on demand. This, however, is beyond the scope of this document.</p>
74 74
75<h2>Recording Debug Traces</h2> 75<h2>Recording Debug Traces</h2>
76 76
@@ -79,25 +79,128 @@ done
79<pre><code>cat litmus_log &gt; my_debug_log 79<pre><code>cat litmus_log &gt; my_debug_log
80</code></pre> 80</code></pre>
81 81
82<p>Kill the <code>cat</code> process to stop recording debug messages. No post-processing is required since the debug messages are plain text.</p> 82<p>Kill the <code>cat</code> process to stop recording debug messages.</p>
83
84<p>No post-processing is required since the debug messages are plain text. However, note that messages may appear in a different order than how they occured at runtime. If order is important (for example when debugging race conditions), then recorded messages can be sorted offline with the help of the <em>sequence number</em> at the start of each recorded message. <br />
85Example:</p>
86
87<pre><code>sort -n my_debug_log &gt; my_sorted_debug_log
88</code></pre>
89
90<p><strong>Hint</strong>: One can use <code>netcat(1)</code> to send the debug messages to another machine via UDP to avoid filesystem activity.</p>
91
92<h2>Recording Overhead Traces</h2>
83 93
84<p><strong>Hint</strong>: You can use <code>netcat</code> to send the debug messages to another machine via UDP to avoid filesystem activity.</p> 94<p>Feather-Trace allows for much more fine-grained tracing than the simple debug stream realized by <code>litmus_log</code> and hence requires special-purpose tools to be used. These tools are available as part of the <code>ft_tools</code> package, which is available on the <a href="../index.html#download">LITMUS<sup>RT</sup> download page</a>.</p>
85 95
86<h2>Recording Overhead Traces</h2> 96<p>Feather-Trace events can be enabled on a per-event basis. Each event is identified by a unique 32-bit ID. Intially, when the device buffer is not being accessed by any user space programs (<em>i.e.</em>, when the device driver is unused), all events are disabled. Events can be enabled (and subsequently disabled again) by writing binary commands to the buffer device file. Once events are enabled they can generate trace records, which are stored in the trace buffer. Userspace programs can obtain these records by reading from the device file. Reading a trace record removes it from the buffer, <em>i.e.</em>, each record can be read exactly once. Since buffer capacity is limited records should be consumed shortly after they were created.</p>
87 97
88<p><em>to be written</em></p> 98<p>The tool <code>ftcat</code>, which is part of the <code>ft_tools</code> package (see above), automates the process of enabling events and retrieving trace records. It takes the name of the <code>ft_trace</code> device file and the events of interest as arguments:</p>
99
100<pre><code>ftcat &lt;ft device&gt; &lt;event 1&gt; &lt;event 2&gt; &lt;event 3&gt; ...
101</code></pre>
102
103<p>The tool enables the specified events and copies all recorded events to <code>stdout</code>.</p>
104
105<p>Events can be specified either by their ID (see <code>include/litmus/trace.h</code> in the kernel directory for a list of timestamp-generating events) or by their symbolic name. The following symbolic names are recognized:</p>
106
107<ul>
108<li><code>SCHED_START</code>, <code>SCHED_END</code>: <br />
109Used to measure the time spent to make a scheduling decision.</li>
110<li><code>CXS_START</code>, <code>CXS_END</code>: <br />
111Used to record the time spent to make a context switch.</li>
112<li><code>SCHED2_START</code>, <code>SCHED2_END</code>: <br />
113Used to measure the time spent to perform post-context-switch cleanup and management activities. (This is part of the scheduling overhead but for technical reasons cannot be measured as part of the interval [<code>SCHED_START</code>, <code>SCHED_END</code>].</li>
114<li><code>TICK_START</code>, <code>TICK_END</code>: <br />
115Used to measure the overhead incurred at the beginning of a scheduling quantum.</li>
116<li><code>PLUGIN_TICK_START</code>, <code>PLUGIN_TICK_END</code>: <br />
117Like [<code>TICK_START</code>, <code>TICK_END</code>], but only measures the time spent by the active scheduling plugin.</li>
118<li><code>PLUGIN_SCHED_START</code>, <code>PLUGIN_SCHED_END</code>: <br />
119Like [<code>SCHED_START</code>, <code>SCHED_END</code>], but only measures the time spent by the active scheduling plugin. There is no equivalent <code>SCHED2</code> counterpart because the scheduling plugins do not directly compute to the <code>SCHED2</code> overhead.</li>
120<li><code>RELEASE_START</code>, <code>RELEASE_END</code>:
121Used to measure the time spent to enqueue a newly-released job in a ready queue.</li>
122</ul>
123
124<p>For example, the following command can be used to store the length of context switches and scheduling decisions in the file <code>my_trace</code>.</p>
125
126<pre><code>$ ftcat ft_trace CXS_START CXS_END SCHED_START SCHED_END SCHED2_START SCHED2_END &gt; my_trace
127</code></pre>
128
129<p>The tracing can be stopped by interrupting <code>ftcat</code> with <code>^C</code> or by sending <code>SIGTERM</code> with <code>kill(1)</code>.</p>
130
131<p>Note that the recorded trace is stored in the byte order of the host.</p>
89 132
90<h2>Post-Processing Overhead Traces</h2> 133<h2>Post-Processing Overhead Traces</h2>
91 134
92<p><em>to be written</em></p> 135<p>The binary event stream recorded by <code>ftcat</code> is of course of limited direct use&mdash;the data has yet to be exported for analysis. This can be achieved with the tool <code>ft2csv</code>, which is also part of the <code>ft_tools</code> package.</p>
136
137<p>As the name suggests, <code>ft2csv</code> extracts intervals defined by pairs of timestamps in a recorded trace and displayse them as <em>comma-separated values</em> (CSV). It takes the name of an overhead trace and one start event as arguments:</p>
138
139<pre><code>ft2csv &lt;start event&gt; &lt;overhead trace&gt;
140</code></pre>
141
142<p>Events are specified in the same way as with <code>ftcat</code>. For example, the following command can be used to print the context-switch lengths that were recorded in the example above to <code>stdout</code>.</p>
143
144<pre><code>$ ft2csv CXS_START my_trace
1452397634444579592, 2397634444583328, 3736
1462397634477323130, 2397634477326686, 3556
1472397634477346366, 2397634477348986, 2620
1482397634611910924, 2397634611914348, 3424
149...
150</code></pre>
151
152<p>For each event, the start time (in clock cycles) is given in the first column, the end time is given in the second column, and the length is given in the third column (again, in cycles).</p>
153
154<p><code>ft2csv</code> accepts a few options that affect how events are filtered. By default, events that do not involve real-time tasks are ignored. This can be changed by specifiying the <code>-b</code> option. If one happens to be processing output on a little-endian host that was produced on a big-endian host then the <code>-e</code> option can come in handy.</p>
93 155
94<h2>Recording Scheduling Traces</h2> 156<p>Once the recorded overheads have been exported to CSV files they can be easily analyzed with tools such as Python, Octave, or Matlab.</p>
95 157
96<p><em>to be written</em></p> 158<h2>Recording and Post-Processing Scheduling Traces</h2>
159
160<p>Scheduling traces are also recorded using Feather-Trace. However, a different binary format is being used. The definition and an explanation of the format can be found in the file <code>include/litmus/sched_trace.h</code> (in the kernel directory).</p>
161
162<p>Since <code>sched_trace</code> uses per-processor buffers several <code>ftcat</code> instances have to be launched. The <code>ft_tools</code> package includes a wrapper script called <code>st_trace</code> that automates this setup procedure. Note that one may have to modify <code>st_trace</code> to change the default location of the <code>sched_trace</code> device files. <code>st_trace</code> accepts a tag as the only argument. The tag is used to assign a unique name to the trace files.</p>
163
164<p>The following example illustrates how a <code>st_trace</code> is used with the tag <code>global-exp</code>.</p>
165
166<pre><code>$ st_trace global-exp
167CPU 0: 8204 &gt; st-global-exp-0.bin [0]
168CPU 1: 8205 &gt; st-global-exp-1.bin [0]
169CPU 2: 8206 &gt; st-global-exp-2.bin [0]
170CPU 3: 8207 &gt; st-global-exp-3.bin [0]
171Press Enter to end tracing... # enter pressed
172
173Disabling 9 events.
174Disabling 9 events.
175Disabling 9 events.
176Disabling 9 events.
177/home/litmus/log0: 1234 bytes read.
178/home/litmus/log1: 1234 bytes read.
179/home/litmus/log2: 1234 bytes read.
180/home/litmus/log3: 1234 bytes read.
181</code></pre>
182
183<p>Note that <code>st_trace</code> may have to modified to change the default <code>sched_trace</code> device locations.</p>
184
185<p><strong>Hint</strong>: To study/test the behavior of a scheduler plugin the dummy real-time task <code>rtspin</code> (distributed as part of the <code>liblitmus</code> package) may be useful.</p>
97 186
98<h2>Post-Processing Overhead Traces</h2> 187<h2>Post-Processing Overhead Traces</h2>
99 188
100<p><em>to be written</em></p> 189<p>The user space library and tools package <code>liblitmus</code> contains the necessary headers to write <code>sched_trace</code> post-processing and analysis tools (see <code>include/sched_trace.h</code> and <code>src/sched_trace.c</code>).</p>
190
191<p>The tool <code>showst</code> (distributed as part of <code>liblitmus</code>) can be used to inspect the binary traces recorded with <code>st_trace</code> and may provide a good starting point for the development of custom analysis tools.</p>
192
193<h2>Concluding Remarks</h2>
194
195<p>At this point we only offer data <em>acquisition</em> tools since we have not yet had the time to develop release-quality <em>analysis</em> tools. <strong>Patches to improve the acquisition tools and contributions of analysis and visualization tools are very much welcome!</strong></p>
196
197<p>For any questions please contact the current LITMUS<sup>RT</sup> maintainer (as indicated on the <a href="../index.html#collaborators">LITMUS<sup>RT</sup> homepage</a>).</p>
198
199<h2>Change History</h2>
200
201<ul>
202<li>Intially written by <a href="http://www.cs.unc.edu/~bbb">Bjoern B. Brandenburg</a> (bbb at cs.unc.edu) on 12/09/2008.</li>
203</ul>
101<script src="http://www.google-analytics.com/urchin.js" type="text/javascript"> 204<script src="http://www.google-analytics.com/urchin.js" type="text/javascript">
102</script> 205</script>
103<script type="text/javascript"> 206<script type="text/javascript">
diff --git a/doc/tracing.text b/doc/tracing.text
index 45df216..3421cd2 100644
--- a/doc/tracing.text
+++ b/doc/tracing.text
@@ -1,11 +1,10 @@
1<!-- 1<!--
2
3 Note: DO NOT EDIT THE HTML FILES! 2 Note: DO NOT EDIT THE HTML FILES!
4 3
5 The documentation is written using the markdown text markup 4 The documentation is written using the markdown. The .html files are
6 language. The .html files are generated from the .text files. If you 5 generated from the .text files. If you want to update the
7 want to update the documentation you must edit the .text file and 6 documentation you must edit the .text file and re-generate the
8 re-generate the corresponding .html file. 7 corresponding .html file by executing make.
9 8
10 See 9 See
11 10
@@ -15,9 +14,10 @@
15 14
16 for further information. 15 for further information.
17 16
18--> 17 Note: PLEASE UPDATE THE CHANGE HISTORY AT THE END OF THE FILE WHEN YOU
18 UPDATE THIS FILE.
19 19
20<!-- 20# The following line is picked up bye the gen_html script.
21TITLE=Tracing with LITMUS^RT 21TITLE=Tracing with LITMUS^RT
22--> 22-->
23 23
@@ -25,8 +25,7 @@ Tracing with LITMUS<sup>RT</sup>
25================================ 25================================
26 26
27<div class="preamble"> 27<div class="preamble">
28This document is part of the documentation of the <a href="../index.html">LITMUS<sup>RT</sup> project</a>. <br/> 28This document is part of the documentation of the <a href="../index.html">LITMUS<sup>RT</sup> project</a>.
29Written by Bjoern B. Brandenburg (bbb at cs.unc.edu) on 12/09/2008.
30</div> 29</div>
31 30
32As of version 2008.2, there are three tracing mechanisms available in LITMUS<sup>RT</sup>: 31As of version 2008.2, there are three tracing mechanisms available in LITMUS<sup>RT</sup>:
@@ -35,14 +34,14 @@ As of version 2008.2, there are three tracing mechanisms available in LITMUS<sup
35macro, see `litmus.h`) that convey information useful for debugging. There is one global 34macro, see `litmus.h`) that convey information useful for debugging. There is one global
36`litmus_log` buffer for the whole system. Debug tracing must be enabled at compile time. Note that debug tracing creates significant overhead because string formatting takes place. 35`litmus_log` buffer for the whole system. Debug tracing must be enabled at compile time. Note that debug tracing creates significant overhead because string formatting takes place.
37 36
382. `ft_trace`: This trace contains binary-encoded time stamps. It is used for overhead tracing. There is one `ft_trace` buffer per processor. The "ft" stands for [Feather-Trace](http://www.cs.unc.edu/~bbb/feather-trace). Feather-Trace is designed to create only negligible overhead when event sources are disabled, and to incur only low overhead when recording time stamps. 372. `ft_trace`: This trace contains binary-encoded time stamps. It is used for overhead tracing. There is one global `ft_trace` buffer for the whole system. The "ft" stands for [Feather-Trace](http://www.cs.unc.edu/~bbb/feather-trace). Feather-Trace is designed to create only negligible overhead when event sources are disabled, and to incur only low overhead when recording time stamps.
39 38
403. `sched_trace`: This trace contains binary-encoded scheduling event information, *e.g.*, an event can be recorded whenever a task got scheduled, a job was released, a job completed, etc. There is one `sched_trace` buffer per processor. `sched_trace` is also based on Feather-Trace and hence incurs only neglible overhead when event sources are disabled. 393. `sched_trace`: This trace contains binary-encoded scheduling event information, *e.g.*, an event can be recorded whenever a task got scheduled, a job was released, a job completed, etc. There is one `sched_trace` buffer per processor. `sched_trace` is also based on Feather-Trace and hence incurs only neglible overhead when event sources are disabled.
41 40
42Accessing Trace Buffers 41Accessing Trace Buffers
43----------------------- 42-----------------------
44 43
45Currently, all three traces are exported to user space through character device drivers. You can discover the major numbers allocated by the drivers by looking at `/proc/devices`. Usually, the major numbers are 251, 252, and 253 respectively. 44Currently, all three traces are exported to user space through character device drivers. The major numbers allocated by the drivers can be discovered by looking at `/proc/devices`. Usually, the major numbers are 251, 252, and 253 respectively.
46 45
47The per-processor buffers are accessible via the minor numbers of the drivers. Hence, proper device files can be created with the following script. 46The per-processor buffers are accessible via the minor numbers of the drivers. Hence, proper device files can be created with the following script.
48 47
@@ -52,44 +51,139 @@ The per-processor buffers are accessible via the minor numbers of the drivers. H
52 FT_TRACE_MAJOR=`grep ft_trace /proc/devices | awk '{print $1}'` 51 FT_TRACE_MAJOR=`grep ft_trace /proc/devices | awk '{print $1}'`
53 SCHED_TRACE_MAJOR=`grep sched_trace /proc/devices | awk '{print $1}'` 52 SCHED_TRACE_MAJOR=`grep sched_trace /proc/devices | awk '{print $1}'`
54 53
54 mknod litmus_log c $LITMUS_LOG_MAJOR 0
55 mknod ft_trace c $FT_TRACE_MAJOR 0
56
55 NUM_PROCS=$((`grep 'processor' /proc/cpuinfo | wc -l` - 1)) 57 NUM_PROCS=$((`grep 'processor' /proc/cpuinfo | wc -l` - 1))
56 58
57 mknod litmus_log c $LITMUS_LOG_MAJOR 0
58 for P in `seq 0 $NUM_PROCS` 59 for P in `seq 0 $NUM_PROCS`
59 do 60 do
60 mknod "ft_trace$P" c $FT_TRACE_MAJOR $P
61 mknod "sched_trace$P" c $SCHED_TRACE_MAJOR $P 61 mknod "sched_trace$P" c $SCHED_TRACE_MAJOR $P
62 done 62 done
63 63
64Alternatively, you can setup `udev` rules to create the devices on demand. This, however, is beyond the scope of this document. 64Alternatively, one can setup `udev` rules to create the devices on demand. This, however, is beyond the scope of this document.
65 65
66Recording Debug Traces 66Recording Debug Traces
67---------------------- 67----------------------
68 68
69The `litmus_log` buffer can be read by simply opening the file and reading its contents: 69The `litmus_log` buffer can be read by simply opening the file and reading its contents:
70 70
71 cat litmus_log > my_debug_log 71 cat litmus_log > my_debug_log
72
73Kill the `cat` process to stop recording debug messages.
74
75No post-processing is required since the debug messages are plain text. However, note that messages may appear in a different order than how they occured at runtime. If order is important (for example when debugging race conditions), then recorded messages can be sorted offline with the help of the *sequence number* at the start of each recorded message.
76Example:
77
78 sort -n my_debug_log > my_sorted_debug_log
79
80**Hint**: One can use `netcat(1)` to send the debug messages to another machine via UDP to avoid filesystem activity.
81
82Recording Overhead Traces
83--------------------------
72 84
73Kill the `cat` process to stop recording debug messages. No post-processing is required since the debug messages are plain text. 85Feather-Trace allows for much more fine-grained tracing than the simple debug stream realized by `litmus_log` and hence requires special-purpose tools to be used. These tools are available as part of the `ft_tools` package, which is available on the [LITMUS<sup>RT</sup> download page](../index.html#download).
74 86
75**Hint**: You can use `netcat` to send the debug messages to another machine via UDP to avoid filesystem activity. 87Feather-Trace events can be enabled on a per-event basis. Each event is identified by a unique 32-bit ID. Intially, when the device buffer is not being accessed by any user space programs (*i.e.*, when the device driver is unused), all events are disabled. Events can be enabled (and subsequently disabled again) by writing binary commands to the buffer device file. Once events are enabled they can generate trace records, which are stored in the trace buffer. Userspace programs can obtain these records by reading from the device file. Reading a trace record removes it from the buffer, *i.e.*, each record can be read exactly once. Since buffer capacity is limited records should be consumed shortly after they were created.
76 88
77Recording Overhead Traces 89The tool `ftcat`, which is part of the `ft_tools` package (see above), automates the process of enabling events and retrieving trace records. It takes the name of the `ft_trace` device file and the events of interest as arguments:
78-------------------------
79 90
80*to be written* 91 ftcat <ft device> <event 1> <event 2> <event 3> ...
92
93The tool enables the specified events and copies all recorded events to `stdout`.
94
95Events can be specified either by their ID (see `include/litmus/trace.h` in the kernel directory for a list of timestamp-generating events) or by their symbolic name. The following symbolic names are recognized:
96
97- `SCHED_START`, `SCHED_END`:
98Used to measure the time spent to make a scheduling decision.
99- `CXS_START`, `CXS_END`:
100Used to record the time spent to make a context switch.
101- `SCHED2_START`, `SCHED2_END`:
102Used to measure the time spent to perform post-context-switch cleanup and management activities. (This is part of the scheduling overhead but for technical reasons cannot be measured as part of the interval [`SCHED_START`, `SCHED_END`].
103- `TICK_START`, `TICK_END`:
104Used to measure the overhead incurred at the beginning of a scheduling quantum.
105- `PLUGIN_TICK_START`, `PLUGIN_TICK_END`:
106Like [`TICK_START`, `TICK_END`], but only measures the time spent by the active scheduling plugin.
107- `PLUGIN_SCHED_START`, `PLUGIN_SCHED_END`:
108Like [`SCHED_START`, `SCHED_END`], but only measures the time spent by the active scheduling plugin. There is no equivalent `SCHED2` counterpart because the scheduling plugins do not directly compute to the `SCHED2` overhead.
109- `RELEASE_START`, `RELEASE_END`:
110Used to measure the time spent to enqueue a newly-released job in a ready queue.
111
112For example, the following command can be used to store the length of context switches and scheduling decisions in the file `my_trace`.
113
114 $ ftcat ft_trace CXS_START CXS_END SCHED_START SCHED_END SCHED2_START SCHED2_END > my_trace
115
116The tracing can be stopped by interrupting `ftcat` with `^C` or by sending `SIGTERM` with `kill(1)`.
117
118Note that the recorded trace is stored in the byte order of the host.
81 119
82Post-Processing Overhead Traces 120Post-Processing Overhead Traces
83------------------------------- 121-------------------------------
84 122
85*to be written* 123The binary event stream recorded by `ftcat` is of course of limited direct use&mdash;the data has yet to be exported for analysis. This can be achieved with the tool `ft2csv`, which is also part of the `ft_tools` package.
124
125As the name suggests, `ft2csv` extracts intervals defined by pairs of timestamps in a recorded trace and displayse them as *comma-separated values* (CSV). It takes the name of an overhead trace and one start event as arguments:
86 126
87Recording Scheduling Traces 127 ft2csv <start event> <overhead trace>
88---------------------------
89 128
90*to be written* 129Events are specified in the same way as with `ftcat`. For example, the following command can be used to print the context-switch lengths that were recorded in the example above to `stdout`.
130
131 $ ft2csv CXS_START my_trace
132 2397634444579592, 2397634444583328, 3736
133 2397634477323130, 2397634477326686, 3556
134 2397634477346366, 2397634477348986, 2620
135 2397634611910924, 2397634611914348, 3424
136 ...
137
138For each event, the start time (in clock cycles) is given in the first column, the end time is given in the second column, and the length is given in the third column (again, in cycles).
139
140`ft2csv` accepts a few options that affect how events are filtered. By default, events that do not involve real-time tasks are ignored. This can be changed by specifiying the `-b` option. If one happens to be processing output on a little-endian host that was produced on a big-endian host then the `-e` option can come in handy.
141
142Once the recorded overheads have been exported to CSV files they can be easily analyzed with tools such as Python, Octave, or Matlab.
143
144Recording and Post-Processing Scheduling Traces
145-----------------------------------------------
146
147Scheduling traces are also recorded using Feather-Trace. However, a different binary format is being used. The definition and an explanation of the format can be found in the file `include/litmus/sched_trace.h` (in the kernel directory).
148
149Since `sched_trace` uses per-processor buffers several `ftcat` instances have to be launched. The `ft_tools` package includes a wrapper script called `st_trace` that automates this setup procedure. Note that one may have to modify `st_trace` to change the default location of the `sched_trace` device files. `st_trace` accepts a tag as the only argument. The tag is used to assign a unique name to the trace files.
150
151The following example illustrates how a `st_trace` is used with the tag `global-exp`.
152
153 $ st_trace global-exp
154 CPU 0: 8204 > st-global-exp-0.bin [0]
155 CPU 1: 8205 > st-global-exp-1.bin [0]
156 CPU 2: 8206 > st-global-exp-2.bin [0]
157 CPU 3: 8207 > st-global-exp-3.bin [0]
158 Press Enter to end tracing... # enter pressed
159
160 Disabling 9 events.
161 Disabling 9 events.
162 Disabling 9 events.
163 Disabling 9 events.
164 /home/litmus/log0: 1234 bytes read.
165 /home/litmus/log1: 1234 bytes read.
166 /home/litmus/log2: 1234 bytes read.
167 /home/litmus/log3: 1234 bytes read.
168
169Note that `st_trace` may have to modified to change the default `sched_trace` device locations.
170
171**Hint**: To study/test the behavior of a scheduler plugin the dummy real-time task `rtspin` (distributed as part of the `liblitmus` package) may be useful.
91 172
92Post-Processing Overhead Traces 173Post-Processing Overhead Traces
93------------------------------- 174-------------------------------
94 175
95*to be written* 176The user space library and tools package `liblitmus` contains the necessary headers to write `sched_trace` post-processing and analysis tools (see `include/sched_trace.h` and `src/sched_trace.c`).
177
178The tool `showst` (distributed as part of `liblitmus`) can be used to inspect the binary traces recorded with `st_trace` and may provide a good starting point for the development of custom analysis tools.
179
180Concluding Remarks
181------------------
182
183At this point we only offer data *acquisition* tools since we have not yet had the time to develop release-quality *analysis* tools. **Patches to improve the acquisition tools and contributions of analysis and visualization tools are very much welcome!**
184
185For any questions please contact the current LITMUS<sup>RT</sup> maintainer (as indicated on the [LITMUS<sup>RT</sup> homepage](../index.html#collaborators)).
186
187Change History
188--------------
189- Intially written by <a href="http://www.cs.unc.edu/~bbb">Bjoern B. Brandenburg</a> (bbb at cs.unc.edu) on 12/09/2008.
diff --git a/inc/format-doc.css b/inc/format-doc.css
index 72c64e9..78637f9 100644
--- a/inc/format-doc.css
+++ b/inc/format-doc.css
@@ -33,7 +33,8 @@ img {
33 33
34p { 34p {
35 font-size: 12pt; 35 font-size: 12pt;
36 } 36 text-align: justify;
37}
37 38
38.alertbox { 39.alertbox {
39 border-color: red; 40 border-color: red;
@@ -88,6 +89,7 @@ h1 {
88 89
89h2 { 90h2 {
90 font: normal normal 18pt Georgia, "Times New Roman", Times, serif; 91 font: normal normal 18pt Georgia, "Times New Roman", Times, serif;
92 padding-top: 0.75cm;
91} 93}
92 94
93.relname { 95.relname {
@@ -110,7 +112,7 @@ pre {
110 padding: 0.2cm; 112 padding: 0.2cm;
111 background-color: #000000; 113 background-color: #000000;
112 color: #cccccc; 114 color: #cccccc;
113 border: 2px solid #eb4f0c; 115 border: 4px solid #b9b9b9;
114 font: 10pt "Courier New", Courier, mono; 116 font: 10pt "Courier New", Courier, mono;
115 overflow: auto; 117 overflow: auto;
116} 118}
@@ -119,4 +121,5 @@ pre {
119 text-align: center; 121 text-align: center;
120 font-style: italic; 122 font-style: italic;
121 margin: 0.75cm; 123 margin: 0.75cm;
124
122} 125}
diff --git a/index.html b/index.html
index 71d30ff..b795da0 100644
--- a/index.html
+++ b/index.html
@@ -449,6 +449,9 @@ make
449 task development. To get started with development, please take a look these example 449 task development. To get started with development, please take a look these example
450 programs. 450 programs.
451 </p> 451 </p>
452 <h3>Tracing Overheads and Scheduling Decisions</h3>
453 <p class="qa">LITMUS<sup>RT</sup> provides numerous tracing facilities that are discussed in-depth in the tutorial <a href="doc/tracing.html">Tracing with LITMUS<sup>RT</sup></a>.
454 </p>
452 <p class="nobottommargin"> 455 <p class="nobottommargin">
453 Please contact <span class="src">bbb[AT]cs.unc.edu</span> if you have any 456 Please contact <span class="src">bbb[AT]cs.unc.edu</span> if you have any
454 questions. 457 questions.
generated by cgit v1.2.2 (git 2.25.0) at 2025-03-20 17:50:32 -0400