The Fuchsia trace system supports various file formats for recording traces. Each data format requires a specific tool to visualize trace results.
Before you attempt to convert or analyze a trace file, make sure you've recorded a trace.
The following types of file formats can store Fuchsia trace data:
To convert one or more files from FXT to JSON, run the following command:
fx trace2json < <FXT_FILE> > trace.json
Replace FXT_FILE
with a trace output file in FXT format, for example:
fx trace2json < trace.fxt > trace.json
There are different ways to visualize a trace based on the format of the trace:
To visualize an FXT trace, use the Perfetto viewer{:.external}, which also allows you to use SQL to query your trace data{:.external}.
To visualize a JSON trace, use Chromium‘s Trace-Viewer{:.external}. The viewer is built into Chrome and can be loaded with chrome://tracing
. For more information on Chrome’s trace viewer, see The Trace Event Profiling Tool{:.external}.
To generate an HTML trace (which is a viewer bundled with trace data), you need to run trace2html
from the Chromium Catapult Repository{:.external}.
From the Catapult repository, run the following command:
./tracing/bin/trace2html <JSON_TRACE_FILE>
Note: The instructions in this section detail how to visualize an JSON trace with a Chrome browser.
To analyze a JSON trace file:
chrome://tracing
.As there is a lot of information in a trace file, there are some useful keyboard shortcuts that you can use:
Note: Near the top right of the page, there is a small ? icon that you can click to see help information.
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.The example in this section shows a trace of what the system is doing while running the du
command, which shows disk usage.
Before you can record trace data, you must start a Fuchsia instance. From your host, if you don't have a Fuchsia target device, you can start a Fuchsia emulator with networking:
Note: For more information on getting started with Fuchsia, see Fuchsia.
ffx emu --net tap
This command configures and starts the Fuchsia emulator.
To record a trace of du
, do the following:
In a new terminal, run ffx trace start
:
Note: For more information on recording a trace in Fuchsia, see Recording a Fuchsia 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 terminal, 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 on your host machine.
When the tracing is finished, it generated an FXT file,
Convert this FXT file to JSON:
fx trace2json < trace.fxt > trace.json
Generate an HTML trace (see HTML Trace above):
./tracing/bin/trace2html trace.json
A trace file has a lot of information including a time scale near the top of the trace. In this example, the whole trace lasted about 2.5 seconds.
The region marked by the yellow circle shows the CPU usage area where you can see the overall CPU usage on all CPU cores.
The region marked by the green circle 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 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:
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.
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.
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 can see the following information:
This information tells you the following:
FileReadAt
is vfs
.Note: For information on how tracing is performed for FileReatAt
, see //src/lib/storage/vfs/cpp/connection.cc.
If you click on Blob::Read
, you can see the following information:
Note: For information on how tracing is performed for Blob::Read
, see //src/storage/blobfs/blob.cc.
The code for Blob::Read
is:
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.
After analyzing these examples, you can still see additional objects that are being traced.