1// Copyright 2022 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 17import ( 18 "fmt" 19 "strings" 20 "time" 21) 22 23// EventHandler tracks nested events and their start/stop times in a single 24// thread. 25type EventHandler struct { 26 completedEvents []Event 27 28 // These fields handle event scoping. When starting a new event, a new entry 29 // is pushed onto these fields. When ending an event, these fields are popped. 30 scopeIds []string 31 scopeStartTimes []time.Time 32} 33 34// _now simply delegates to time.Now() function. _now is declared for unit testing purpose. 35var _now = time.Now 36 37// Event holds the performance metrics data of a single build event. 38type Event struct { 39 // A unique human-readable identifier / "name" for the build event. Event 40 // names use period-delimited scoping. For example, if an event alpha starts, 41 // then an event bravo starts, then an event charlie starts and ends, the 42 // unique identifier for charlie will be 'alpha.bravo.charlie'. 43 Id string 44 45 Start time.Time 46 end time.Time 47} 48 49// RuntimeNanoseconds returns the number of nanoseconds between the start 50// and end times of the event. 51func (e Event) RuntimeNanoseconds() uint64 { 52 return uint64(e.end.Sub(e.Start).Nanoseconds()) 53} 54 55// Begin logs the start of an event. This must be followed by a corresponding 56// call to End (though other events may begin and end before this event ends). 57// Events within the same scope must have unique names. 58func (h *EventHandler) Begin(name string) { 59 if strings.ContainsRune(name, '.') { 60 panic(fmt.Sprintf("illegal event name (avoid dot): %s", name)) 61 } 62 h.scopeIds = append(h.scopeIds, name) 63 h.scopeStartTimes = append(h.scopeStartTimes, _now()) 64} 65 66// Do wraps a function with calls to Begin() and End(). 67func (h *EventHandler) Do(name string, f func()) { 68 h.Begin(name) 69 defer h.End(name) 70 f() 71} 72 73// End logs the end of an event. All events nested within this event must have 74// themselves been marked completed. 75func (h *EventHandler) End(name string) { 76 if len(h.scopeIds) == 0 || name != h.scopeIds[len(h.scopeIds)-1] { 77 panic(fmt.Errorf("unexpected scope end '%s'. Current scope: (%s)", 78 name, h.scopeIds)) 79 } 80 event := Event{ 81 // The event Id is formed from the period-delimited scope names of all 82 // active events (e.g. `alpha.beta.charlie`). See Event.Id documentation 83 // for more detail. 84 Id: strings.Join(h.scopeIds, "."), 85 Start: h.scopeStartTimes[len(h.scopeStartTimes)-1], 86 end: _now(), 87 } 88 h.completedEvents = append(h.completedEvents, event) 89 h.scopeIds = h.scopeIds[:len(h.scopeIds)-1] 90 h.scopeStartTimes = h.scopeStartTimes[:len(h.scopeStartTimes)-1] 91} 92 93// CompletedEvents returns all events which have been completed, after 94// validation. 95// It is an error to call this method if there are still ongoing events, or 96// if two events were completed with the same scope and name. 97func (h *EventHandler) CompletedEvents() []Event { 98 if len(h.scopeIds) > 0 { 99 panic(fmt.Errorf( 100 "retrieving events before all events have been closed. Current scope: (%s)", 101 h.scopeIds)) 102 } 103 // Validate no two events have the same full id. 104 ids := map[string]struct{}{} 105 for _, event := range h.completedEvents { 106 if _, containsId := ids[event.Id]; containsId { 107 panic(fmt.Errorf("duplicate event registered: %s", event.Id)) 108 } 109 ids[event.Id] = struct{}{} 110 } 111 return h.completedEvents 112} 113