This page describes how to record and visualize a trace on a Fuchsia device with the Fuchsia tracing system.
Prerequisites
Many existing Fuchsia components are already registered as trace providers, whose trace data often provide a sufficient overview of the system. For this reason, if you only need to record a general trace (for instance, to include details in a bug report), you may proceed to the sections below. However, if you want to collect additional, customized trace events from a specific component, you need to complete the following tasks first:
Record a trace
To record a trace on a Fuchsia device from your host machine, run the following command:
ffx trace start --duration <SECONDS>
This command starts a trace with the default settings, capturing a general overview of the target device.
The trace continues for the specified duration (or until the ENTER
key
is pressed if a duration is not specified). When the trace is finished, the
trace data is automatically saved to the trace.fxt
file in the
current directory (which can be changed by specifying the --output
flag;
for example, ffx trace start --output <FILE_PATH>
). To visualize the trace
results stored in this file, see the Visualize a trace
section below.
Visualize a trace
Fuchsia trace format (.fxt
) is Fuchsia's
binary format that directly encodes the original trace data. To
visualize an .fxt
trace file, you can use the
Perfetto viewer.
Do the following:
- Visit the Perfetto viewer site on a web browser.
- Click Open trace file on the navigation bar.
- Select your
.fxt
file from the host machine.
This viewer also allows you to use SQL to query the trace data.
Appendices
The Fuchsia tracing system previously supported various file formats and different ways to visualize a trace. The sections below describe workflows related to those now-deprecated trace formats.
(Deprecated) Visualize a JSON trace
A JSON trace is a format for viewing trace data on a Chrome browser.
To convert an .fxt
trace file into JSON format, run the following
command:
fx trace2json < <FXT_FILE> > trace.json
Replace FXT_FILE
with an FXT trace file, for example:
$ fx trace2json < trace.fxt > trace.json
To visualize a JSON trace, use Chromium's Trace-Viewer, whichis built into a Chrome browser.
Do the following:
- Open a new tab on a Chrome browser.
- Navigate to
chrome://tracing
. - Click the Load button.
- Open your JSON trace file.
For more information on Chromium's Trace-Viewer, see The Trace Event Profiling Tool.
(Deprecated) Visualize an HTML trace
A HTML trace is a standalone file that includes both the viewer and trace data.
To produce an HTML trace, you can use the trace2html
tool
from the Chromium Catapult Repository
to convert an existing JSON trace file.
From the Catapult repository, run the following command:
./tracing/bin/trace2html <JSON_TRACE_FILE>
Once an HTML trace file is generated, you can open the file on any web browser to analyze the trace results.
Navigate an HTML trace file
For navigating information on an HTML trace file, the following are some useful keyboard shortcuts:
w
ands
: Zoom in and zoom out, respectively. The zoom function is based on the current position of your mouse.W
andS
: Zoom in and zoom out at a larger scale, respectively. The zoom function is based on the current position of your mouse.a
andd
: Pan left and right, respectively.A
andD
: Pan left and right at a larger scale, respectively.
Also, you can deselect specific process rows to remove processes that aren't important for your current trace. To deselect a specific process row, click the x in the right corner of the process row.
(Deprecated) Analyze an HTML trace
This walkthrough covers workflows of generating an HTML trace file
and analyzing the results on a web browser. The example in this
walkthrough records a trace of a Fuchsia system while constantly
running the du
command, which scans and generates the disk usage
of the system.
Generate trace data and convert it to HTML
To record a trace of du
and convert it to an HTML trace file,
do the following:
(Optional) If you don't have a running Fuchsia device, start an instance on the Fuchsia emulator with networking enabled:
ffx emu --net tap
In a new terminal, start a trace:
ffx trace start --buffer-size 64 --categories all
This command sets a recording buffer size of 64 megabytes and records all tracing categories.
In the Fuchsia emulator's console, run the following command:
/boot/bin/sh -c "'\ sleep 2 ;\ i=0 ;\ while [ \$i -lt 10 ] ;\ do /bin/du /boot ;\ i=\$(( \$i + 1 )) ;\ done'"
This command runs
du
in a loop,To finish the tracing, press
Enter
key in the terminal whereffx trace start
is running.When finished, the command generates a
trace.fxt
file.Convert this FXT file to JSON format:
fx trace2json < trace.fxt > trace.json
Generate an HTML trace:
./tracing/bin/trace2html trace.json
Open this HTML file on a web browser.
Figure 1. Screenshot of an HTML trace file that recorded a
du
process in a loop.A trace file has a lot of information including a time scale near the top of the trace. In the example above, the whole trace lasted about 2.5 seconds.
Examine CPU usage
The region marked by the yellow circle in Figure 1 shows the CPU usage area where you can see the overall CPU usage on all CPU cores.
Examine program execution
The region marked by the green circle in Figure 1 shows the program execution.
In this example, you can see 10 invocations of the du
program, which is
expected since the trace was recorded during a loop of du
. Therefore,
you can see 10 different du
process IDs, one after the other.
Examine blobfs CPU usage
The region marked by the blue circle in Figure 1 shows the CPU usage to write to the blobstore filesystem (blobFS).
In this example, you can see little bursts of CPU time that are each related
to an invocation of du
. At this high level, it can be difficult to determine
the exact correlation between the CPU usage and the filesystem, for instance,
for the following reasons:
- Is the CPU usage caused by the loading of
du
from the filesystem? - Is the CPU usage caused by the execution
du
as it runs through the target filesystem to see how much space is in use?
You can zoom in on specific areas of this region to determine the correlation between the CPU usage and the filesystem (see Figure 2).
Figure 2. Screenshot of the HTML trace file zoomed into a region.
In this example, you can see just two du
executions (the first is marked
with a green circle). The first blobfs
CPU burst actually consists of
three main clusters and some smaller spikes. Subsequent blobfs
CPU bursts
have two clusters.
From analyzing this example, you can see that the blobfs
bursts happen
before the du
program is executed. This information shows that the
blobfs
bursts are not due to the du
program reading the filesystem.
Instead, it shows that the bursts are due to loading the du
program.
You are now ready to dive further into what is causing the blobs
bursts.
Figure 3. Screenshot of the HTML trace file showing a time scale of about 1 millisecond.
In this example, notice the time scale that spans a time period from 2,023,500
microseconds to just past 2,024,500 which indicated a time scale of about
1 millisecond. During that millisecond, blobfs
executed code,
starting with a process identified as FileReadAt
, which then called
Blob::Read
, which then called Blob::ReadInternal
.
To correlate this information with the code, you can click on parts of the report for more detailed information about a specific object:
If you click on
FileReadAt
, you may see information similar to the following:This information tells you the following:
- The trace category for
FileReadAt
isvfs
. - The length of time of the function execution.
To understand how tracing is performed for
FileReatAt
, see//src/storage/lib/vfs/cpp/connection/connection.cc
.- The trace category for
If you click on
Blob::Read
, you may see information similar to the following:Below is the code for
Blob::Read
:zx_status_t Blob::Read(void* data, size_t len, size_t off, size_t* out_actual) { TRACE_DURATION("blobfs", "Blob::Read", "len", len, "off", off); LatencyEvent event(&blobfs_->GetMutableVnodeMetrics()->read, blobfs_->CollectingMetrics()); return ReadInternal(data, len, off, out_actual); }
This code calls calls the
TRACE_DURATION()
macro with the category ofblobfs
, a name ofBlob::Read
, and a length and offset key and value pairs. All of this information is recorded in the trace file.To understand how tracing is performed for
Blob::Read
, see//src/storage/blobfs/blob.cc
.