Add profile times to treble_build am: a241bc30e4 am: b63cbd19a5 am: 0f25425af7 am: fe5e598347

Original change: https://android-review.googlesource.com/c/platform/tools/treble/+/2153943

Change-Id: I6ad5d5151e2ba2d1fcb5f705d74c5f4a9b5afa97
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>

4 files changed, 119 insertions, 11 deletions

diff --git a/build/treble_build/cmd/main.go b/build/treble_build/cmd/main.go
index 0264ff3..d3eb7c6 100644
--- a/build/treble_build/cmd/main.go
+++ b/build/treble_build/cmd/main.go
@@ -26,6 +26,7 @@ import (
 	"os"
 	"runtime"
 	"strings"
+	"time"
 
 	"tools/treble/build/report/app"
 	"tools/treble/build/report/local"
@@ -67,11 +68,14 @@ var (
 	// Common flags
 	ninjaDbPtr          = flag.String("ninja", local.DefNinjaDb(), "Set the .ninja file to use when building metrics")
 	ninjaExcPtr         = flag.String("ninja_cmd", local.DefNinjaExc(), "Set the ninja executable")
+	ninjaTimeoutStr     = flag.String("ninja_timeout", local.DefaultNinjaTimeout, "Default ninja timeout")
+	buildTimeoutStr     = flag.String("build_timeout", local.DefaultNinjaBuildTimeout, "Default build timeout")
 	manifestPtr         = flag.String("manifest", local.DefManifest(), "Set the location of the manifest file")
 	upstreamPtr         = flag.String("upstream", "", "Upstream branch to compare files against")
 	repoBasePtr         = flag.String("repo_base", local.DefRepoBase(), "Set the repo base directory")
 	workerCountPtr      = flag.Int("worker_count", runtime.NumCPU(), "Number of worker routines")
 	buildWorkerCountPtr = flag.Int("build_worker_count", local.MaxNinjaCliWorkers, "Number of build worker routines")
+	clientServerPtr     = flag.Bool("client_server", false, "Run client server mode")
 	buildPtr            = flag.Bool("build", false, "Build targets")
 	jsonPtr             = flag.Bool("json", false, "Print json data")
 	verbosePtr          = flag.Bool("v", false, "Print verbose text data")
@@ -82,6 +86,12 @@ var (
 	pathsFlags = flag.NewFlagSet("paths", flag.ExitOnError)
 )
 
+// Add profiling data
+type profTime struct {
+	Description  string  `json:"description"`
+	DurationSecs float64 `json:"duration"`
+}
+
 type commit struct {
 	Project app.ProjectCommit `json:"project"`
 	Commit  *app.GitCommit    `json:"commit"`
@@ -99,14 +109,32 @@ type response struct {
 	Query *app.QueryResponse `json:"query,omitempty"`
 	Paths []*app.BuildPath   `json:"build_paths,omitempty"`
 	Host  *app.HostReport    `json:"host,omitempty"`
+
+	// Profile data
+	Profile []*profTime `json:"profile"`
 }
 
 func main() {
+	startTime := time.Now()
 	ctx := context.Background()
 	rsp := &response{}
 
+	var addProfileData = func(desc string) {
+		rsp.Profile = append(rsp.Profile, &profTime{Description: desc, DurationSecs: time.Since(startTime).Seconds()})
+		startTime = time.Now()
+	}
 	flag.Parse()
 
+	ninjaTimeout, err := time.ParseDuration(*ninjaTimeoutStr)
+	if err != nil {
+		log.Fatalf("Invalid ninja timeout %s", *ninjaTimeoutStr)
+	}
+
+	buildTimeout, err := time.ParseDuration(*buildTimeoutStr)
+	if err != nil {
+		log.Fatalf("Invalid build timeout %s", *buildTimeoutStr)
+	}
+
 	subArgs := flag.Args()
 	if len(subArgs) < 1 {
 		// Nothing to do
@@ -115,7 +143,17 @@ func main() {
 	defBuildTarget := "droid"
 	log.SetFlags(log.LstdFlags | log.Llongfile)
 
-	ninja := local.NewNinjaCli(*ninjaExcPtr, *ninjaDbPtr)
+	ninja := local.NewNinjaCli(*ninjaExcPtr, *ninjaDbPtr, ninjaTimeout, buildTimeout, *clientServerPtr)
+
+	if *clientServerPtr {
+		go func() {
+			ninjaServ := local.NewNinjaCli(*ninjaExcPtr, *ninjaDbPtr, ninjaTimeout, buildTimeout, false)
+			ninjaServ.StartServer(ctx)
+		}()
+		if err := ninja.WaitForServer(ctx, 60); err != nil {
+			log.Fatalf("Failed to connect to server")
+		}
+	}
 	rtx := &report.Context{
 		RepoBase:         *repoBasePtr,
 		Repo:             &report.RepoMan{},
@@ -154,8 +192,10 @@ func main() {
 	default:
 		rsp.Targets = subArgs
 	}
-
+	addProfileData("Init")
 	rtx.ResolveProjectMap(ctx, *manifestPtr, *upstreamPtr)
+	addProfileData("Project Map")
+
 	// Resolve any commits
 	if len(commits) > 0 {
 		log.Printf("Resolving %s", commits.String())
@@ -171,6 +211,7 @@ func main() {
 			// Add files to list of inputs
 			rsp.Inputs = append(rsp.Inputs, files...)
 		}
+		addProfileData("Commit Resolution")
 	}
 
 	// Run any sub tools
@@ -178,6 +219,7 @@ func main() {
 		if err := subcommand.Run(ctx, rtx, rsp); err != nil {
 			log.Fatal(err)
 		}
+		addProfileData(subArgs[0])
 	}
 
 	buildErrors := 0
@@ -185,6 +227,7 @@ func main() {
 		for _, t := range rsp.Targets {
 			log.Printf("Building %s\n", t)
 			res := ninja.Build(ctx, t)
+			addProfileData(fmt.Sprintf("Build %s", t))
 			log.Printf("%s\n", res.Output)
 			if res.Success != true {
 				buildErrors++
@@ -194,10 +237,10 @@ func main() {
 	}
 
 	// Generate report
-	var err error
 	log.Printf("Generating report for targets %s", rsp.Targets)
 	req := &app.ReportRequest{Targets: rsp.Targets}
 	rsp.Report, err = report.RunReport(ctx, rtx, req)
+	addProfileData("Report")
 	if err != nil {
 		log.Fatal(fmt.Sprintf("Report failure <%s>", err))
 	}
@@ -294,4 +337,9 @@ func printTextReport(w io.Writer, subcommand tool, rsp *response, verbose bool)
 		targetPrint(t)
 	}
 
+	fmt.Fprintln(w, "  Run Times")
+	for _, p := range rsp.Profile {
+		fmt.Fprintf(w, "     %-30s : %f secs\n", p.Description, p.DurationSecs)
+	}
+
 }
diff --git a/build/treble_build/local/cmd.go b/build/treble_build/local/cmd.go
index 3fc24c8..3d4e9c2 100644
--- a/build/treble_build/local/cmd.go
+++ b/build/treble_build/local/cmd.go
@@ -21,6 +21,7 @@ import (
 	"errors"
 	"io"
 	"os/exec"
+	"syscall"
 	"time"
 )
 
@@ -66,10 +67,22 @@ func run(ctx context.Context, timeout time.Duration, cmdName string, args []stri
 	return &outputBuf, nil, ""
 }
 
+// run without timeout, kill when application dies
+func runNoTimeout(ctx context.Context, cmdName string, args []string) error {
+	cmd := exec.CommandContext(ctx, cmdName, args[0:]...)
+	// Kill when app dies
+	cmd.SysProcAttr = &syscall.SysProcAttr{Pdeathsig: syscall.SIGKILL}
+	err := cmd.Start()
+	if err != nil {
+		return err
+	}
+	cmd.Wait()
+	return nil
+}
+
 // lineScanner
 //
-//  Map output lines to strings, with expected number of
-// lines
+// Map output lines to strings, with expected number of lines.
 type lineScanner struct {
 	Lines []string
 }
diff --git a/build/treble_build/local/ninja.go b/build/treble_build/local/ninja.go
index 012bcc7..1b9eec6 100644
--- a/build/treble_build/local/ninja.go
+++ b/build/treble_build/local/ninja.go
@@ -18,6 +18,8 @@ import (
 	"bufio"
 	"bytes"
 	"context"
+	"errors"
+	"fmt"
 	"io"
 	"io/ioutil"
 	"strings"
@@ -27,7 +29,11 @@ import (
 )
 
 // Performance degrades running multiple CLIs
-const MaxNinjaCliWorkers = 4
+const (
+	MaxNinjaCliWorkers       = 4
+	DefaultNinjaTimeout      = "100s"
+	DefaultNinjaBuildTimeout = "30m"
+)
 
 // Separate out the executable to allow tests to override the results
 type ninjaExec interface {
@@ -37,6 +43,7 @@ type ninjaExec interface {
 	Path(ctx context.Context, target string, dependency string) (*bytes.Buffer, error)
 	Paths(ctx context.Context, target string, dependency string) (*bytes.Buffer, error)
 	Deps(ctx context.Context) (*bytes.Buffer, error)
+	StartServer(ctx context.Context) error
 	Build(ctx context.Context, target string) (*bytes.Buffer, error)
 }
 
@@ -174,14 +181,23 @@ type ninjaCmd struct {
 	cmd string
 	db  string
 
+	clientMode   bool
 	timeout      time.Duration
 	buildTimeout time.Duration
 }
 
 func (n *ninjaCmd) runTool(ctx context.Context, tool string, targets []string) (out *bytes.Buffer, err error) {
-	args := append([]string{
-		"-f", n.db,
-		"-t", tool}, targets...)
+
+	args := []string{"-f", n.db}
+
+	if n.clientMode {
+		args = append(args, []string{
+			"-t", "client",
+			"-c", tool}...)
+	} else {
+		args = append(args, []string{"-t", tool}...)
+	}
+	args = append(args, targets...)
 	data := []byte{}
 	err, _ = runPipe(ctx, n.timeout, n.cmd, args, func(r io.Reader) {
 		data, _ = ioutil.ReadAll(r)
@@ -207,6 +223,10 @@ func (n *ninjaCmd) Paths(ctx context.Context, target string, dependency string)
 func (n *ninjaCmd) Deps(ctx context.Context) (*bytes.Buffer, error) {
 	return n.runTool(ctx, "deps", []string{})
 }
+func (n *ninjaCmd) StartServer(ctx context.Context) error {
+	args := []string{"-f", n.db, "-t", "server"}
+	return runNoTimeout(ctx, n.cmd, args)
+}
 
 func (n *ninjaCmd) Build(ctx context.Context, target string) (*bytes.Buffer, error) {
 
@@ -221,6 +241,7 @@ func (n *ninjaCmd) Build(ctx context.Context, target string) (*bytes.Buffer, err
 	return bytes.NewBuffer(data), err
 }
 
+// Command line ninja
 type ninjaCli struct {
 	n ninjaExec
 }
@@ -285,7 +306,29 @@ func (cli *ninjaCli) Build(ctx context.Context, target string) *app.BuildCmdResu
 	return parseBuild(target, raw, err == nil)
 
 }
-func NewNinjaCli(cmd string, db string) *ninjaCli {
-	cli := &ninjaCli{n: &ninjaCmd{cmd: cmd, db: db, timeout: 100000 * time.Millisecond, buildTimeout: 300000 * time.Millisecond}}
+
+// Run server
+func (cli *ninjaCli) StartServer(ctx context.Context) error {
+	return cli.n.StartServer(ctx)
+}
+
+// Wait for server
+func (cli *ninjaCli) WaitForServer(ctx context.Context, maxTries int) error {
+	// Wait for server to response to an empty input request
+	fmt.Printf("Waiting for server.")
+	for i := 0; i < maxTries; i++ {
+		_, err := cli.Input(ctx, "")
+		if err == nil {
+			fmt.Printf("\nConnected\n")
+			return nil
+		}
+		fmt.Printf(".")
+		time.Sleep(time.Second)
+	}
+	fmt.Printf(" failed\n")
+	return errors.New("Failed to connect")
+}
+func NewNinjaCli(cmd string, db string, timeout, buildTimeout time.Duration, client bool) *ninjaCli {
+	cli := &ninjaCli{n: &ninjaCmd{cmd: cmd, db: db, timeout: timeout, buildTimeout: buildTimeout, clientMode: client}}
 	return cli
 }
diff --git a/build/treble_build/local/ninja_test.go b/build/treble_build/local/ninja_test.go
index 40e2043..2b3aabc 100644
--- a/build/treble_build/local/ninja_test.go
+++ b/build/treble_build/local/ninja_test.go
@@ -17,6 +17,7 @@ package local
 import (
 	"bytes"
 	"context"
+	"errors"
 	"reflect"
 	"testing"
 
@@ -51,6 +52,9 @@ func (n *ninjaTest) Paths(ctx context.Context, target string, dependency string)
 func (n *ninjaTest) Deps(ctx context.Context) (*bytes.Buffer, error) {
 	return bytes.NewBufferString(n.deps.text), n.deps.err
 }
+func (n *ninjaTest) StartServer(ctx context.Context) error {
+	return errors.New("server not support")
+}
 func (n *ninjaTest) Build(ctx context.Context, target string) (*bytes.Buffer, error) {
 	return bytes.NewBufferString(n.build.text), n.build.err
 }