[Pitch] SwiftPM Build Performance Debugging Options

Evolution Pitches
,
1

Hello,

I wanted to share a brief pitch to add two new flags to SwiftPM for understanding build performance of packages. These are tools which are currently available in nightly snapshots in hidden/experimental form and used to analyze build perf when working on SwiftPM. However, I think they can be quite useful for users of SwiftPM who want to optimize build perf of their own packages as well, so I'm proposing upgrading them to stable, officially supported options. Looking forward to your feedback!

  • Owen

SwiftPM Build Performance Debugging Options

  • Proposal: SE-NNNN
  • Authors: Owen Voorhees
  • Implementation: Nightly snapshot toolchains via experimental flags --experimental-trace-events-file and --experimental-task-backtraces

Introduction

This proposal introduces two new SwiftPM CLI options, --trace-events-file and --enable-task-backtraces, which can be used to analyze the performance of clean and incremental builds and identify common issues.

Motivation

Build performance is an important component of developer productivity. Clean build performance is largely determined by how much work is required to build a package and how effectively that work can be parallelized, while incremental build performance also depends on how much of a build is invalidated by a particular incremental change. When analyzing build performance of a package, it's sometimes difficult to determine how build tools and package configuration influence these factors and where there are opportunities to make improvements. This proposal introduces new command line options which give users greater insight into build performance so that they can make more informed decisions when optimizing build times or debugging build performance issues.

Proposed solution

This proposal introduces two new flags which may be passed to any SwiftPM subcommand which runs a build:

  • --trace-events-file: When passed with a path argument, will cause a JSON file to be emitted using the Trace Event Format which describes the timing of tasks run as part of the current build. This file can be viewed using a performance analysis tool like Perfetto, speedscope, or about://tracing in Chrome.
  • --enable-task-backtraces: When passed, will cause the build log to include a 'task backtrace' for each task which describes the sequence of events which caused it to run as part of the current build.

Detailed design

--trace-events-file

--trace-events-file <trace-path> may be passed to any SwiftPM subcommand which runs a build, including swift build, swift test, and swift-run. When passed, SwiftPM will emit a file at <trace-path> using the Trace Event Format which includes command line, timing, and (optionally) backtrace information for each task run during the build. If an existing file exists at <trace-path>, it will be overwritten when the build starts.

The Trace Event Format is a JSON-based format for compiling performance data. It's supported by a variety of producers (clang, Bazel) and consumers (Perfetto, speedscope, Chrome about://tracing), making it a good candidate for adoption by SwiftPM.

Here's an example of a trace emitted when building SwiftPM itself, visualized using Perfetto:

NNNN-build-debugging-options-trace-example
NNNN-build-debugging-options-trace-example1400×543 277 KB

This type of visualization can be very helpful when optimizing a clean build to improve parallelism, identifying expensive work on the critical path, or identifying the full set of tasks running in an incremental build after making a particular change.

--enable-task-backtraces

Visualizing the trace of a build can be used to identify which tasks ran in an incremental build, but it's not always easy to identify why those tasks needed to run. Task backtraces help answer this question by enumerating the sequence of steps which led a task to be invalidated and re-run.

Task backtraces are enabled by passing --enable-task-backtraces to any SwiftPM subcommand which runs a build. This flag must be paired with either --trace-events-file to include the backtrace information in the build trace, --verbose/--very-verbose to include it in the build output, or both. Task backtraces are provided as an opt-in feature intended to be used primarily when debugging incremental builds, as they have a small but measurable impact on overall build performance.

Here's an example of a backtrace from an incremental build of SwiftPM itself, describing why the swift-build executable was re-linked in an incremental build after making a change to URL.swift in the Basics module of the package:

#0: an input of 'Link swift-build (arm64)' changed
#1: the task producing file '.../swiftpm/.build/out/Products/Debug/Basics.o' ran
#2: an input of 'Link Basics.o (arm64)' changed
#3: the task producing file '.../swiftpm/.build/out/Intermediates.noindex/SwiftPM.build/Debug/Basics-t.build/Objects-normal/arm64/URL.o' ran
#4: an input of 'Compile Basics (arm64)' changed
#5: file '.../swiftpm/Sources/Basics/URL.swift' changed

The first line of the backtrace describes the most immediate reason the link task needed to run: one of its inputs had changed. From there, the backtrace can be read top to bottom to understand the full chain of events which connect this change to the original change, the user-initated modification to URL.swift. In this case, the change to URL.swift meant it needed to be recompiled, which in turn invalidated the corresponding object file, which in turn invalidated the link of the Basics target, which in turn invalidated the link of the final executable.

In addition to diagnosing changes in input files, task backtraces could also indicate a task needed to run in an incremental build because:

  • Its arguments, working directory, or environment changed
  • One of its outputs was deleted or otherwise modified outside the build
  • The previous build failed or was cancelled before the task ran

The specific formatting of task backtraces is implementation defined to allow flexibility for future improvements which provide more specific information.

Security

This change has no meaningful security impact. It emits additional information during builds which is either not sensitive (timing information) or already present in verbose logging (builder file paths in backtraces).

Impact on existing packages

There is no impact on the build of existing packages, the new logging is opt in and does not change the behavior of the build itself.

Alternatives considered

Design a new build trace format

Instead of adopting the existing Trace Event Format, one could argue we should consider designing a new format from scratch for SwiftPM build traces. This might make it easier to represent SwiftPM/Swift-specific concepts more accurately. However, in practice, the existing format does a good job of representing build task timing information, and its freeform arguments fields allow it to support features like task backtrace information in a natural way. Furthermore, adopting a well-established format has a number of interoperability advantages. Users have a number of choices for visualizing traces, and it enables interesting future directions like merging Clang -ftime-trace output with a SwiftPM trace to get a combined trace of high-level build and granular compile performance.

10 Likes
2

This would be great, any insight into build performance would be appreciated. I do have a tangential question, is there any way to break the batch build steps into any timing information per file? The fact that the batch steps get nothing more than overall time makes it very hard to find slow building file.

1 Like
3

The -trace-stats-events flag exists on the compiler side that outputs a CSV file with very detailed timing information about the frontend invocations used to compile individual files, like every type checker request, SIL function generation, optimization, etc.

It's not something you can directly drop into the Perfetto UI like the proposed Trace Events JSON file, though (but it's a lot more compact, by an order of magnitude typically). It would be fairly trivial to hook into the existing Swift stats reporting and use LLVM's tracing logic that powers Clang's -ftime-trace to produce the same JSON files for Swift compiles.

@owenv, is that something you're also looking into, to complete the performance picture?

4

Tangential thought: I have no insight into the plans here, but I did notice this outstanding open PR from not too long ago that looks like it aims to support something like -ftime-trace in the frontend.

1 Like
5

Not really. Batch mode amortizes parsing and some type checking costs across all files in the batch, so it's not possible to attribute all time spent to a single file. -Xswiftc --disable-batch-mode can be used to force the driver to use a separate frontend job for every file which can be used to see their relative cost, but will generally slow down the build overall.

@owenv, is that something you're also looking into, to complete the performance picture?

Tangential thought: I have no insight into the plans here, but I did notice this outstanding open PR from not too long ago that looks like it aims to support something like -ftime-trace in the frontend.

Yeah, this PR from @Max_Desiatov hooks swiftc's tracing up to the same format. With that, we can try merging clang, swift, and build system trace data into a unified visualization. I think this will be very useful for tools development and allowing us to better target compiler/build system perf efforts. However, the compiler tracing often requires more familiarity with the compiler codebase to interpret, so I think it would need some kind of additional opt-in as a future direction.

2 Likes
6

I've also now opened a complete proposal PR (the content is largely the same as the original pitch): Add proposal: SwiftPM build performance debugging options by owenv · Pull Request #3341 · swiftlang/swift-evolution · GitHub

7

I support moving this to stable! I've been thinking about package build perf recently and how it's affected by dependency depth and the stability of upstream packages. Having these additional visuals will make it much easier to help others understand performance gotchas.

8

@owenv I read the proposal and overall I am in favor of adding these options. I have a few questions:

  1. There are commands that run a build as an implementation detail such as swift package command-plugin-name or swift package diagnose-api-breaking-changes, the latter actually runs two builds. Will those also support the options?
  2. Could we have an example of how this works with build plugins and how they are modeled in the graph? Are they separate graphs or part of one unified graph?
  3. Can we align the flag names better e.g. --enable-build-system-tracing and --build-system-tracing-file? Right now they are misaligned one contains task backtraces and the other trace events.
9

Yes, any command which runs a build should be able to emit a trace.

The build of tools used by plugins, and the invocations of the tools are all part of the same unified build graph now, so appear the same as any other task in a trace.

I don't think this necessarily makes sense because while the features can be enabled together to produce a trace which includes task backtrace information, they can also be used independently of each other to, for example, emit task backtraces to the build log without emitting a trace events file

1 Like
10

I wasn't sure where to look for the implementation -- I wanted to check in if you've considered on the implementation side to instrument the build system using swift-distributed-tracing and then use a backend that would produce the format you're interested in exporting?

I mostly advertise it because of convenience of instrumenting async structured concurrency systems and that it's pretty flexible so I think you could reuse that infra rather easily if you wanted to. Though you'd still need to plug in your data format etc.

Just an open question / hint; the general output looks great and I hope we can make use of that soon :slight_smile: I could definitely see others wanting to use the same trace format so if we're doing this once might as well help others to benefit from that by making a Tracer impl handling the Trace Event Format "once"?

3 Likes
11

The implementation avoids swift-distributed-tracing because it would involve pulling both it and swift-service context into the set of packages which need to be bootstrapped with CMake

12

In my opinion, that's not a strong reason for avoiding the dependency if we believe swift-distributed-tracing to be the ecosystem wide tracing interface for Swift (which I personally do) then we should overcome that CMake bootstrapping setup. It does bring a lot of benefits if we can unify behind those APIs such as allowing configuration of different backends like OTEL unlocking an entire ecosystem of trace observability tools.

FWIW, I don't think this should block this proposal but I personally see a lot of value in technically using swift-distributed-tracing.

2 Likes
13

I agree, I would actually like to start using swift-log and swift-distributed-tracing in Swift Build at some point and think we should just do the CMake work to make that possible.

1 Like
14

The implementation avoids swift-distributed-tracing because it would involve pulling both it and swift-service context into the set of packages which need to be bootstrapped with CMake

For what it's worth these are absolutely fundamental packages and we ought to promote them as part of the Swift project eventually. I'm, and others maintaining those packages, would be more than happy to resolve any bootstrapping issues you may be seeing there -- would it be sufficient to just add CMake builds there? I'm happy to do that anytime.

I do agree this is no reason to block this proposal from landing, but let's figure out a way to make use of the core API libraries in the near future :+1:

Probably the right time to revisit this will be if and when we'd argue for inclusion of those API packages in the Swift project itself.

2 Likes