Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions profiler-cli/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ profiler-cli load <PATH> # Start daemon and load profile (file
profiler-cli profile info # Print profile summary [--all] [--search <term>]
profiler-cli profile meta # Print profile metadata (application, platform, recording settings)
profiler-cli profile logs # Print Log markers in MOZ_LOG format [--thread] [--module] [--level] [--search] [--limit]
profiler-cli profile markers # Search markers across all threads [--search] [--thread] [--category] [--min-duration] [--max-duration] [--has-stack] [--limit]
profiler-cli thread list # List all threads as a flat table [--sort] [--search] [--limit]
profiler-cli thread info # Print detailed thread information
profiler-cli thread select <handle> # Select a thread (e.g., t-0, t-1)
Expand Down
11 changes: 6 additions & 5 deletions profiler-cli/guide.txt
Original file line number Diff line number Diff line change
Expand Up @@ -26,12 +26,13 @@ CORE WORKFLOW
profiler-cli load profile.json.gz --session run-a Recommended for scripting or concurrent work

Step 2: Explore the profile
profiler-cli profile info Overview: processes, threads, time range, CPU activity
profiler-cli profile info --all Show all processes and threads (not just top 5)
profiler-cli profile info Overview: processes, threads, time range, CPU activity
profiler-cli profile info --all Show all processes and threads (not just top 5)
profiler-cli profile info --search GeckoMain Filter by process/thread name, pid, or tid
profiler-cli thread list Flat table of every thread: handle, name, process, pid, CPU, markers
profiler-cli profile meta Metadata: application, platform, and recording settings
profiler-cli profile logs Print all Log markers in MOZ_LOG format (across all threads)
profiler-cli thread list Flat table of every thread: handle, name, process, pid, CPU, markers
profiler-cli profile meta Metadata: application, platform, and recording settings
profiler-cli profile logs Print all Log markers in MOZ_LOG format (across all threads)
profiler-cli profile markers --search X Find which thread/process has marker X (across all threads)

See the "Network activity" section in "profile info": if requests are in
flight for much of the profile while threads are idle, the bottleneck may be
Expand Down
97 changes: 96 additions & 1 deletion profiler-cli/src/commands/profile.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,9 @@
*/

import type { Command } from 'commander';
import type { MarkerFilterOptions } from '../protocol';
import { parseLimitArg } from '../utils/parse';
import { addGlobalOptions, runCommand } from './shared';
import { addGlobalOptions, parseFloatArg, runCommand } from './shared';

export function registerProfileCommand(
program: Command,
Expand Down Expand Up @@ -57,6 +58,100 @@ export function registerProfileCommand(
);
});

addGlobalOptions(
profile
.command('markers')
.description(
'Search markers across all threads (same rows as `thread markers --list`, plus a thread column)'
)
.option(
'--search <term>',
'Filter markers. A bare term matches the marker name, category, payload ' +
'type and payload field values; "field:value" narrows to one field, ' +
'"-field:value" excludes, comma separates terms (OR)'
)
.option(
'--thread <handle>',
'Restrict the search to a specific thread (e.g. t-0); default is every thread'
)
.option(
'--category <name>',
'Filter by category name (case-insensitive substring match)'
)
.option(
'--min-duration <ms>',
'Filter by minimum duration in milliseconds'
)
.option(
'--max-duration <ms>',
'Filter by maximum duration in milliseconds'
)
.option('--has-stack', 'Show only markers with stack traces')
.option(
'--limit <N>',
'Limit the number of marker rows shown (max 100000; the per-thread counts stay exact)'
)
).action(async (opts) => {
const markerFilters: MarkerFilterOptions & { thread?: string } = {};

if (opts.search !== undefined) {
markerFilters.searchString = opts.search;
}
if (opts.thread !== undefined) {
markerFilters.thread = opts.thread;
}
if (opts.category !== undefined) {
markerFilters.category = opts.category;
}
if (opts.hasStack) {
markerFilters.hasStack = true;
}
if (opts.minDuration !== undefined) {
markerFilters.minDuration = parseFloatArg(
'--min-duration',
opts.minDuration,
0,
Infinity,
'Error: --min-duration must be a positive number (in milliseconds)'
);
}
if (opts.maxDuration !== undefined) {
markerFilters.maxDuration = parseFloatArg(
'--max-duration',
opts.maxDuration,
0,
Infinity,
'Error: --max-duration must be a positive number (in milliseconds)'
);
}
// Without a filter this sweeps every marker in the profile and the first
// rows are whichever markers thread 0 happened to record first, which
// answers nothing. `--limit` is an explicit opt-in to that browsing mode.
if (Object.keys(markerFilters).length === 0 && opts.limit === undefined) {
console.error(
'Error: profile markers needs a filter: --search, --category, --min-duration, --max-duration, --has-stack, or --thread.\n' +
Comment thread
fqueze marked this conversation as resolved.
'Or pass --limit <N> to browse without a filter, showing the first N rows.\n' +
'For a thread inventory use "profile info"; to browse one thread use "thread markers".'
);
process.exit(1);
}

if (opts.limit !== undefined) {
markerFilters.limit = parseLimitArg('--limit', opts.limit);
}

await runCommand(
sessionDir,
{
command: 'profile',
subcommand: 'markers',
markerFilters:
Object.keys(markerFilters).length > 0 ? markerFilters : undefined,
},
opts
);
});

const VALID_LOG_LEVELS = ['error', 'warn', 'info', 'debug', 'verbose'];

addGlobalOptions(
Expand Down
2 changes: 2 additions & 0 deletions profiler-cli/src/daemon.ts
Original file line number Diff line number Diff line change
Expand Up @@ -402,6 +402,8 @@ export class Daemon {
throw new Error('unimplemented');
case 'logs':
return this.querier.profileLogs(command.logFilters);
case 'markers':
return this.querier.profileMarkers(command.markerFilters);
default:
throw assertExhaustiveCheck(command);
}
Expand Down
90 changes: 90 additions & 0 deletions profiler-cli/src/formatters.ts
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,7 @@ import type {
FilterEntry,
SampleFilterSpec,
ProfileLogsResult,
ProfileMarkersResult,
ThreadSelectResult,
StrategySelectResult,
CallTreeSummaryStrategy,
Expand Down Expand Up @@ -2165,6 +2166,95 @@ export function formatProfileLogsResult(
return lines.join('\n');
}

/** How many threads the "Matches by thread" breakdown lists before truncating. */
const PROFILE_MARKERS_THREADS_SHOWN = 10;

/**
* Format a ProfileMarkersResult as plain text: `thread markers --list` rows
* prefixed with their thread, followed by a per-thread breakdown.
*/
export function formatProfileMarkersResult(
result: WithContext<ProfileMarkersResult>
): string {
const lines: string[] = [formatContextHeader(result.context), ''];

const isFiltered = result.filters !== undefined;
// `--limit` on its own truncates the rows but selects nothing, so the set
// below is every marker in the profile rather than a set of matches.
const { limit, ...selectingFilters } = result.filters ?? {};
const isSelected = Object.values(selectingFilters).some(
(v) => v !== undefined
);
const shown = result.markers.length;
const total = result.totalCount;

if (total === 0) {
lines.push(
isFiltered
? `No markers match the specified filters (searched ${result.searchedThreadCount} threads).`
: 'No markers found in this profile.'
);
return lines.join('\n');
}

const threadSuffix = `across ${result.matchingThreadCount} of ${result.searchedThreadCount} threads`;
if (shown < total) {
lines.push(`Showing ${shown} of ${total} markers ${threadSuffix}`);
} else {
lines.push(`${total} markers ${threadSuffix}`);
}
lines.push('Legend: ✓ = has stack trace, ✗ = no stack trace\n');

for (const m of result.markers) {
const stackIndicator = m.hasStack ? '✓' : '✗';
const startStr = `t=${formatDuration(m.start)}`;
const durationStr =
m.duration !== undefined ? formatDuration(m.duration) : 'instant';
const labelSuffix = m.label !== m.name ? ` ${m.label}` : '';
lines.push(
` ${m.threadHandle.padEnd(6)} ${m.handle.padEnd(8)} ${m.name.padEnd(30)} ${startStr.padEnd(14)} ${durationStr.padEnd(10)} ${stackIndicator}${labelSuffix}`
);
}

// With a single matching thread the breakdown only repeats the thread
// handle already on every row, so it is left out.
if (result.byThread.length > 1) {
// Nothing was "matched" unless something selected these markers, so an
// unfiltered browse gets a plain heading. Say "exact counts" whenever rows
// were capped: the counts are computed over every marker in the set, not
// over the rows above.
const heading = isSelected ? 'Matches by thread' : 'Markers by thread';
lines.push(
'',
shown < total ? `${heading} (exact counts):` : `${heading}:`
);
for (const t of result.byThread.slice(0, PROFILE_MARKERS_THREADS_SHOWN)) {
const who = `${t.threadName} (${t.processName}, pid ${t.pid})`;
lines.push(
` ${t.threadHandle.padEnd(6)} ${who.padEnd(50)} ${t.count}`
);
}
const omitted = result.byThread.length - PROFILE_MARKERS_THREADS_SHOWN;
if (omitted > 0) {
lines.push(
` ... and ${omitted} more ${omitted === 1 ? 'thread' : 'threads'}; --json lists them all`
);
}
}

lines.push('');
if (result.maxRowsClamped !== undefined) {
lines.push(
`Rows were capped at ${result.maxRowsClamped}, the most this command can return; the counts above are exact. Narrow with --search/--thread.`
);
}
lines.push(
'Use --thread <handle> to restrict the sweep, or "marker info m-<N>" to inspect one marker.'
);

return lines.join('\n');
}

export function formatThreadPageLoadResult(
result: WithContext<ThreadPageLoadResult>
): string {
Expand Down
1 change: 1 addition & 0 deletions profiler-cli/src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -89,6 +89,7 @@ Examples:
profiler-cli thread samples
profiler-cli thread functions --search GC --min-self 1
profiler-cli thread markers --search DOMEvent --category Graphics
profiler-cli profile markers --search CompositorScreenshot
profiler-cli counter list
profiler-cli counter info c-0
profiler-cli zoom push 2.7,3.1
Expand Down
3 changes: 3 additions & 0 deletions profiler-cli/src/output.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@ import {
formatThreadFunctionsResult,
formatThreadNetworkResult,
formatProfileLogsResult,
formatProfileMarkersResult,
formatThreadPageLoadResult,
formatThreadSelectResult,
formatStrategySelectResult,
Expand Down Expand Up @@ -98,6 +99,8 @@ export function formatOutput(
return formatThreadNetworkResult(result);
case 'profile-logs':
return formatProfileLogsResult(result);
case 'profile-markers':
return formatProfileMarkersResult(result);
case 'thread-page-load':
return formatThreadPageLoadResult(result);
case 'thread-select':
Expand Down
10 changes: 10 additions & 0 deletions profiler-cli/src/protocol.ts
Original file line number Diff line number Diff line change
Expand Up @@ -68,6 +68,9 @@ export type {
ProfileInfoResult,
ProfileMetaResult,
ProfileLogsResult,
ProfileMarkersResult,
ProfileMarkerItem,
ProfileMarkersThreadBreakdown,
ThreadSelectResult,
CounterSummary,
CounterListResult,
Expand Down Expand Up @@ -111,6 +114,7 @@ import type {
ThreadPageLoadResult,
FilterStackResult,
ProfileLogsResult,
ProfileMarkersResult,
ThreadSelectResult,
CounterListResult,
CounterInfoResult,
Expand All @@ -135,6 +139,11 @@ export type ClientCommand =
command: 'profile';
subcommand: 'meta';
}
| {
command: 'profile';
subcommand: 'markers';
markerFilters?: MarkerFilterOptions & { thread?: string };
}
| {
command: 'profile';
subcommand: 'logs';
Expand Down Expand Up @@ -261,6 +270,7 @@ export type CommandResult =
| WithContext<ThreadNetworkResult>
| WithContext<FunctionAnnotateResult>
| WithContext<ProfileLogsResult>
| WithContext<ProfileMarkersResult>
| WithContext<ThreadPageLoadResult>
| WithContext<ThreadSelectResult>
| WithContext<StrategySelectResult>
Expand Down
20 changes: 20 additions & 0 deletions profiler-cli/src/test/integration/basic.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -644,6 +644,26 @@ describe('profiler-cli basic functionality', () => {
expect(samples.callTreeSummaryStrategy).toBe('native-deallocations-sites');
});

it('profile markers requires a filter, but --limit opts into browsing', async () => {
await cli(ctx, ['load', 'src/test/fixtures/upgrades/processed-1.json']);

// An unfiltered sweep would dump arbitrary rows in profile order, which
// answers no question; the error has to name the flags that do.
const bare = await cliFail(ctx, ['profile', 'markers']);
expect(bare.exitCode).not.toBe(0);
const output = String(bare.stdout || '') + String(bare.stderr || '');
expect(output).toContain('profile markers needs a filter');
expect(output).toContain('--search');

// A filter satisfies it...
const filtered = await cli(ctx, ['profile', 'markers', '--search', 'a']);
expect(filtered.exitCode).toBe(0);

// ...and so does an explicit --limit, the opt-in to unfiltered browsing.
const limited = await cli(ctx, ['profile', 'markers', '--limit', '5']);
expect(limited.exitCode).toBe(0);
});

it('build hash mismatch stops the daemon before cleaning up the session', async () => {
const loadResult = await cli(ctx, [
'load',
Expand Down
Loading
Loading