diff options
| -rw-r--r-- | eval.go | 2 | ||||
| -rw-r--r-- | expr.go | 15 | ||||
| -rw-r--r-- | func.go | 15 | ||||
| -rw-r--r-- | pathutil.go | 5 | ||||
| -rw-r--r-- | stats.go | 35 |
5 files changed, 47 insertions, 25 deletions
@@ -263,7 +263,7 @@ func (ev *Evaluator) EvaluateVar(name string) string { } func (ev *Evaluator) evalIncludeFile(fname string, c []byte) error { - te := traceEvent.begin("include", literal(fname)) + te := traceEvent.begin("include", fname, traceEventMain) defer func() { traceEvent.end(te) }() @@ -149,7 +149,7 @@ func (v varref) String() string { } func (v varref) Eval(w io.Writer, ev *Evaluator) { - te := traceEvent.begin("var", v) + te := traceEvent.begin("var", v.String(), traceEventMain) buf := newBuf() v.varname.Eval(buf, ev) vv := ev.LookupVar(buf.String()) @@ -177,7 +177,7 @@ func (p paramref) String() string { } func (p paramref) Eval(w io.Writer, ev *Evaluator) { - te := traceEvent.begin("param", p) + te := traceEvent.begin("param", p.String(), traceEventMain) n := int(p) if n < len(ev.paramVars) { ev.paramVars[n].Eval(w, ev) @@ -209,7 +209,7 @@ func (v varsubst) String() string { } func (v varsubst) Eval(w io.Writer, ev *Evaluator) { - te := traceEvent.begin("varsubst", v) + te := traceEvent.begin("varsubst", v.String(), traceEventMain) buf := newBuf() params := ev.args(buf, v.varname, v.pat, v.subst) vname := string(params[0]) @@ -565,7 +565,11 @@ func parseFunc(f Func, in []byte, s int, term []byte, funcName string) (Value, i fv = compactor.Compact() } if katiEvalStatsFlag || traceEvent.enabled() { - fv = funcstats{fv} + fv = funcstats{ + Value: fv, + str: fv.String(), + } + } return fv, i, nil } @@ -576,10 +580,11 @@ type Compactor interface { type funcstats struct { Value + str string } func (f funcstats) Eval(w io.Writer, ev *Evaluator) { - te := traceEvent.begin("func", f) + te := traceEvent.begin("func", f.str, traceEventMain) f.Value.Eval(w, ev) // TODO(ukai): per functype? traceEvent.end(te) @@ -447,7 +447,7 @@ func (f *funcWildcard) Eval(w io.Writer, ev *Evaluator) { assertArity("wildcard", 1, len(f.args)) abuf := newBuf() f.args[1].Eval(abuf, ev) - te := traceEvent.begin("wildcard", tmpval(abuf.Bytes())) + te := traceEvent.begin("wildcard", string(abuf.Bytes()), traceEventMain) if ev.avoidIO && !useWildcardCache { ev.hasIO = true w.Write([]byte("$(/bin/ls -d ")) @@ -721,7 +721,7 @@ func (f *funcShell) Eval(w io.Writer, ev *Evaluator) { abuf := newBuf() f.args[1].Eval(abuf, ev) if ev.avoidIO && !hasNoIoInShellScript(abuf.Bytes()) { - te := traceEvent.begin("shell", tmpval(abuf.Bytes())) + te := traceEvent.begin("shell", string(abuf.Bytes()), traceEventMain) ev.hasIO = true w.Write([]byte("$(")) w.Write(abuf.Bytes()) @@ -740,7 +740,7 @@ func (f *funcShell) Eval(w io.Writer, ev *Evaluator) { Args: cmdline, Stderr: os.Stderr, } - te := traceEvent.begin("shell", literal(arg)) + te := traceEvent.begin("shell", arg, traceEventMain) out, err := cmd.Output() shellFuncTime += time.Since(te.t) shellFuncCount++ @@ -784,14 +784,15 @@ func (f *funcCall) Arity() int { return 0 } func (f *funcCall) Eval(w io.Writer, ev *Evaluator) { abuf := newBuf() fargs := ev.args(abuf, f.args[1:]...) - variable := fargs[0] - te := traceEvent.begin("call", tmpval(variable)) + varname := fargs[0] + variable := string(varname) + te := traceEvent.begin("call", variable, traceEventMain) Logf("call %q variable %q", f.args[1], variable) - v := ev.LookupVar(string(variable)) + v := ev.LookupVar(variable) // Evalualte all arguments first before we modify the table. var args []tmpval // $0 is variable. - args = append(args, tmpval(variable)) + args = append(args, tmpval(varname)) // TODO(ukai): If variable is the name of a built-in function, // the built-in function is always invoked (even if a make variable // by that name also exists). diff --git a/pathutil.go b/pathutil.go index 31a9e55..73b32d7 100644 --- a/pathutil.go +++ b/pathutil.go @@ -108,9 +108,10 @@ func (c *androidFindCacheT) init(prunes []string) { func (c *androidFindCacheT) start(prunes []string) { Logf("find cache init: %q", prunes) defer c.mu.Unlock() - t := time.Now() + te := traceEvent.begin("findcache", "init", traceEventFindCache) defer func() { - c.scanTime = time.Since(t) + traceEvent.end(te) + c.scanTime = time.Since(te.t) LogStats("android find cache scan: %v", c.scanTime) }() @@ -19,15 +19,22 @@ import ( "io" "os" "sort" + "sync" "time" ) type traceEventT struct { + mu sync.Mutex f io.WriteCloser t0 time.Time pid int } +const ( + traceEventMain = iota + 1 + traceEventFindCache +) + var traceEvent traceEventT func (t *traceEventT) start(f io.WriteCloser) { @@ -47,28 +54,33 @@ func (t *traceEventT) stop() { type event struct { name, v string + tid int t time.Time emit bool } -func (t *traceEventT) begin(name string, v Value) event { +func (t *traceEventT) begin(name string, v string, tid int) event { + t.mu.Lock() + defer t.mu.Unlock() var e event + e.tid = tid e.t = time.Now() if t.f != nil || katiEvalStatsFlag { e.name = name - e.v = v.String() + e.v = v } if t.f != nil { - e.emit = name == "include" || name == "shell" - if t.pid == 0 { - t.pid = os.Getpid() - } else if e.emit { - fmt.Fprint(t.f, ",\n") - } + e.emit = name == "include" || name == "shell" || name == "findcache" if e.emit { + if t.pid == 0 { + t.pid = os.Getpid() + } else { + fmt.Fprintf(t.f, ",\n") + } ts := e.t.Sub(t.t0) - fmt.Fprintf(t.f, `{"pid":%d,"tid":1,"ts":%d,"ph":"B","cat":%q,"name":%q,"args":{}}`, + fmt.Fprintf(t.f, `{"pid":%d,"tid":%d,"ts":%d,"ph":"B","cat":%q,"name":%q,"args":{}}`, t.pid, + e.tid, ts.Nanoseconds()/1e3, e.name, e.v, @@ -79,13 +91,16 @@ func (t *traceEventT) begin(name string, v Value) event { } func (t *traceEventT) end(e event) { + t.mu.Lock() + defer t.mu.Unlock() if t.f != nil { now := time.Now() ts := now.Sub(t.t0) if e.emit { fmt.Fprint(t.f, ",\n") - fmt.Fprintf(t.f, `{"pid":%d,"tid":1,"ts":%d,"ph":"E","cat":%q,"name":%q}`, + fmt.Fprintf(t.f, `{"pid":%d,"tid":%d,"ts":%d,"ph":"E","cat":%q,"name":%q}`, t.pid, + e.tid, ts.Nanoseconds()/1e3, e.name, e.v, |