USDT probes – Userspace Static Defined Tracing probes – act as markers for events of interest in user-space programs and libraries. As with kernel tracepoints, defining important events has huge value when trying to understand system behaviour. It is as if the developer who added these probes has marked the important sites on a map, and now we can use that map to help guide us to an understanding of what the system is doing by extracting the tracing information from those places.
In this blog entry, Alan Maguire and Sherwood Zern will discuss how to leverage dynamic probe creation to support USDT tracing in runtimes like python, go and java in Linux.
How USDT probes work
USDT probes are added at compile time by adding metadata about probes, principally:
- the associated domain of the probes, termed the provider
- the individual probe name, the probe
- the address(es) of instance(s) of the probe in the code
- arguments to probes
Tracers then read that metadata, and place uprobes (user-space probes equivalent to kprobes) at the USDT probe points.
In a previous blog post we discussed the various forms of user-space tracing, and gave a C example of defining USDT probes, and tracing them with BPF. The short summary is that by knowing the address of the probe and which registers are used for parameters, we can add a trap instruction into the Virtual Memory Area (VMA) associated with the inode representation of the binary being traced such that we trap into the kernel when we hit the probe – in essence we use the USDT metadata to create a uprobe at the appropriate place in the code where the USDT probe fires. Knowing which registers probe parameters are in allows tracers to read parameters passed to the probe. So the USDT probe metadata enables us to implement USDT on top of the uprobe mechanism the kernel provides.
From static to dynamic probes
One of the problems with defining such probes in applications is that it is a compile-time activity – the word “static” is the “S” in the USDT acronym! Ideally to support different languages, a dynamic method of defining USDT probes (URDT probes for runtime-defined tracing maybe?) and firing them would need to exist, allowing the runtime to call functions to define probes and trigger them.
And this is where libstapsdt comes in – it supports creation of probe points at runtime via the following steps:
- creating a shared library dynamically;
- adding USDT instrumentation to it via the ELF notes section identifying provider, probe, etc;
- dlopen()ing that library, such that then when the “probe fire” functionality is called, the associated function and probe point are called and hit.
- this triggers the tracer since a uprobe has been placed on the probe point, and the probe fires!
The great thing is, with the above in place, tracing tools that understand the static ELF notes information will work as if these probes were added at “compile time”, as long as they are attached to the process – and thus do their probe scanning – after the probes have been registered. (This is an important caveat – it is not a fully dynamic approach where probes can be added at any time. Probes should instead be added early on in the program lifetime such that tracers can then pick them up when attaching to the process.)
And even better, different runtimes can – via bindings to libstapsdt – then create USDT probes for tracing!
Building/installing libstaspsdt
To build and install libstapsdt – which provides the core functionality various runtimes use to support run-time probe definition
$ git clone https://github.com/linux-usdt/libstapsdt $ cd libstapsdt $ make && sudo make install
Adding probes in python
We can demonstrate probe use in python, with the example from https://pypi.org/project/stapsdt/ , which looks like this:
#!/usr/bin/python3
from time import sleep
import stapsdt
provider = stapsdt.Provider("pythonapp")
probe = provider.add_probe(
"firstProbe", stapsdt.ArgTypes.uint64, stapsdt.ArgTypes.int32)
provider.load()
while True:
print("Firing probe...")
if probe.fire("My little probe", 42):
print("Probe fired!")
sleep(1)
We see above, stapsdt functions are called to add and fire the probe.
We install and run the example:
$ pip3 install stapsdt $ chmod 777 example.py $ ./example.py Firing probe... Firing probe...
One thing to note here – we see “Firing probe…” but not “Probe fired!”. The reason for this is that libstapsdt checks to see if the probe function actually has any tracing attached; if it does, the kernel will replace the initial function instructions (a NOP in the case of libstapsdt) with a trap instruction. So probe.fire returns true if this has happened, and in the above case we have not attached a tracer so we do not see the “Probe fired!” message. See the previous blog post for more discussion on the mechanics of USDT tracing.
Examining the process image of the associated process, we can see our (fabricated) shared library (courtesy of libstapsdt):
$ cat /proc/$(pgrep example.py)/maps | grep stap 7f9fde1ff000-7f9fde200000 r-xp 00000000 00:01 9099 /memfd:libstapsdt:pythonapp (deleted) 7f9fde200000-7f9fde3ff000 ---p 00001000 00:01 9099 /memfd:libstapsdt:pythonapp (deleted) 7f9fde3ff000-7f9fde400000 rw-p 00000000 00:01 9099 /memfd:libstapsdt:pythonapp (deleted)
…and we can see our probe exists also:
$ /usr/share/bcc/tools/tplist -p $(pgrep example.py)|grep first /proc/46275/fd/3 pythonapp:firstProbe
We can even examine the library itself by extracting it from the memory image of the process:
$ sudo cat /proc/$(pgrep example.py)/maps|grep pythonapp
7f13289ff000-7f1328a00000 r-xp 00000000 00:01 258616 /memfd:libstapsdt:pythonapp (deleted)
7f1328a00000-7f1328bff000 ---p 00001000 00:01 258616 /memfd:libstapsdt:pythonapp (deleted)
7f1328bff000-7f1328c00000 rw-p 00000000 00:01 258616 /memfd:libstapsdt:pythonapp (deleted)
# Extract the library from the address space of the process:
$ dd if=/proc/$(pgrep example.py)/mem of=out.lib bs=1 count=$((0x7f1328a00000-0x7f13289ff000)) skip=$((0x7f13289ff000))
$ nm -D out.lib
0000000000200120 D __bss_start
0000000000200120 D _edata
0000000000200120 D _end
0000000000000260 T firstProbe
$ readelf -n out.lib
Displaying notes found in: .note.stapsdt
Owner Data size Description
stapsdt 0x0000003c NT_STAPSDT (SystemTap probe descriptors)
Provider: pythonapp
Name: firstProbe
Location: 0x0000000000000260, Base: 0x0000000000000318, Semaphore: 0x0000000000000000
Arguments: 8@%rdi -4@%rsi
Above we see the firstProbe function along with the ELF notes that describe the USDT probe pythonapp/firstProbe.
Adding probes in go
Next we will demonstrate the procedure for adding probes to go code, using salp which provides go bindings for libstapsdt.
import (
"log"
"os"
"strconv"
"time"
"github.com/mmcshane/salp"
)
func main() {
. . . .
provider = salp.NewProvider("Factorial")
defer salp.UnloadAndDispose(provider)
fileProbe = salp.MustAddProbe(
provider, "writeprobe", salp.Int64, salp.String, salp.String)
salp.MustLoadProvider(provider)
. . . . . .
fileProbe.Fire(
traceId, "factorialwritestring", "wrote the file")
}
Again we run this, and see our shared library:
$ ./main 15 2024/01/24 18:34:34 Calculating the factorial for the value: 15 .... 2024/01/24 18:35:34 Firing writeprobe probe... 2024/01/24 18:35:44 Firing writeprobe probe... 2024/01/24 18:35:54 Firing writeprobe probe... ... $ cat /proc/$(pgrep main)/maps | grep stap 7f03c8590000-7f03c8591000 r-xp 00000000 00:01 12010 /memfd:libstapsdt:Factorial (deleted) 7f03c8591000-7f03c8790000 ---p 00001000 00:01 12010 /memfd:libstapsdt:Factorial (deleted) 7f03c8790000-7f03c8791000 rw-p 00000000 00:01 12010 /memfd:libstapsdt:Factorial (deleted)
For the Factorial main method we can see that there are two probes defined
$ sudo /usr/share/bcc/tools/tplist -p $(pgrep main) | grep Factorial /proc/350609/fd/3 Factorial:factorialprobe /proc/350609/fd/3 Factorial:writeprobe $ sudo /usr/share/bcc/tools/trace -p $(pgrep main) u::writeprobe -T -C TIME CPU PID TID COMM FUNC 18:35:34 0 350609 350609 main writeprobe 18:35:44 0 350609 350609 main writeprobe 18:35:54 0 350609 350609 main writeprobe
Adding probes in java
Adding probes in Java requires a bit more foundational work before you can add probes in your Java Code. Let’s have a peek at some of this foundation code. The foundation code is Java; however, it must be compiled and built as Native code.
There are four Java classes that need to be compiled into Native code. The following classes are the key ones:
- Native.java
- Probe.java
- Provider.java
- SDTException.java
In addition, there is a sdt_Native.cc class that must be included when building the native code. This code implements the Java Native Implementation for the USDT Java Probes.
Let’s take a look at the build script. In a future release, I will have a maven project, so it can build eveything soup to nuts.
#!/bin/bash
javac -d target/classes src/main/java/com/sdt/*.java
javac -d target/classes -h . src/main/java/com/sdt/Native.java
sudo mv com_sdt_Native.h sdt_Native.h
sudo cp sdt_Native.h /usr/lib/
# -shared: Produce a shared object which can then be linked with outher objects to form an executable
# -o: output file and location
# -l: The option switches G++ to use the headers from the specified library and to
# emit -lstdc++ or -lc++ respectively, when a C++ runtime is required for linking.
#
# -I: Add the directory dir to the list of directories to be searched for header files dur-
# ing preprocessing.
# -f: Generate position-independent code (PIC) suitable for use in a shared library
# -std=c++11: A revised ISO C++ standard was published in 2011 as ISO/IEC 14882:2011, and is
# referred to as C++11
sudo gcc -shared -std=c++11 -fPIC -I${JAVA_HOME}/include -I${JAVA_HOME}/include/linux -I/usr/lib \
-o libstapsdt-jni.so sdt_Native.cc -lstdc++ -lstapsdt
sudo cp libstapsdt-jni.so /usr/lib/
cd target/classes
jar cvf provider.jar com/sdt/*.class
cp provider.jar ../../../../usdttracing/
You only need to execute the above once. Once the shared library is created there is no need to rebuild the shared library.
With the shared library created we can now implement the Java code that will register and fire probes. The registration and firing probe is shown within the basic code provided below:
package com.example;
import com.sdt.*;
public class USDTTracing
{
public static void main( String[] args ) throws Exception
{
Provider provider = new Provider("myProvider");
Probe probe = provider.addProbe("jprobe", Probe.INT32, Probe.INT64, Probe.STRING);
provider.load();
for (int i = 1; i < 1000; i++) {
Thread.sleep(1000);
if (probe.isEnabled()) {
System.out.println("Firing Probe...#" + i);
probe.fire(i, i*i, String.format("iteration #%d done", i));
} else {
System.out.println("Probe is not enabled");
}
}
provider.unload();
provider.destroy();
}
}
Notice again in the code that the block “if (probe.isEnabled())” guards for cases where a tracer has been attached. Such guarding allows us to limit the overheads associated with collecting data for probe firings to the cases where someone is actually tracing the probe firing.
Now that we have some context let’s execute this code. A quick review of the code, and you will see that this probe is firing a probe with three arguments. This indicates that the probe will be passing two integers (i and i*i) and one string, “iteration done”) to the user-space code.
$ java -cp ../../provider.jar:. com.example.USDTTracing Firing Probe...#1 Firing Probe...#2 Firing Probe...#3 Firing Probe...#4
The Java code created one Provider, named myProvider. You are able to identify the name of the provider as shown below.
$ cat /proc/$(pgrep java)/maps 7f1de0f5b000-7f1de0f5c000 r-xp 00000000 00:01 14811 /memfd:libstapsdt:myProvider (deleted) 7f1de0f5c000-7f1de115b000 ---p 00001000 00:01 14811 /memfd:libstapsdt:myProvider (deleted) 7f1de115b000-7f1de115c000 rw-p 00000000 00:01 14811 /memfd:libstapsdt:myProvider (deleted)
With the name of the provider identified we can see which probes are registered with the Provider. There is only one probe in the Java application – jprobe.
$ sudo /usr/share/bcc/tools/tplist -p $(pgrep java) | grep myProvider /proc/2991056/fd/5 myProvider:jprobe
We are now able to trace when the myProvider:jprobe is fired. The given output demonstrates that the probe is fired every second.
$ sudo /usr/share/bcc/tools/trace -p $(pgrep java) u::jprobe -T -C TIME CPU PID TID COMM FUNC 21:17:25 2 2991056 2991057 java jprobe 21:17:26 2 2991056 2991057 java jprobe 21:17:27 2 2991056 2991057 java jprobe 21:17:28 2 2991056 2991057 java jprobe
The running java application, at this point, only writes a message to stdout letting you know that a probe is being fired and the current iteration.
java -cp ../../provider.jar:. com.example.USDTTracing Firing Probe...#1 Firing Probe...#2 Firing Probe...#3 Firing Probe...#4
Summing up
You now have the means to introduce tracepoints into your python, go and Java application code. As stated earlier, building the foundation to produce the native code in the Java case does take a bit of extra effort. But, once the shared library is created you are off and running. Look for a new feature in Java 22 that will eliminate a lot of the work in creating the shared library. In fact, the feature, jextract, is available in Java 21 as a preview feature.
The next blog in this series will demonstrate how to use such probes in analyzing system behaviour. You will then have a complete flow – from application code to Linux kernel. You can get a complete view of your application and depending upon the probes created be able to identify latency in HTTP requests, latency in writing to disk, and myriad other insights.