This page describes how to record and visualize a trace on a Fuchsia device with the Fuchsia tracing system.
Important: Tracing is only enabled for core
and eng
build types in Fuchsia images. Make sure that the Fuchsia image you use is of core
or eng
build type. In other words, if you‘re to build a Fuchsia image from the Fuchsia source checkout or download a Fuchsia prebuilt image, make sure that the image’s build type is not user
or userdebug
.
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:
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.
Note: For more details on the ffx trace
commands and options, see Record traces for performance analysis.
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{:.external}.
Do the following:
.fxt
file from the host machine.This viewer also allows you to use SQL to query the trace data{:.external}.
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.
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{:.external}, whichis built into a Chrome{:.external} browser.
Do the following:
chrome://tracing
.For more information on Chromium's Trace-Viewer, see The Trace Event Profiling Tool{:.external}.
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{:.external} 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.
Tip: In the top right corner of the HTML page, click the small ? icon to see help information.
For navigating information on an HTML trace file, the following are some useful keyboard shortcuts:
w
and s
: Zoom in and zoom out, respectively. The zoom function is based on the current position of your mouse.W
and S
: Zoom in and zoom out at a larger scale, respectively. The zoom function is based on the current position of your mouse.a
and d
: Pan left and right, respectively.A
and D
: 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.
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.
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,
Note: For more information on creating a process in Fuchsia, see Process creation.
To finish the tracing, press Enter
key in the terminal where ffx 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.
{: width=“600”}
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.
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.
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.
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:
du
from the filesystem?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).
{: width=“600”}
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.
{: width=“600”}
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:
{: width=“300” border=“1”}
This information tells you the following:
FileReadAt
is vfs
.To understand how tracing is performed for FileReatAt
, see //src/storage/lib/vfs/cpp/connection/connection.cc
.
If you click on Blob::Read
, you may see information similar to the following:
{: width=“300”}
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 of blobfs
, a name of Blob::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
.