1// Copyright 2018 Google Inc. All Rights Reserved.
2//
3// Licensed under the Apache License, Version 2.0 (the "License");
4// you may not use this file except in compliance with the License.
5// You may obtain a copy of the License at
6//
7//   http://www.apache.org/licenses/LICENSE-2.0
8//
9// Unless required by applicable law or agreed to in writing, software
10// distributed under the License is distributed on an "AS IS" BASIS,
11// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12// See the License for the specific language governing permissions and
13// limitations under the License.
14
15package metrics
16
17// This file contains the functionality to represent a build event in respect
18// to the metric system. A build event corresponds to a block of scoped code
19// that contains a "Begin()" and immediately followed by "defer End()" trace.
20// When defined, the duration of the scoped code is measure along with other
21// performance measurements such as memory.
22//
23// As explained in the metrics package, the metrics system is a stacked based
24// system since the collected metrics is considered to be topline metrics.
25// The steps of the build system in the UI layer is sequential. Hence, the
26// functionality defined below follows the stack data structure operations.
27
28import (
29	"os"
30	"syscall"
31	"time"
32
33	soong_metrics_proto "android/soong/ui/metrics/metrics_proto"
34
35	"google.golang.org/protobuf/proto"
36)
37
38// _now wraps the time.Now() function. _now is declared for unit testing purpose.
39var _now = func() time.Time {
40	return time.Now()
41}
42
43// event holds the performance metrics data of a single build event.
44type event struct {
45	// The event name (mostly used for grouping a set of events)
46	name string
47
48	// The description of the event (used to uniquely identify an event
49	// for metrics analysis).
50	desc string
51
52	nonZeroExitCode bool
53
54	errorMsg *string
55
56	// The time that the event started to occur.
57	start time.Time
58
59	// The list of process resource information that was executed.
60	procResInfo []*soong_metrics_proto.ProcessResourceInfo
61}
62
63// newEvent returns an event with start populated with the now time.
64func newEvent(name, desc string) *event {
65	return &event{
66		name:  name,
67		desc:  desc,
68		start: _now(),
69	}
70}
71
72func (e event) perfInfo() soong_metrics_proto.PerfInfo {
73	realTime := uint64(_now().Sub(e.start).Nanoseconds())
74	perfInfo := soong_metrics_proto.PerfInfo{
75		Description:           proto.String(e.desc),
76		Name:                  proto.String(e.name),
77		StartTime:             proto.Uint64(uint64(e.start.UnixNano())),
78		RealTime:              proto.Uint64(realTime),
79		ProcessesResourceInfo: e.procResInfo,
80		NonZeroExit:           proto.Bool(e.nonZeroExitCode),
81	}
82	if m := e.errorMsg; m != nil {
83		perfInfo.ErrorMessage = proto.String(*m)
84	}
85	return perfInfo
86}
87
88// EventTracer is an array of events that provides functionality to trace a
89// block of code on time and performance. The End call expects the Begin is
90// invoked, otherwise panic is raised.
91type EventTracer []*event
92
93// empty returns true if there are no pending events.
94func (t *EventTracer) empty() bool {
95	return len(*t) == 0
96}
97
98// lastIndex returns the index of the last element of events.
99func (t *EventTracer) lastIndex() int {
100	return len(*t) - 1
101}
102
103// peek returns the active build event.
104func (t *EventTracer) peek() *event {
105	if t.empty() {
106		return nil
107	}
108	return (*t)[t.lastIndex()]
109}
110
111// push adds the active build event in the stack.
112func (t *EventTracer) push(e *event) {
113	*t = append(*t, e)
114}
115
116// pop removes the active event from the stack since the event has completed.
117// A panic is raised if there are no pending events.
118func (t *EventTracer) pop() *event {
119	if t.empty() {
120		panic("Internal error: No pending events")
121	}
122	e := (*t)[t.lastIndex()]
123	*t = (*t)[:t.lastIndex()]
124	return e
125}
126
127// AddProcResInfo adds information on an executed process such as max resident
128// set memory and the number of voluntary context switches.
129func (t *EventTracer) AddProcResInfo(name string, state *os.ProcessState) {
130	if t.empty() {
131		return
132	}
133
134	rusage := state.SysUsage().(*syscall.Rusage)
135	e := t.peek()
136	e.procResInfo = append(e.procResInfo, &soong_metrics_proto.ProcessResourceInfo{
137		Name:             proto.String(name),
138		UserTimeMicros:   proto.Uint64(uint64(state.UserTime().Microseconds())),
139		SystemTimeMicros: proto.Uint64(uint64(state.SystemTime().Microseconds())),
140		MinorPageFaults:  proto.Uint64(uint64(rusage.Minflt)),
141		MajorPageFaults:  proto.Uint64(uint64(rusage.Majflt)),
142		// ru_inblock and ru_oublock are measured in blocks of 512 bytes.
143		IoInputKb:                  proto.Uint64(uint64(rusage.Inblock / 2)),
144		IoOutputKb:                 proto.Uint64(uint64(rusage.Oublock / 2)),
145		VoluntaryContextSwitches:   proto.Uint64(uint64(rusage.Nvcsw)),
146		InvoluntaryContextSwitches: proto.Uint64(uint64(rusage.Nivcsw)),
147	})
148}
149
150// Begin starts tracing the event.
151func (t *EventTracer) Begin(name, desc string) {
152	t.push(newEvent(name, desc))
153}
154
155// End performs post calculations such as duration of the event, aggregates
156// the collected performance information into PerfInfo protobuf message.
157func (t *EventTracer) End() soong_metrics_proto.PerfInfo {
158	return t.pop().perfInfo()
159}
160