| 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 man page</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. |