Lab 14 — SQL on traces

Clicking around a timeline answers one question at a time. A query answers the same question for every frame, every thread, every process — and it is repeatable. This lab is the bridge from looking to measuring.

TL;DR#

• trace_processor query <trace> "<sql>" runs SQL and prints the result.
• slice holds time spans; thread_track and thread map a slice to a thread; process maps a thread to a process.
• thread_state holds why a thread was not running, with state and blocked_function.
• sched holds CPU scheduling slices.
• actual_frame_timeline_slice holds frame timing with jank_type and present_type.

Mental model#

Think of a spreadsheet of everything that happened.

Each row is an event with a start time, a duration and some labels. The timeline view is a pivot chart over those rows. SQL is how you ask the pivot chart a question that is not one of its buttons.

The tables are normalised: a slice does not store the thread name, it stores a track id, and the track stores a thread id. That is why almost every useful query has a join.

Where the analogy breaks#

A spreadsheet has a fixed schema and a human chose the columns. Trace Processor's schema is derived from the trace's own structure and from a parser for each data source, and the set of tables depends on what was recorded. A query that works on one trace may return nothing on another because the data source was not enabled.

Deep dive#

Running a query#

trace_processor query trace.pftrace "SELECT ts, dur, name FROM slice LIMIT 10"

The query subcommand loads the trace, runs the SQL and exits.¹ For longer queries, a file is easier:

trace_processor query -f queries.sql trace.pftrace

-f - reads from stdin, which is convenient for piping.

The core tables#

The join that unlocks almost everything: a slice's track_id matches thread_track.id, and thread_track.utid matches thread.utid.²

The first useful query#

Every slice on a process's threads, longest first:

SELECT s.ts, s.dur, s.name, t.name AS thread
FROM slice AS s
LEFT JOIN thread_track AS trk ON s.track_id = trk.id
LEFT JOIN thread AS t ON trk.utid = t.utid
WHERE t.name = 'main'
ORDER BY s.dur DESC
LIMIT 20;

That is the query form you will adapt forever: filter by thread or process, order by duration, limit.

Thread state: the sleep analysis#

SELECT ts, dur, state, blocked_function
FROM thread_state
WHERE dur > 1000000
ORDER BY dur DESC
LIMIT 20;

Durations are in nanoseconds, so 1000000 is 1 ms. This query finds the longest intervals where a thread was not running, with the state and, where the kernel knows it, the blocking function. It is the query version of "why was the main thread asleep?".

Scheduling#

SELECT cpu, COUNT(*) AS slices, SUM(dur) AS total
FROM sched
GROUP BY cpu
ORDER BY total DESC;

This tells you how the work was distributed across cores. A single core carrying most of the time is a hint about affinity or about a workload that does not parallelise.

Frame timeline#

SELECT ts, dur, jank_type, present_type, on_time_finish
FROM actual_frame_timeline_slice
WHERE jank_type != 'None'
ORDER BY ts
LIMIT 50;

The jank_type column is the platform's own classification of why a frame was late.³ Group by it to see the distribution:

SELECT jank_type, COUNT(*) AS frames
FROM actual_frame_timeline_slice
GROUP BY jank_type
ORDER BY frames DESC;

That single result often settles an argument about whether an app is main-thread bound or render-bound.

Logs in the trace#

If the trace was recorded with the Android log data source, android_logs contains log lines with ts, prio, tag and msg, joinable to thread via utid. It is how you align a log message with a slice in the same timeline.³

Saving queries#

A query that answers a recurring question is worth keeping. Two options:

• Save the SQL file next to your notes and run it with -f.
• Use the UI's query tab, which keeps the query with the trace session.

The first is better for sharing and for CI; the second is better for exploration.

Walkthrough#

1. Confirm the tool

   trace_processor --help

   You should seeHelp text listing the subcommands.
2. Run a trivial query

   trace_processor query trace.pftrace "SELECT ts, dur, name FROM slice LIMIT 10"

   You should seeTen rows.
3. List the tables

   trace_processor query trace.pftrace "SELECT name FROM sqlite_master WHERE type='table' ORDER BY name LIMIT 40"

   You should seeA list including slice, thread_state, sched.
4. Find the longest slices

   Run the first useful query above.

   You should seeA ranked list.
5. Find the longest sleeps

   Run the thread_state query above.

   You should seeA ranked list with states.

$ trace_processor --help
trace_processor query trace.pftrace "SELECT ts, dur, name FROM slice LIMIT 10"
trace_processor query trace.pftrace "SELECT name FROM sqlite_master WHERE type='table' ORDER BY name LIMIT 40"
trace_processor query -f queries.sql trace.pftrace

Illustrative — table names and results depend on the trace.

Challenges#

Challenge 1 — Aggregate by thread#

Find the thread with the largest total slice duration in the trace.

SELECT t.name AS thread, SUM(s.dur) AS total
FROM slice AS s
LEFT JOIN thread_track AS trk ON s.track_id = trk.id
LEFT JOIN thread AS t ON trk.utid = t.utid
WHERE t.name IS NOT NULL
GROUP BY t.name
ORDER BY total DESC
LIMIT 10;

Challenge 2 — Count jank by type#

Produce a table of jank types and frame counts, and identify the dominant one.

SELECT jank_type, COUNT(*) AS frames
FROM actual_frame_timeline_slice
GROUP BY jank_type
ORDER BY frames DESC;

Challenge 3 — Correlate a log line with a slice#

Find a log message and the slice that was running on the same thread at that time.

SELECT l.ts, l.tag, l.msg, s.name AS slice
FROM android_logs AS l
LEFT JOIN thread AS t ON l.utid = t.utid
LEFT JOIN thread_track AS trk ON trk.utid = t.utid
LEFT JOIN slice AS s ON s.track_id = trk.id
  AND l.ts >= s.ts AND l.ts < s.ts + s.dur
WHERE l.msg LIKE '%YourTag%'
LIMIT 20;

What you learned#

You can query a trace for durations, states, scheduling and jank, and you can correlate two kinds of event by time. That is the skill that turns a one-off investigation into a measurement you can repeat.

Where to go next#

The performance path in Learning paths continues from here. The builder track turns the measurements into projects, and Lab 11 and Lab 12 are the questions these queries were written to answer.

Sources#