Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit ac91c3f7 authored by Patrice Arruda's avatar Patrice Arruda
Browse files

Use monotonic clock instead of wall time clock for metrics. 

From several dashboards, there are high spikes from several
builds where the real time of executing a part of the build
system took many many hours. This is due to using the wall
time clock when calculating the duration. For metrics, the
monotonic clock should be used for more accurate measurement.
Also, cleaned up the time.go file to use the proper proto
functions when marshalling perf protobuf and deleted
unnecessary functions.

Bug: b/143492984
Test: Wrote and ran unit test case.
Change-Id: I1540cfbf37915e3045ecedaa2595c1f9429bcd62
Merged-In: I1540cfbf37915e3045ecedaa2595c1f9429bcd62
parent 70ca506d

ui/metrics/Android.bp

+3 −0
Original line number Diff line number Diff line
@@ -25,6 +25,9 @@ bootstrap_go_package { 
        "metrics.go",

        "time.go",

    ],

    testSrcs: [

        "time_test.go",

    ],

}



bootstrap_go_package {

ui/metrics/time.go

+17 −19
Original line number Diff line number Diff line
@@ -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 {

	return uint64(time.Now().UnixNano())

}



func (t *timeTracerImpl) Begin(name, desc string, thread tracer.Thread) {

	t.beginAt(name, desc, t.now())

func now() time.Time {

	return time.Now()

}



func (t *timeTracerImpl) beginAt(name, desc string, atNanos uint64) {

	t.activeEvents = append(t.activeEvents, timeEvent{name: name, desc: desc, atNanos: atNanos})

func (t *timeTracerImpl) Begin(name, desc string, _ tracer.Thread) {

	t.activeEvents = append(t.activeEvents, timeEvent{name: name, desc: desc, start: _now()})

}



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 {

func (t *timeTracerImpl) End(tracer.Thread) 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,

		Name:      &lastEvent.name,

		StartTime: &lastEvent.atNanos,

		RealTime:  &realTime}

		Desc:      proto.String(lastEvent.desc),

		Name:      proto.String(lastEvent.name),

		StartTime: proto.Uint64(uint64(lastEvent.start.UnixNano())),

		RealTime:  proto.Uint64(realTime),

	}

}

ui/metrics/time_test.go

0 → 100644
+42 −0
Original line number Diff line number Diff line 
// 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())

	}

}