contents/getting-started/tracing-your-own-user-application.md

   1 ---
   2 id: tracing-your-own-user-application
   3 ---
   4
   5 The previous section helped you create a trace out of Linux kernel events.
   6 This section steps you through a simple example showing you how to trace
   7 a _Hello world_ program written in C.
   8
   9 Make sure LTTng-tools and LTTng-UST packages
  10 [are installed](#doc-installing-lttng).
  11
  12 Tracing is just like having `printf()` calls at specific locations of
  13 your source code, albeit LTTng is much more faster and flexible than
  14 `printf()`. In the LTTng realm, **`tracepoint()`** is analogous to
  15 `printf()`.
  16
  17 Unlike `printf()`, though, `tracepoint()` does not use a format string to
  18 know the types of its arguments: the formats of all tracepoints must be
  19 defined before using them. So before even writing our _Hello world_ program,
  20 we need to define the format of our tracepoint. This is done by writing a
  21 **template file**, with a name usually ending with the `.tp` extension (for **t**race**p**oint),
  22 which the `lttng-gen-tp` tool (shipped with LTTng-UST) uses to generate
  23 an object file (along with a `.c` file) and a header to be included in our application source code.
  24
  25 Here's the whole flow:
  26
  27 <div class="img img-80">
  28     <object data="/images/docs26/lttng-lttng-gen-tp.svg" type="image/svg+xml">
  29         <img src="/images/docs26/lttng-lttng-gen-tp.svg">
  30     </object>
  31 </div>
  32
  33 The template file format is a list of tracepoint definitions
  34 and other optional definition entries which we skip for
  35 this quickstart. Each tracepoint is defined using the
  36 `TRACEPOINT_EVENT()` macro. For each tracepoint, you must provide:
  37
  38   * a **provider name**, which is the "scope" of this tracepoint (this usually
  39     includes the company and project names)
  40   * a **tracepoint name**
  41   * a **list of arguments** for the eventual `tracepoint()` call, each item being:
  42     * the argument C type
  43     * the argument name
  44   * a **list of fields**, which correspond to the actual fields of the
  45     recorded events for this tracepoint
  46
  47 Here's a simple tracepoint definition example with two arguments: an integer
  48 and a string:
  49
  50 ~~~ c
  51 TRACEPOINT_EVENT(
  52     hello_world,
  53     my_first_tracepoint,
  54     TP_ARGS(
  55         int, my_integer_arg,
  56         char*, my_string_arg
  57     ),
  58     TP_FIELDS(
  59         ctf_string(my_string_field, my_string_arg)
  60         ctf_integer(int, my_integer_field, my_integer_arg)
  61     )
  62 )
  63 ~~~
  64
  65 The exact syntax is well explained in the
  66 [C application](#doc-c-application) instrumenting guide of the
  67 [Using LTTng](#doc-using-lttng) chapter, as well as in the
  68 <a href="/man/3/lttng-ust" class="ext">LTTng-UST manpage</a>.
  69
  70 Save the above snippet as `hello-tp.tp` and run:
  71
  72 <pre class="term">
  73 lttng-gen-tp hello-tp.tp
  74 </pre>
  75
  76 The following files are created next to `hello-tp.tp`:
  77
  78   * `hello-tp.c`
  79   * `hello-tp.o`
  80   * `hello-tp.h`
  81
  82 `hello-tp.o` is the compiled object file of `hello-tp.c`.
  83
  84 Now, by including `hello-tp.h` in your own application, you may use the
  85 tracepoint defined above by properly refering to it when calling
  86 `tracepoint()`:
  87
  88 ~~~ c
  89 #include <stdio.h>
  90 #include "hello-tp.h"
  91
  92 int main(int argc, char* argv[])
  93 {
  94     int x;
  95
  96     puts("Hello, World!\nPress Enter to continue...");
  97
  98     /* The following getchar() call is only placed here for the purpose
  99      * of this demonstration, for pausing the application in order for
 100      * you to have time to list its events. It's not needed otherwise.
 101      */
 102     getchar();
 103
 104     /* A tracepoint() call. Arguments, as defined in hello-tp.tp:
 105      *
 106      *     1st: provider name (always)
 107      *     2nd: tracepoint name (always)
 108      *     3rd: my_integer_arg (first user-defined argument)
 109      *     4th: my_string_arg (second user-defined argument)
 110      *
 111      * Notice the provider and tracepoint names are NOT strings;
 112      * they are in fact parts of variables created by macros in
 113      * hello-tp.h.
 114      */
 115     tracepoint(hello_world, my_first_tracepoint, 23, "hi there!");
 116
 117     for (x = 0; x < argc; ++x) {
 118         tracepoint(hello_world, my_first_tracepoint, x, argv[x]);
 119     }
 120
 121     puts("Quitting now!");
 122
 123     tracepoint(hello_world, my_first_tracepoint, x * x, "x^2");
 124
 125     return 0;
 126 }
 127 ~~~
 128
 129 Save this as `hello.c`, next to `hello-tp.tp`.
 130
 131 Notice `hello-tp.h`, the header file generated by `lttng-gen-tp` from
 132 our template file `hello-tp.tp`, is included by `hello.c`.
 133
 134 You are now ready to compile the application with LTTng-UST support:
 135
 136 <pre class="term">
 137 gcc -o hello hello.c <strong>hello-tp.o -llttng-ust -ldl</strong>
 138 </pre>
 139
 140 If you followed the
 141 [Tracing the Linux kernel](#doc-tracing-the-linux-kernel) section, the
 142 following steps should look familiar.
 143
 144 First, run the application with a few arguments:
 145
 146 <pre class="term">
 147 ./hello world and beyond
 148 </pre>
 149
 150 You should see
 151
 152 ~~~ text
 153 Hello, World!
 154 Press Enter to continue...
 155 ~~~
 156
 157 Use the `lttng` tool to list all available user space events:
 158
 159 <pre class="term">
 160 lttng list --userspace
 161 </pre>
 162
 163 You should see the `hello_world:my_first_tracepoint` tracepoint listed
 164 under the `./hello` process.
 165
 166 Create a tracing session:
 167
 168 <pre class="term">
 169 lttng create my-userspace-session
 170 </pre>
 171
 172 Enable the `hello_world:my_first_tracepoint` tracepoint:
 173
 174 <pre class="term">
 175 lttng enable-event --userspace hello_world:my_first_tracepoint
 176 </pre>
 177
 178 Start tracing:
 179
 180 <pre class="term">
 181 lttng start
 182 </pre>
 183
 184 Go back to the running `hello` application and press Enter. All `tracepoint()`
 185 calls are executed and the program finally exits.
 186
 187 Stop tracing:
 188
 189 <pre class="term">
 190 lttng stop
 191 </pre>
 192
 193 Done! You may use `lttng view` to list the recorded events. This command
 194 starts
 195 <a href="http://www.efficios.com/babeltrace" class="ext"><code>babeltrace</code></a>
 196 in the background, if it is installed:
 197
 198 <pre class="term">
 199 lttng view
 200 </pre>
 201
 202 should output something like:
 203
 204 ~~~ text
 205 [18:10:27.684304496] (+?.?????????) hostname hello_world:my_first_tracepoint: { cpu_id = 0 }, { my_string_field = "hi there!", my_integer_field = 23 }
 206 [18:10:27.684338440] (+0.000033944) hostname hello_world:my_first_tracepoint: { cpu_id = 0 }, { my_string_field = "./hello", my_integer_field = 0 }
 207 [18:10:27.684340692] (+0.000002252) hostname hello_world:my_first_tracepoint: { cpu_id = 0 }, { my_string_field = "world", my_integer_field = 1 }
 208 [18:10:27.684342616] (+0.000001924) hostname hello_world:my_first_tracepoint: { cpu_id = 0 }, { my_string_field = "and", my_integer_field = 2 }
 209 [18:10:27.684343518] (+0.000000902) hostname hello_world:my_first_tracepoint: { cpu_id = 0 }, { my_string_field = "beyond", my_integer_field = 3 }
 210 [18:10:27.684357978] (+0.000014460) hostname hello_world:my_first_tracepoint: { cpu_id = 0 }, { my_string_field = "x^2", my_integer_field = 16 }
 211 ~~~
 212
 213 When you're done, you may destroy the tracing session, which does _not_
 214 destroy the generated trace files, leaving them available for further
 215 analysis:
 216
 217 <pre class="term">
 218 lttng destroy my-userspace-session
 219 </pre>
 220
 221 The next section presents other alternatives to view and analyze your
 222 LTTng traces.