Add microfactory tracing

Test: m clean; load out/build.trace.gz in chrome://tracing
Test: m -j nothing; load again
Change-Id: I67d4e006a4bdde593b54c20d6d93a48278fe696d

4 files changed, 104 insertions, 38 deletions

diff --git a/ui/tracer/Android.bp b/ui/tracer/Android.bp
index 89812a13..9729c7e5 100644
--- a/ui/tracer/Android.bp
+++ b/ui/tracer/Android.bp
@@ -17,6 +17,7 @@ bootstrap_go_package {
     pkgPath: "android/soong/ui/tracer",
     deps: ["soong-ui-logger"],
     srcs: [
+        "microfactory.go",
         "ninja.go",
         "tracer.go",
     ],
diff --git a/ui/tracer/microfactory.go b/ui/tracer/microfactory.go
new file mode 100644
index 00000000..320d9d8e
--- /dev/null
+++ b/ui/tracer/microfactory.go
@@ -0,0 +1,63 @@
+// Copyright 2017 Google Inc. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package tracer
+
+import (
+	"bufio"
+	"os"
+	"strconv"
+	"strings"
+)
+
+func (t *tracerImpl) ImportMicrofactoryLog(filename string) {
+	if _, err := os.Stat(filename); err != nil {
+		return
+	}
+
+	f, err := os.Open(filename)
+	if err != nil {
+		t.log.Println("Error opening microfactory trace:", err)
+		return
+	}
+	defer f.Close()
+
+	entries := []*eventEntry{}
+	begin := map[string][]uint64{}
+	s := bufio.NewScanner(f)
+	for s.Scan() {
+		fields := strings.SplitN(s.Text(), " ", 3)
+		if len(fields) != 3 {
+			t.log.Verboseln("Unknown line in microfactory trace:", s.Text())
+			continue
+		}
+		timestamp, err := strconv.ParseUint(fields[0], 10, 64)
+		if err != nil {
+			t.log.Verboseln("Failed to parse timestamp in microfactory trace:", err)
+		}
+
+		if fields[1] == "B" {
+			begin[fields[2]] = append(begin[fields[2]], timestamp)
+		} else if beginTimestamps, ok := begin[fields[2]]; ok {
+			entries = append(entries, &eventEntry{
+				Name:  fields[2],
+				Begin: beginTimestamps[len(beginTimestamps)-1],
+				End:   timestamp,
+			})
+			begin[fields[2]] = beginTimestamps[:len(beginTimestamps)-1]
+		}
+	}
+
+	t.importEvents(entries)
+}
diff --git a/ui/tracer/ninja.go b/ui/tracer/ninja.go
index da558f12..1980559c 100644
--- a/ui/tracer/ninja.go
+++ b/ui/tracer/ninja.go
@@ -23,16 +23,42 @@ import (
 	"time"
 )
 
-type ninjaLogEntry struct {
+type eventEntry struct {
 	Name  string
-	Begin int
-	End   int
+	Begin uint64
+	End   uint64
 }
-type ninjaLogEntries []*ninjaLogEntry
 
-func (n ninjaLogEntries) Len() int           { return len(n) }
-func (n ninjaLogEntries) Less(i, j int) bool { return n[i].Begin < n[j].Begin }
-func (n ninjaLogEntries) Swap(i, j int)      { n[i], n[j] = n[j], n[i] }
+func (t *tracerImpl) importEvents(entries []*eventEntry) {
+	sort.Slice(entries, func(i, j int) bool {
+		return entries[i].Begin < entries[j].Begin
+	})
+
+	cpus := []uint64{}
+	for _, entry := range entries {
+		tid := -1
+		for cpu, endTime := range cpus {
+			if endTime <= entry.Begin {
+				tid = cpu
+				cpus[cpu] = entry.End
+				break
+			}
+		}
+		if tid == -1 {
+			tid = len(cpus)
+			cpus = append(cpus, entry.End)
+		}
+
+		t.writeEvent(&viewerEvent{
+			Name:  entry.Name,
+			Phase: "X",
+			Time:  entry.Begin,
+			Dur:   entry.End - entry.Begin,
+			Pid:   1,
+			Tid:   uint64(tid),
+		})
+	}
+}
 
 // ImportNinjaLog reads a .ninja_log file from ninja and writes the events out
 // to the trace.
@@ -61,8 +87,9 @@ func (t *tracerImpl) ImportNinjaLog(thread Thread, filename string, startOffset
 
 	s := bufio.NewScanner(f)
 	header := true
-	entries := ninjaLogEntries{}
+	entries := []*eventEntry{}
 	prevEnd := 0
+	offset := uint64(startOffset.UnixNano()) / 1000
 	for s.Scan() {
 		if header {
 			hdr := s.Text()
@@ -89,10 +116,10 @@ func (t *tracerImpl) ImportNinjaLog(thread Thread, filename string, startOffset
 			entries = nil
 		}
 		prevEnd = end
-		entries = append(entries, &ninjaLogEntry{
+		entries = append(entries, &eventEntry{
 			Name:  fields[3],
-			Begin: begin,
-			End:   end,
+			Begin: offset + uint64(begin)*1000,
+			End:   offset + uint64(end)*1000,
 		})
 	}
 	if err := s.Err(); err != nil {
@@ -100,31 +127,5 @@ func (t *tracerImpl) ImportNinjaLog(thread Thread, filename string, startOffset
 		return
 	}
 
-	sort.Sort(entries)
-
-	cpus := []int{}
-	offset := uint64(startOffset.UnixNano()) / 1000
-	for _, entry := range entries {
-		tid := -1
-		for cpu, endTime := range cpus {
-			if endTime <= entry.Begin {
-				tid = cpu
-				cpus[cpu] = entry.End
-				break
-			}
-		}
-		if tid == -1 {
-			tid = len(cpus)
-			cpus = append(cpus, entry.End)
-		}
-
-		t.writeEvent(&viewerEvent{
-			Name:  entry.Name,
-			Phase: "X",
-			Time:  offset + uint64(entry.Begin)*1000,
-			Dur:   uint64(entry.End-entry.Begin) * 1000,
-			Pid:   1,
-			Tid:   uint64(tid),
-		})
-	}
+	t.importEvents(entries)
 }
diff --git a/ui/tracer/tracer.go b/ui/tracer/tracer.go
index f19ac186..87050403 100644
--- a/ui/tracer/tracer.go
+++ b/ui/tracer/tracer.go
@@ -45,6 +45,7 @@ type Tracer interface {
 	End(thread Thread)
 	Complete(name string, thread Thread, begin, end uint64)
 
+	ImportMicrofactoryLog(filename string)
 	ImportNinjaLog(thread Thread, filename string, startOffset time.Time)
 
 	NewThread(name string) Thread