Loading ui/metrics/event.go +86 −42 Original line number Diff line number Diff line Loading @@ -14,6 +14,17 @@ package metrics // This file contains the functionality to represent a build event in respect // to the metric system. A build event corresponds to a block of scoped code // that contains a "Begin()" and immediately followed by "defer End()" trace. // When defined, the duration of the scoped code is measure along with other // performance measurements such as memory. // // As explained in the metrics package, the metrics system is a stacked based // system since the collected metrics is considered to be topline metrics. // The steps of the build system in the UI layer is sequential. Hence, the // functionality defined below follows the stack data structure operations. import ( "os" "syscall" Loading @@ -21,54 +32,97 @@ import ( "android/soong/ui/metrics/metrics_proto" "android/soong/ui/tracer" "github.com/golang/protobuf/proto" ) // for testing purpose only var _now = now // _now wraps the time.Now() function. _now is declared for unit testing purpose. var _now = func() time.Time { return time.Now() } // event holds the performance metrics data of a single build event. type event struct { desc string // The event name (mostly used for grouping a set of events) name string // the time that the event started to occur. // The description of the event (used to uniquely identify an event // for metrics analysis). desc string // The time that the event started to occur. start time.Time // The list of process resource information that was executed // The list of process resource information that was executed. procResInfo []*soong_metrics_proto.ProcessResourceInfo } type EventTracer interface { Begin(name, desc string, thread tracer.Thread) End(thread tracer.Thread) soong_metrics_proto.PerfInfo AddProcResInfo(string, *os.ProcessState) // newEvent returns an event with start populated with the now time. func newEvent(name, desc string) *event { return &event{ name: name, desc: desc, start: _now(), } } type eventTracerImpl struct { activeEvents []event func (e event) perfInfo() soong_metrics_proto.PerfInfo { realTime := uint64(_now().Sub(e.start).Nanoseconds()) return soong_metrics_proto.PerfInfo{ Desc: proto.String(e.desc), Name: proto.String(e.name), StartTime: proto.Uint64(uint64(e.start.UnixNano())), RealTime: proto.Uint64(realTime), ProcessesResourceInfo: e.procResInfo, } } var _ EventTracer = &eventTracerImpl{} // EventTracer is an array of events that provides functionality to trace a // block of code on time and performance. The End call expects the Begin is // invoked, otherwise panic is raised. type EventTracer []*event func now() time.Time { return time.Now() // empty returns true if there are no pending events. func (t *EventTracer) empty() bool { return len(*t) == 0 } // AddProcResInfo adds information on an executed process such as max resident set memory // and the number of voluntary context switches. func (t *eventTracerImpl) AddProcResInfo(name string, state *os.ProcessState) { if len(t.activeEvents) < 1 { // lastIndex returns the index of the last element of events. func (t *EventTracer) lastIndex() int { return len(*t) - 1 } // peek returns the active build event. func (t *EventTracer) peek() *event { return (*t)[t.lastIndex()] } // push adds the active build event in the stack. func (t *EventTracer) push(e *event) { *t = append(*t, e) } // pop removes the active event from the stack since the event has completed. // A panic is raised if there are no pending events. func (t *EventTracer) pop() *event { if t.empty() { panic("Internal error: No pending events") } e := (*t)[t.lastIndex()] *t = (*t)[:t.lastIndex()] return e } // AddProcResInfo adds information on an executed process such as max resident // set memory and the number of voluntary context switches. func (t *EventTracer) AddProcResInfo(name string, state *os.ProcessState) { if t.empty() { return } rusage := state.SysUsage().(*syscall.Rusage) // The implementation of the metrics system is a stacked based system. The steps of the // build system in the UI layer is sequential so the Begin function is invoked when a // function (or scoped code) is invoked. That is translated to a new event which is added // at the end of the activeEvents array. When the invoking function is completed, End is // invoked which is a pop operation from activeEvents. curEvent := &t.activeEvents[len(t.activeEvents)-1] curEvent.procResInfo = append(curEvent.procResInfo, &soong_metrics_proto.ProcessResourceInfo{ e := t.peek() e.procResInfo = append(e.procResInfo, &soong_metrics_proto.ProcessResourceInfo{ Name: proto.String(name), UserTimeMicros: proto.Uint64(uint64(rusage.Utime.Usec)), SystemTimeMicros: proto.Uint64(uint64(rusage.Stime.Usec)), Loading @@ -82,23 +136,13 @@ func (t *eventTracerImpl) AddProcResInfo(name string, state *os.ProcessState) { }) } func (t *eventTracerImpl) Begin(name, desc string, _ tracer.Thread) { t.activeEvents = append(t.activeEvents, event{name: name, desc: desc, start: _now()}) } func (t *eventTracerImpl) End(tracer.Thread) soong_metrics_proto.PerfInfo { if len(t.activeEvents) < 1 { panic("Internal error: No pending events for endAt to end!") // Begin starts tracing the event. func (t *EventTracer) Begin(name, desc string, _ tracer.Thread) { t.push(newEvent(name, desc)) } lastEvent := t.activeEvents[len(t.activeEvents)-1] t.activeEvents = t.activeEvents[:len(t.activeEvents)-1] realTime := uint64(_now().Sub(lastEvent.start).Nanoseconds()) return soong_metrics_proto.PerfInfo{ Desc: proto.String(lastEvent.desc), Name: proto.String(lastEvent.name), StartTime: proto.Uint64(uint64(lastEvent.start.UnixNano())), RealTime: proto.Uint64(realTime), ProcessesResourceInfo: lastEvent.procResInfo, } // End performs post calculations such as duration of the event, aggregates // the collected performance information into PerfInfo protobuf message. func (t *EventTracer) End(tracer.Thread) soong_metrics_proto.PerfInfo { return t.pop().perfInfo() } ui/metrics/event_test.go +3 −3 Original line number Diff line number Diff line Loading @@ -28,14 +28,14 @@ func TestEnd(t *testing.T) { _now = func() time.Time { return startTime.Add(dur) } defer func() { _now = initialNow }() eventTracer := &eventTracerImpl{} eventTracer.activeEvents = append(eventTracer.activeEvents, event{ et := &EventTracer{} et.push(&event{ desc: "test", name: "test", start: startTime, }) perf := eventTracer.End(tracer.Thread(0)) perf := et.End(tracer.Thread(0)) if perf.GetRealTime() != uint64(dur.Nanoseconds()) { t.Errorf("got %d, want %d nanoseconds for event duration", perf.GetRealTime(), dur.Nanoseconds()) } Loading ui/metrics/metrics.go +2 −2 Original line number Diff line number Diff line Loading @@ -39,13 +39,13 @@ const ( type Metrics struct { metrics soong_metrics_proto.MetricsBase EventTracer EventTracer EventTracer *EventTracer } func New() (metrics *Metrics) { m := &Metrics{ metrics: soong_metrics_proto.MetricsBase{}, EventTracer: &eventTracerImpl{}, EventTracer: &EventTracer{}, } return m } Loading Loading
ui/metrics/event.go +86 −42 Original line number Diff line number Diff line Loading @@ -14,6 +14,17 @@ package metrics // This file contains the functionality to represent a build event in respect // to the metric system. A build event corresponds to a block of scoped code // that contains a "Begin()" and immediately followed by "defer End()" trace. // When defined, the duration of the scoped code is measure along with other // performance measurements such as memory. // // As explained in the metrics package, the metrics system is a stacked based // system since the collected metrics is considered to be topline metrics. // The steps of the build system in the UI layer is sequential. Hence, the // functionality defined below follows the stack data structure operations. import ( "os" "syscall" Loading @@ -21,54 +32,97 @@ import ( "android/soong/ui/metrics/metrics_proto" "android/soong/ui/tracer" "github.com/golang/protobuf/proto" ) // for testing purpose only var _now = now // _now wraps the time.Now() function. _now is declared for unit testing purpose. var _now = func() time.Time { return time.Now() } // event holds the performance metrics data of a single build event. type event struct { desc string // The event name (mostly used for grouping a set of events) name string // the time that the event started to occur. // The description of the event (used to uniquely identify an event // for metrics analysis). desc string // The time that the event started to occur. start time.Time // The list of process resource information that was executed // The list of process resource information that was executed. procResInfo []*soong_metrics_proto.ProcessResourceInfo } type EventTracer interface { Begin(name, desc string, thread tracer.Thread) End(thread tracer.Thread) soong_metrics_proto.PerfInfo AddProcResInfo(string, *os.ProcessState) // newEvent returns an event with start populated with the now time. func newEvent(name, desc string) *event { return &event{ name: name, desc: desc, start: _now(), } } type eventTracerImpl struct { activeEvents []event func (e event) perfInfo() soong_metrics_proto.PerfInfo { realTime := uint64(_now().Sub(e.start).Nanoseconds()) return soong_metrics_proto.PerfInfo{ Desc: proto.String(e.desc), Name: proto.String(e.name), StartTime: proto.Uint64(uint64(e.start.UnixNano())), RealTime: proto.Uint64(realTime), ProcessesResourceInfo: e.procResInfo, } } var _ EventTracer = &eventTracerImpl{} // EventTracer is an array of events that provides functionality to trace a // block of code on time and performance. The End call expects the Begin is // invoked, otherwise panic is raised. type EventTracer []*event func now() time.Time { return time.Now() // empty returns true if there are no pending events. func (t *EventTracer) empty() bool { return len(*t) == 0 } // AddProcResInfo adds information on an executed process such as max resident set memory // and the number of voluntary context switches. func (t *eventTracerImpl) AddProcResInfo(name string, state *os.ProcessState) { if len(t.activeEvents) < 1 { // lastIndex returns the index of the last element of events. func (t *EventTracer) lastIndex() int { return len(*t) - 1 } // peek returns the active build event. func (t *EventTracer) peek() *event { return (*t)[t.lastIndex()] } // push adds the active build event in the stack. func (t *EventTracer) push(e *event) { *t = append(*t, e) } // pop removes the active event from the stack since the event has completed. // A panic is raised if there are no pending events. func (t *EventTracer) pop() *event { if t.empty() { panic("Internal error: No pending events") } e := (*t)[t.lastIndex()] *t = (*t)[:t.lastIndex()] return e } // AddProcResInfo adds information on an executed process such as max resident // set memory and the number of voluntary context switches. func (t *EventTracer) AddProcResInfo(name string, state *os.ProcessState) { if t.empty() { return } rusage := state.SysUsage().(*syscall.Rusage) // The implementation of the metrics system is a stacked based system. The steps of the // build system in the UI layer is sequential so the Begin function is invoked when a // function (or scoped code) is invoked. That is translated to a new event which is added // at the end of the activeEvents array. When the invoking function is completed, End is // invoked which is a pop operation from activeEvents. curEvent := &t.activeEvents[len(t.activeEvents)-1] curEvent.procResInfo = append(curEvent.procResInfo, &soong_metrics_proto.ProcessResourceInfo{ e := t.peek() e.procResInfo = append(e.procResInfo, &soong_metrics_proto.ProcessResourceInfo{ Name: proto.String(name), UserTimeMicros: proto.Uint64(uint64(rusage.Utime.Usec)), SystemTimeMicros: proto.Uint64(uint64(rusage.Stime.Usec)), Loading @@ -82,23 +136,13 @@ func (t *eventTracerImpl) AddProcResInfo(name string, state *os.ProcessState) { }) } func (t *eventTracerImpl) Begin(name, desc string, _ tracer.Thread) { t.activeEvents = append(t.activeEvents, event{name: name, desc: desc, start: _now()}) } func (t *eventTracerImpl) End(tracer.Thread) soong_metrics_proto.PerfInfo { if len(t.activeEvents) < 1 { panic("Internal error: No pending events for endAt to end!") // Begin starts tracing the event. func (t *EventTracer) Begin(name, desc string, _ tracer.Thread) { t.push(newEvent(name, desc)) } lastEvent := t.activeEvents[len(t.activeEvents)-1] t.activeEvents = t.activeEvents[:len(t.activeEvents)-1] realTime := uint64(_now().Sub(lastEvent.start).Nanoseconds()) return soong_metrics_proto.PerfInfo{ Desc: proto.String(lastEvent.desc), Name: proto.String(lastEvent.name), StartTime: proto.Uint64(uint64(lastEvent.start.UnixNano())), RealTime: proto.Uint64(realTime), ProcessesResourceInfo: lastEvent.procResInfo, } // End performs post calculations such as duration of the event, aggregates // the collected performance information into PerfInfo protobuf message. func (t *EventTracer) End(tracer.Thread) soong_metrics_proto.PerfInfo { return t.pop().perfInfo() }
ui/metrics/event_test.go +3 −3 Original line number Diff line number Diff line Loading @@ -28,14 +28,14 @@ func TestEnd(t *testing.T) { _now = func() time.Time { return startTime.Add(dur) } defer func() { _now = initialNow }() eventTracer := &eventTracerImpl{} eventTracer.activeEvents = append(eventTracer.activeEvents, event{ et := &EventTracer{} et.push(&event{ desc: "test", name: "test", start: startTime, }) perf := eventTracer.End(tracer.Thread(0)) perf := et.End(tracer.Thread(0)) if perf.GetRealTime() != uint64(dur.Nanoseconds()) { t.Errorf("got %d, want %d nanoseconds for event duration", perf.GetRealTime(), dur.Nanoseconds()) } Loading
ui/metrics/metrics.go +2 −2 Original line number Diff line number Diff line Loading @@ -39,13 +39,13 @@ const ( type Metrics struct { metrics soong_metrics_proto.MetricsBase EventTracer EventTracer EventTracer *EventTracer } func New() (metrics *Metrics) { m := &Metrics{ metrics: soong_metrics_proto.MetricsBase{}, EventTracer: &eventTracerImpl{}, EventTracer: &EventTracer{}, } return m } Loading