Write bazel metrics file from soong.
Test: b build libcore:all
Change-Id: I372d48a9c7132bc57ecc1a8ba06eb098d28cbad7
diff --git a/ui/build/upload.go b/ui/build/upload.go
index 9f14bdd..9959e6f 100644
--- a/ui/build/upload.go
+++ b/ui/build/upload.go
@@ -18,16 +18,21 @@
// another.
import (
+ "bufio"
"fmt"
"io/ioutil"
"os"
"path/filepath"
+ "strconv"
+ "strings"
"time"
+ "android/soong/shared"
"android/soong/ui/metrics"
"google.golang.org/protobuf/proto"
+ bazel_metrics_proto "android/soong/ui/metrics/bazel_metrics_proto"
upload_proto "android/soong/ui/metrics/upload_proto"
)
@@ -73,12 +78,113 @@
return metricsFiles
}
+func parseTimingToNanos(str string) int64 {
+ millisString := removeDecimalPoint(str)
+ timingMillis, _ := strconv.ParseInt(millisString, 10, 64)
+ return timingMillis * 1000000
+}
+
+func parsePercentageToTenThousandths(str string) int32 {
+ percentageString := removeDecimalPoint(str)
+ //remove the % at the end of the string
+ percentage := strings.ReplaceAll(percentageString, "%", "")
+ percentagePortion, _ := strconv.ParseInt(percentage, 10, 32)
+ return int32(percentagePortion)
+}
+
+func removeDecimalPoint(numString string) string {
+ // The format is always 0.425 or 10.425
+ return strings.ReplaceAll(numString, ".", "")
+}
+
+func parseTotal(line string) int64 {
+ words := strings.Fields(line)
+ timing := words[3]
+ return parseTimingToNanos(timing)
+}
+
+func parsePhaseTiming(line string) bazel_metrics_proto.PhaseTiming {
+ words := strings.Fields(line)
+ getPhaseNameAndTimingAndPercentage := func([]string) (string, int64, int32) {
+ // Sample lines include:
+ // Total launch phase time 0.011 s 2.59%
+ // Total target pattern evaluation phase time 0.011 s 2.59%
+ var beginning int
+ var end int
+ for ind, word := range words {
+ if word == "Total" {
+ beginning = ind + 1
+ } else if beginning > 0 && word == "phase" {
+ end = ind
+ break
+ }
+ }
+ phaseName := strings.Join(words[beginning:end], " ")
+
+ // end is now "phase" - advance by 2 for timing and 4 for percentage
+ percentageString := words[end+4]
+ timingString := words[end+2]
+ timing := parseTimingToNanos(timingString)
+ percentagePortion := parsePercentageToTenThousandths(percentageString)
+ return phaseName, timing, percentagePortion
+ }
+
+ phaseName, timing, portion := getPhaseNameAndTimingAndPercentage(words)
+ phaseTiming := bazel_metrics_proto.PhaseTiming{}
+ phaseTiming.DurationNanos = &timing
+ phaseTiming.PortionOfBuildTime = &portion
+
+ phaseTiming.PhaseName = &phaseName
+ return phaseTiming
+}
+
+func processBazelMetrics(bazelProfileFile string, bazelMetricsFile string, ctx Context) {
+ if bazelProfileFile == "" {
+ return
+ }
+
+ readBazelProto := func(filepath string) bazel_metrics_proto.BazelMetrics {
+ //serialize the proto, write it
+ bazelMetrics := bazel_metrics_proto.BazelMetrics{}
+
+ file, err := os.ReadFile(filepath)
+ if err != nil {
+ ctx.Fatalln("Error reading metrics file\n", err)
+ }
+
+ scanner := bufio.NewScanner(strings.NewReader(string(file)))
+ scanner.Split(bufio.ScanLines)
+
+ var phaseTimings []*bazel_metrics_proto.PhaseTiming
+ for scanner.Scan() {
+ line := scanner.Text()
+ if strings.HasPrefix(line, "Total run time") {
+ total := parseTotal(line)
+ bazelMetrics.Total = &total
+ } else if strings.HasPrefix(line, "Total") {
+ phaseTiming := parsePhaseTiming(line)
+ phaseTimings = append(phaseTimings, &phaseTiming)
+ }
+ }
+ bazelMetrics.PhaseTimings = phaseTimings
+
+ return bazelMetrics
+ }
+
+ if _, err := os.Stat(bazelProfileFile); err != nil {
+ // We can assume bazel didn't run if the profile doesn't exist
+ return
+ }
+ bazelProto := readBazelProto(bazelProfileFile)
+ shared.Save(&bazelProto, bazelMetricsFile)
+}
+
// UploadMetrics uploads a set of metrics files to a server for analysis.
// The metrics files are first copied to a temporary directory
// and the uploader is then executed in the background to allow the user/system
// to continue working. Soong communicates to the uploader through the
// upload_proto raw protobuf file.
-func UploadMetrics(ctx Context, config Config, simpleOutput bool, buildStarted time.Time, paths ...string) {
+func UploadMetrics(ctx Context, config Config, simpleOutput bool, buildStarted time.Time, bazelProfileFile string, bazelMetricsFile string, paths ...string) {
ctx.BeginTrace(metrics.RunSetupTool, "upload_metrics")
defer ctx.EndTrace()
@@ -88,6 +194,7 @@
return
}
+ processBazelMetrics(bazelProfileFile, bazelMetricsFile, ctx)
// Several of the files might be directories.
metricsFiles := pruneMetricsFiles(paths)
if len(metricsFiles) == 0 {
diff --git a/ui/build/upload_test.go b/ui/build/upload_test.go
index 764a1e1..58d9237 100644
--- a/ui/build/upload_test.go
+++ b/ui/build/upload_test.go
@@ -29,6 +29,30 @@
"android/soong/ui/logger"
)
+func writeBazelProfileFile(dir string) error {
+ contents := `
+
+=== PHASE SUMMARY INFORMATION ===
+
+Total launch phase time 1.193 s 15.77%
+Total init phase time 1.092 s 14.44%
+Total target pattern evaluation phase time 0.580 s 7.67%
+Total interleaved loading-and-analysis phase time 3.646 s 48.21%
+Total preparation phase time 0.022 s 0.30%
+Total execution phase time 0.993 s 13.13%
+Total finish phase time 0.036 s 0.48%
+---------------------------------------------------------------------
+Total run time 7.563 s 100.00%
+
+Critical path (178 ms):
+ Time Percentage Description
+ 178 ms 100.00% action 'BazelWorkspaceStatusAction stable-status.txt'
+
+`
+ file := filepath.Join(dir, "bazel_metrics.txt")
+ return os.WriteFile(file, []byte(contents), 0666)
+}
+
func TestPruneMetricsFiles(t *testing.T) {
rootDir := t.TempDir()
@@ -84,12 +108,12 @@
}, {
description: "non-existent metrics files no upload",
uploader: "echo",
- files: []string{"metrics_file_1", "metrics_file_2", "metrics_file_3"},
+ files: []string{"metrics_file_1", "metrics_file_2", "metrics_file_3, bazel_metrics.pb"},
}, {
description: "trigger upload",
uploader: "echo",
createFiles: true,
- files: []string{"metrics_file_1", "metrics_file_2"},
+ files: []string{"metrics_file_1", "metrics_file_2, bazel_metrics.pb"},
}}
for _, tt := range tests {
@@ -130,6 +154,9 @@
}
}
}
+ if err := writeBazelProfileFile(outDir); err != nil {
+ t.Fatalf("failed to create bazel profile file in dir: %v", outDir)
+ }
config := Config{&configImpl{
environ: &Environment{
@@ -139,7 +166,7 @@
metricsUploader: tt.uploader,
}}
- UploadMetrics(ctx, config, false, time.Now(), metricsFiles...)
+ UploadMetrics(ctx, config, false, time.Now(), "out/bazel_metrics.txt", "out/bazel_metrics.pb", metricsFiles...)
})
}
}
@@ -194,8 +221,79 @@
metricsUploader: "echo",
}}
- UploadMetrics(ctx, config, true, time.Now(), metricsFile)
+ UploadMetrics(ctx, config, true, time.Now(), "", "", metricsFile)
t.Errorf("got nil, expecting %q as a failure", tt.expectedErr)
})
}
}
+
+func TestParsePercentageToTenThousandths(t *testing.T) {
+ // 2.59% should be returned as 259 - representing 259/10000 of the build
+ percentage := parsePercentageToTenThousandths("2.59%")
+ if percentage != 259 {
+ t.Errorf("Expected percentage to be returned as ten-thousandths. Expected 259, have %d\n", percentage)
+ }
+
+ // Test without a leading digit
+ percentage = parsePercentageToTenThousandths(".52%")
+ if percentage != 52 {
+ t.Errorf("Expected percentage to be returned as ten-thousandths. Expected 52, have %d\n", percentage)
+ }
+}
+
+func TestParseTimingToNanos(t *testing.T) {
+ // This parses from seconds (with millis precision) and returns nanos
+ timingNanos := parseTimingToNanos("0.111")
+ if timingNanos != 111000000 {
+ t.Errorf("Error parsing timing. Expected 111000, have %d\n", timingNanos)
+ }
+
+ // Test without a leading digit
+ timingNanos = parseTimingToNanos(".112")
+ if timingNanos != 112000000 {
+ t.Errorf("Error parsing timing. Expected 112000, have %d\n", timingNanos)
+ }
+}
+
+func TestParsePhaseTiming(t *testing.T) {
+ // Sample lines include:
+ // Total launch phase time 0.011 s 2.59%
+ // Total target pattern evaluation phase time 0.012 s 4.59%
+
+ line1 := "Total launch phase time 0.011 s 2.59%"
+ timing := parsePhaseTiming(line1)
+
+ if timing.GetPhaseName() != "launch" {
+ t.Errorf("Failed to parse phase name. Expected launch, have %s\n", timing.GetPhaseName())
+ } else if timing.GetDurationNanos() != 11000000 {
+ t.Errorf("Failed to parse duration nanos. Expected 11000000, have %d\n", timing.GetDurationNanos())
+ } else if timing.GetPortionOfBuildTime() != 259 {
+ t.Errorf("Failed to parse portion of build time. Expected 259, have %d\n", timing.GetPortionOfBuildTime())
+ }
+
+ // Test with a multiword phase name
+ line2 := "Total target pattern evaluation phase time 0.012 s 4.59%"
+
+ timing = parsePhaseTiming(line2)
+ if timing.GetPhaseName() != "target pattern evaluation" {
+ t.Errorf("Failed to parse phase name. Expected target pattern evaluation, have %s\n", timing.GetPhaseName())
+ } else if timing.GetDurationNanos() != 12000000 {
+ t.Errorf("Failed to parse duration nanos. Expected 12000000, have %d\n", timing.GetDurationNanos())
+ } else if timing.GetPortionOfBuildTime() != 459 {
+ t.Errorf("Failed to parse portion of build time. Expected 459, have %d\n", timing.GetPortionOfBuildTime())
+ }
+}
+
+func TestParseTotal(t *testing.T) {
+ // Total line is in the form of:
+ // Total run time 7.563 s 100.00%
+
+ line := "Total run time 7.563 s 100.00%"
+
+ total := parseTotal(line)
+
+ // Only the seconds field is parsed, as nanos
+ if total != 7563000000 {
+ t.Errorf("Failed to parse total build time. Expected 7563000000, have %d\n", total)
+ }
+}