Copy soong_build metrics into build.trace.gz

Make soong_ui read soong_build_metrics.bp to extract the event timings
and propagate them to Tracer, which will put them in build.trace.gz.
This provides much better visibility into what parts of the build are
contributing to the overly large analysis time.

Test: m nothing and examine build.trace.gz
Change-Id: I473727f1ec044b0d973f2cb4e3eaca96bfca94f6

ui/build/soong.go

@@ -23,9 +23,11 @@ import (
 	"strings"
 	"sync"
 	"sync/atomic"
+	"time"
 
 	"android/soong/bazel"
 	"android/soong/ui/metrics"
+	"android/soong/ui/metrics/metrics_proto"
 	"android/soong/ui/status"
 
 	"android/soong/shared"
@@ -33,6 +35,8 @@ import (
 	"github.com/google/blueprint"
 	"github.com/google/blueprint/bootstrap"
 	"github.com/google/blueprint/microfactory"
+
+	"google.golang.org/protobuf/proto"
 )
 
 const (
@@ -717,8 +721,12 @@ func runSoong(ctx Context, config Config) {
 		targets = append(targets, config.SoongNinjaFile())
 	}
 
+	beforeSoongTimestamp := time.Now()
+
 	ninja(targets...)
 
+	loadSoongBuildMetrics(ctx, config, beforeSoongTimestamp)
+
 	distGzipFile(ctx, config, config.SoongNinjaFile(), "soong")
 	distFile(ctx, config, config.SoongVarsFile(), "soong")
 
@@ -732,6 +740,42 @@ func runSoong(ctx Context, config Config) {
 	}
 }
 
+// loadSoongBuildMetrics reads out/soong_build_metrics.pb if it was generated by soong_build and copies the
+// events stored in it into the soong_ui trace to provide introspection into how long the different phases of
+// soong_build are taking.
+func loadSoongBuildMetrics(ctx Context, config Config, oldTimestamp time.Time) {
+	soongBuildMetricsFile := config.SoongBuildMetrics()
+	if metricsStat, err := os.Stat(soongBuildMetricsFile); err != nil {
+		ctx.Verbosef("Failed to stat %s: %s", soongBuildMetricsFile, err)
+		return
+	} else if !metricsStat.ModTime().After(oldTimestamp) {
+		ctx.Verbosef("%s timestamp not later after running soong, expected %s > %s",
+			soongBuildMetricsFile, metricsStat.ModTime(), oldTimestamp)
+		return
+	}
+
+	metricsData, err := os.ReadFile(config.SoongBuildMetrics())
+	if err != nil {
+		ctx.Verbosef("Failed to read %s: %s", soongBuildMetricsFile, err)
+		return
+	}
+
+	soongBuildMetrics := metrics_proto.SoongBuildMetrics{}
+	err = proto.Unmarshal(metricsData, &soongBuildMetrics)
+	if err != nil {
+		ctx.Verbosef("Failed to unmarshal %s: %s", soongBuildMetricsFile, err)
+		return
+	}
+	for _, event := range soongBuildMetrics.Events {
+		desc := event.GetDescription()
+		if dot := strings.LastIndexByte(desc, '.'); dot >= 0 {
+			desc = desc[dot+1:]
+		}
+		ctx.Tracer.Complete(desc, ctx.Thread,
+			event.GetStartTime(), event.GetStartTime()+event.GetRealTime())
+	}
+}
+
 func runMicrofactory(ctx Context, config Config, name string, pkg string, mapping map[string]string) {
 	ctx.BeginTrace(metrics.RunSoong, name)
 	defer ctx.EndTrace()