blob: a8ea4618d8fa4769dee04db7896285b3eba59b13 [file] [log] [blame]
Shinichiro Hamajib69bf8a2015-06-10 14:52:06 +09001// Copyright 2015 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
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +090015package kati
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +090016
17import (
18 "fmt"
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090019 "io"
20 "os"
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +090021 "sort"
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090022 "sync"
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +090023 "time"
24)
25
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090026type traceEventT struct {
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090027 mu sync.Mutex
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090028 f io.WriteCloser
29 t0 time.Time
30 pid int
31}
32
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090033const (
34 traceEventMain = iota + 1
Fumitoshi Ukai0547db62015-07-29 16:20:59 +090035 // add new ones to use new goroutine.
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090036)
37
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090038var traceEvent traceEventT
39
Fumitoshi Ukai65c72332015-06-26 21:32:50 +090040// TraceEventStart starts trace event.
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +090041func TraceEventStart(f io.WriteCloser) {
42 traceEvent.start(f)
43}
44
Fumitoshi Ukai65c72332015-06-26 21:32:50 +090045// TraceEventStop stops trace event.
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +090046func TraceEventStop() {
47 traceEvent.stop()
48}
49
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090050func (t *traceEventT) start(f io.WriteCloser) {
51 t.f = f
52 t.t0 = time.Now()
53 fmt.Fprint(t.f, "[ ")
54}
55
56func (t *traceEventT) enabled() bool {
57 return t.f != nil
58}
59
60func (t *traceEventT) stop() {
61 fmt.Fprint(t.f, "\n]\n")
62 t.f.Close()
63}
64
65type event struct {
66 name, v string
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090067 tid int
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090068 t time.Time
Fumitoshi Ukaicb393c52015-06-11 15:34:10 +090069 emit bool
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090070}
71
Fumitoshi Ukai83410132015-06-15 14:50:07 +090072func (t *traceEventT) begin(name string, v Value, tid int) event {
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090073 var e event
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090074 e.tid = tid
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090075 e.t = time.Now()
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +090076 if t.f != nil || EvalStatsFlag {
Fumitoshi Ukai6ab72dd2015-06-11 15:45:52 +090077 e.name = name
Fumitoshi Ukai83410132015-06-15 14:50:07 +090078 e.v = v.String()
Fumitoshi Ukai6ab72dd2015-06-11 15:45:52 +090079 }
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090080 if t.f != nil {
Fumitoshi Ukai0547db62015-07-29 16:20:59 +090081 e.emit = name == "include" || name == "shell"
Fumitoshi Ukaicb393c52015-06-11 15:34:10 +090082 if e.emit {
Fumitoshi Ukai83410132015-06-15 14:50:07 +090083 t.emit("B", e, e.t.Sub(t.t0))
Fumitoshi Ukai432a2422015-06-11 15:16:29 +090084 }
85 }
86 return e
87}
88
Fumitoshi Ukai83410132015-06-15 14:50:07 +090089func (t *traceEventT) emit(ph string, e event, ts time.Duration) {
Fumitoshi Ukaif543f4d2015-06-15 15:21:47 +090090 t.mu.Lock()
91 defer t.mu.Unlock()
Fumitoshi Ukai83410132015-06-15 14:50:07 +090092
93 if t.pid == 0 {
94 t.pid = os.Getpid()
95 } else {
96 fmt.Fprintf(t.f, ",\n")
97 }
98 fmt.Fprintf(t.f, `{"pid":%d,"tid":%d,"ts":%d,"ph":%q,"cat":%q,"name":%q,"args":{}}`,
99 t.pid,
100 e.tid,
101 ts.Nanoseconds()/1e3,
102 ph,
103 e.name,
104 e.v,
105 )
106}
107
108func (t *traceEventT) end(e event) {
Fumitoshi Ukai432a2422015-06-11 15:16:29 +0900109 if t.f != nil {
Fumitoshi Ukaicb393c52015-06-11 15:34:10 +0900110 if e.emit {
Fumitoshi Ukai83410132015-06-15 14:50:07 +0900111 t.emit("E", e, time.Since(t.t0))
Fumitoshi Ukai432a2422015-06-11 15:16:29 +0900112 }
113 }
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900114 stats.add(e.name, e.v, e.t)
Fumitoshi Ukai432a2422015-06-11 15:16:29 +0900115}
116
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900117type statsData struct {
118 Name string
119 Count int
120 Longest time.Duration
121 Total time.Duration
122}
123
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900124type statsT struct {
125 mu sync.Mutex
126 data map[string]statsData
127}
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900128
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900129var stats = &statsT{
130 data: make(map[string]statsData),
131}
132
133func (s *statsT) add(name, v string, t time.Time) {
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +0900134 if !EvalStatsFlag {
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900135 return
136 }
Fumitoshi Ukai358c68a2015-06-08 13:12:55 +0900137 d := time.Since(t)
Fumitoshi Ukai432a2422015-06-11 15:16:29 +0900138 key := fmt.Sprintf("%s:%s", name, v)
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900139 s.mu.Lock()
140 sd := s.data[key]
141 if d > sd.Longest {
142 sd.Longest = d
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900143 }
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900144 sd.Total += d
145 sd.Count++
146 s.data[key] = sd
147 s.mu.Unlock()
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900148}
149
Fumitoshi Ukai65c72332015-06-26 21:32:50 +0900150// DumpStats dumps statistics collected if EvalStatsFlag is set.
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +0900151func DumpStats() {
152 if !EvalStatsFlag {
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900153 return
154 }
155 var sv byTotalTime
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900156 for k, v := range stats.data {
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900157 v.Name = k
158 sv = append(sv, v)
159 }
160 sort.Sort(sv)
Fumitoshi Ukai47f401f2015-04-30 17:29:50 +0900161 fmt.Println("count,longest(ns),total(ns),longest,total,name")
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900162 for _, s := range sv {
Fumitoshi Ukai47f401f2015-04-30 17:29:50 +0900163 fmt.Printf("%d,%d,%d,%v,%v,%s\n", s.Count, s.Longest, s.Total, s.Longest, s.Total, s.Name)
Fumitoshi Ukai6ac7f692015-04-15 17:13:51 +0900164 }
165}
166
167type byTotalTime []statsData
168
169func (b byTotalTime) Len() int { return len(b) }
170func (b byTotalTime) Swap(i, j int) { b[i], b[j] = b[j], b[i] }
171func (b byTotalTime) Less(i, j int) bool {
172 return b[i].Total > b[j].Total
173}
Fumitoshi Ukai9042b992015-06-23 16:10:27 +0900174
175type shellStatsT struct {
176 mu sync.Mutex
177 duration time.Duration
178 count int
179}
180
181var shellStats = &shellStatsT{}
182
183func (s *shellStatsT) add(d time.Duration) {
184 s.mu.Lock()
185 s.duration += d
186 s.count++
187 s.mu.Unlock()
188}
Fumitoshi Ukai744bb2b2015-06-25 00:10:52 +0900189
190func (s *shellStatsT) Duration() time.Duration {
191 s.mu.Lock()
192 defer s.mu.Unlock()
193 return s.duration
194}
195
196func (s *shellStatsT) Count() int {
197 s.mu.Lock()
198 defer s.mu.Unlock()
199 return s.count
200}