Merge "Use monotonic clock instead of wall time clock for metrics."

ui/metrics/Android.bp

@@ -25,6 +25,9 @@ bootstrap_go_package {
         "metrics.go",
         "time.go",
     ],
+    testSrcs: [
+        "time_test.go",
+    ],
 }
 
 bootstrap_go_package {

ui/metrics/time.go

@@ -19,13 +19,18 @@ import (
 
 	"android/soong/ui/metrics/metrics_proto"
 	"android/soong/ui/tracer"
+	"github.com/golang/protobuf/proto"
 )
 
+// for testing purpose only
+var _now = now
+
 type timeEvent struct {
 	desc string
 	name string
 
-	atNanos uint64 // timestamp measured in nanoseconds since the reference date
+	// the time that the event started to occur.
+	start time.Time
 }
 
 type TimeTracer interface {
@@ -39,33 +44,26 @@ type timeTracerImpl struct {
 
 var _ TimeTracer = &timeTracerImpl{}
 
-func (t *timeTracerImpl) now() uint64 {
+func now() time.Time {
-	return uint64(time.Now().UnixNano())
+	return time.Now()
 }
 
-func (t *timeTracerImpl) Begin(name, desc string, thread tracer.Thread) {
+func (t *timeTracerImpl) Begin(name, desc string, _ tracer.Thread) {
-	t.beginAt(name, desc, t.now())
+	t.activeEvents = append(t.activeEvents, timeEvent{name: name, desc: desc, start: _now()})
 }
 
-func (t *timeTracerImpl) beginAt(name, desc string, atNanos uint64) {
+func (t *timeTracerImpl) End(tracer.Thread) soong_metrics_proto.PerfInfo {
-	t.activeEvents = append(t.activeEvents, timeEvent{name: name, desc: desc, atNanos: atNanos})
-}
-
-func (t *timeTracerImpl) End(thread tracer.Thread) soong_metrics_proto.PerfInfo {
-	return t.endAt(t.now())
-}
-
-func (t *timeTracerImpl) endAt(atNanos uint64) soong_metrics_proto.PerfInfo {
 	if len(t.activeEvents) < 1 {
 		panic("Internal error: No pending events for endAt to end!")
 	}
 	lastEvent := t.activeEvents[len(t.activeEvents)-1]
 	t.activeEvents = t.activeEvents[:len(t.activeEvents)-1]
-	realTime := atNanos - lastEvent.atNanos
+	realTime := uint64(_now().Sub(lastEvent.start).Nanoseconds())
 
 	return soong_metrics_proto.PerfInfo{
-		Desc:      &lastEvent.desc,
+		Desc:      proto.String(lastEvent.desc),
-		Name:      &lastEvent.name,
+		Name:      proto.String(lastEvent.name),
-		StartTime: &lastEvent.atNanos,
+		StartTime: proto.Uint64(uint64(lastEvent.start.UnixNano())),
-		RealTime:  &realTime}
+		RealTime:  proto.Uint64(realTime),
+	}
 }

ui/metrics/time_test.go

@@ -0,0 +1,42 @@
+// Copyright 2020 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 metrics
+
+import (
+	"testing"
+	"time"
+
+	"android/soong/ui/tracer"
+)
+
+func TestEnd(t *testing.T) {
+	startTime := time.Date(2020, time.July, 13, 13, 0, 0, 0, time.UTC)
+	dur := time.Nanosecond * 10
+	initialNow := _now
+	_now = func() time.Time { return startTime.Add(dur) }
+	defer func() { _now = initialNow }()
+
+	timeTracer := &timeTracerImpl{}
+	timeTracer.activeEvents = append(timeTracer.activeEvents, timeEvent{
+		desc:  "test",
+		name:  "test",
+		start: startTime,
+	})
+
+	perf := timeTracer.End(tracer.Thread(0))
+	if perf.GetRealTime() != uint64(dur.Nanoseconds()) {
+		t.Errorf("got %d, want %d nanoseconds for event duration", perf.GetRealTime(), dur.Nanoseconds())
+	}
+}