Skip to content

Commit b348f63

Browse files
committed
feat: parse xcode build log via xcresulttool for per-subsection spans
Replaces the -showBuildTimingSummary approach: that flag is documented but produces no output on Xcode 26 (and presumably 16+), so parsing xcodebuild stdout for a "** Build Timing Summary **" block silently yielded nothing on modern Xcode. Switches to xcresulttool, which Flutter already points at via -resultBundlePath. After xcodebuild finishes, we run xcrun xcresulttool get log --type build --path <bundle> and walk the top-level subsections. Each subsection (one per target build action — "Build target X from project Y", "Archive target Z", etc.) has a real startTime + duration, so events land on an accurate timeline instead of synthetic sequential spans. Emitted on tid=4 with cat='xcode_subsection'. Subsection titles are kept in the raw trace for local debug; Shorebird's privacy-safe summary only records count + sum + p50/p90/max, no titles. Best-effort: xcresulttool's JSON schema drifts across Xcode versions, so parse failures are silent no-ops rather than errors. Also revert the -quiet skip: it's no longer needed now that we don't depend on xcodebuild stdout for timing data.
1 parent 0c03c2c commit b348f63

1 file changed

Lines changed: 72 additions & 85 deletions

File tree

  • packages/flutter_tools/lib/src/ios

packages/flutter_tools/lib/src/ios/mac.dart

Lines changed: 72 additions & 85 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
// found in the LICENSE file.
44

55
import 'dart:async';
6+
import 'dart:convert';
67

78
import 'package:meta/meta.dart';
89
import 'package:process/process.dart';
@@ -386,12 +387,6 @@ Future<XcodeBuildResult> buildXcodeProject({
386387
'shorebird_assemble_trace.json',
387388
);
388389
buildCommands.add('SHOREBIRD_TRACE_FILE=$assembleTraceFilePath');
389-
// Ask xcodebuild to print a per-phase timing summary at the end of the
390-
// build ("** Build Timing Summary **"). Shorebird parses this out of
391-
// the build log and turns it into trace events so the otherwise-opaque
392-
// `xcode archive` span isn't a black box. xcodebuild docs describe it
393-
// as a reporting-only flag with no effect on what's built.
394-
buildCommands.add('-showBuildTimingSummary');
395390
} else {
396391
assembleTraceFilePath = null;
397392
}
@@ -400,11 +395,8 @@ Future<XcodeBuildResult> buildXcodeProject({
400395
// An environment variable to be passed to xcode_backend.sh determining
401396
// whether to echo back executed commands.
402397
buildCommands.add('VERBOSE_SCRIPT_LOGGING=YES');
403-
} else if (buildInfo.shorebirdTraceFilePath == null) {
398+
} else {
404399
// This will print warnings and errors only.
405-
// Skipped when the Shorebird build trace is active because `-quiet`
406-
// also suppresses the `** Build Timing Summary **` block we parse to
407-
// produce per-phase Xcode spans.
408400
buildCommands.add('-quiet');
409401
}
410402

@@ -621,30 +613,16 @@ Future<XcodeBuildResult> buildXcodeProject({
621613
startMicros: xcodeStartMicros,
622614
endMicros: xcodeEndMicros,
623615
);
624-
// Parse the per-phase breakdown from `-showBuildTimingSummary` and
625-
// emit one event per phase on tid=4 so the single "xcode archive"
626-
// span isn't a black box. Events are synthetic (we only know
627-
// aggregate durations per phase, not wall-clock start/end), so we
628-
// lay them out sequentially back from xcodeEndMicros — that keeps
629-
// the sum accurate and preserves the relative distribution even if
630-
// individual spans don't line up with real wall clock inside Xcode.
631-
final String? buildStdout = buildResult?.stdout;
632-
if (buildStdout != null) {
633-
final List<_XcodePhaseTiming> phases =
634-
_parseXcodeBuildTimingSummary(buildStdout);
635-
var cursor = xcodeEndMicros;
636-
for (final _XcodePhaseTiming phase in phases.reversed) {
637-
tracer.addCompleteEvent(
638-
name: phase.name,
639-
cat: 'xcode_phase',
640-
tid: 4,
641-
startMicros: cursor - phase.durationMicros,
642-
endMicros: cursor,
643-
args: <String, Object?>{'taskCount': phase.taskCount},
644-
);
645-
cursor -= phase.durationMicros;
646-
}
647-
}
616+
// Break the monolithic "xcode archive" span into per-subsection
617+
// events by asking xcresulttool for the structured build log. Each
618+
// top-level subsection ("Build target X", "Archive target Y",
619+
// "Compile Swift module Z", ...) has a real wall-clock startTime
620+
// and duration, so events land on an accurate timeline inside the
621+
// xcode outer span.
622+
await _emitXcodeSubsectionEvents(
623+
tracer: tracer,
624+
resultBundleDirectory: resultBundleDirectory,
625+
);
648626
// Merge the assemble trace file that flutter assemble wrote.
649627
if (assembleTraceFilePath != null) {
650628
final File assembleTraceFile = globals.fs.file(assembleTraceFilePath);
@@ -1461,59 +1439,68 @@ class _XCResultIssueHandlingResult {
14611439
const _kResultBundlePath = 'temporary_xcresult_bundle';
14621440
const _kResultBundleVersion = '3';
14631441

1464-
/// A single phase from xcodebuild's `** Build Timing Summary **` section.
1465-
/// Shorebird-specific.
1466-
class _XcodePhaseTiming {
1467-
_XcodePhaseTiming({
1468-
required this.name,
1469-
required this.taskCount,
1470-
required this.durationMicros,
1471-
});
1442+
/// Ask xcresulttool for the structured build log of the archive action
1443+
/// and emit one Chrome Trace Event per top-level subsection (each Xcode
1444+
/// "target" build). Best-effort: silently returns if the bundle can't be
1445+
/// parsed (xcresulttool output format drifts across Xcode versions).
1446+
Future<void> _emitXcodeSubsectionEvents({
1447+
required BuildTracer tracer,
1448+
required Directory resultBundleDirectory,
1449+
}) async {
1450+
if (!resultBundleDirectory.existsSync()) {
1451+
return;
1452+
}
1453+
final ProcessResult result;
1454+
try {
1455+
result = await globals.processManager.run(<String>[
1456+
'xcrun',
1457+
'xcresulttool',
1458+
'get',
1459+
'log',
1460+
'--type',
1461+
'build',
1462+
'--path',
1463+
resultBundleDirectory.path,
1464+
]);
1465+
} on Exception {
1466+
return;
1467+
}
1468+
if (result.exitCode != 0) {
1469+
return;
1470+
}
14721471

1473-
final String name;
1474-
final int taskCount;
1475-
final int durationMicros;
1476-
}
1472+
final Object? decoded;
1473+
try {
1474+
decoded = json.decode(result.stdout as String);
1475+
} on FormatException {
1476+
return;
1477+
}
1478+
if (decoded is! Map<String, Object?>) {
1479+
return;
1480+
}
14771481

1478-
/// Parses the `** Build Timing Summary **` block xcodebuild prints when
1479-
/// invoked with `-showBuildTimingSummary`.
1480-
///
1481-
/// Format (observed on Xcode 15/16, stable since the option was added in
1482-
/// Xcode 10):
1483-
///
1484-
/// ```text
1485-
/// ** Build Timing Summary **
1486-
///
1487-
/// CompileC (123 tasks) | 45.678 seconds
1488-
/// SwiftCompile (89 tasks) | 34.567 seconds
1489-
/// Ld (4 tasks) | 12.345 seconds
1490-
/// PhaseScriptExecution (5 tasks) | 8.901 seconds
1491-
/// CodeSign (12 tasks) | 3.456 seconds
1492-
/// ```
1493-
///
1494-
/// Returns phases in the order they appear (longest to shortest in
1495-
/// practice). Returns an empty list if the section isn't found.
1496-
List<_XcodePhaseTiming> _parseXcodeBuildTimingSummary(String stdout) {
1497-
final int headerIdx = stdout.indexOf('Build Timing Summary');
1498-
if (headerIdx < 0) {
1499-
return const <_XcodePhaseTiming>[];
1482+
final Object? subsections = decoded['subsections'];
1483+
if (subsections is! List) {
1484+
return;
15001485
}
1501-
final String tail = stdout.substring(headerIdx);
1502-
// Each entry: `<Phase> (<N> tasks?) | <D> seconds`
1503-
final line = RegExp(
1504-
r'^\s*([A-Za-z][A-Za-z0-9_]*)\s*\((\d+)\s*tasks?\)\s*\|\s*([0-9]+(?:\.[0-9]+)?)\s*seconds?\s*$',
1505-
multiLine: true,
1506-
);
1507-
final out = <_XcodePhaseTiming>[];
1508-
for (final RegExpMatch m in line.allMatches(tail)) {
1509-
final String name = m.group(1)!;
1510-
final int taskCount = int.parse(m.group(2)!);
1511-
final double seconds = double.parse(m.group(3)!);
1512-
out.add(_XcodePhaseTiming(
1513-
name: name,
1514-
taskCount: taskCount,
1515-
durationMicros: (seconds * 1000000).round(),
1516-
));
1486+
for (final Object? sub in subsections) {
1487+
if (sub is! Map<String, Object?>) {
1488+
continue;
1489+
}
1490+
final String title = (sub['title'] as String?) ?? '';
1491+
final double? startTime = (sub['startTime'] as num?)?.toDouble();
1492+
final double? duration = (sub['duration'] as num?)?.toDouble();
1493+
if (startTime == null || duration == null || duration <= 0) {
1494+
continue;
1495+
}
1496+
final int startMicros = (startTime * 1000000).round();
1497+
final int endMicros = ((startTime + duration) * 1000000).round();
1498+
tracer.addCompleteEvent(
1499+
name: title,
1500+
cat: 'xcode_subsection',
1501+
tid: 4,
1502+
startMicros: startMicros,
1503+
endMicros: endMicros,
1504+
);
15171505
}
1518-
return out;
15191506
}

0 commit comments

Comments
 (0)