github.com/megatontech/mynoteforgo@v0.0.0-20200507084910-5d0c6ea6e890/源码/cmd/trace/trace.go (about) 1 // Copyright 2014 The Go Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style 3 // license that can be found in the LICENSE file. 4 5 package main 6 7 import ( 8 "encoding/json" 9 "fmt" 10 "internal/trace" 11 "io" 12 "log" 13 "math" 14 "net/http" 15 "path/filepath" 16 "runtime" 17 "runtime/debug" 18 "sort" 19 "strconv" 20 "strings" 21 "time" 22 ) 23 24 func init() { 25 http.HandleFunc("/trace", httpTrace) 26 http.HandleFunc("/jsontrace", httpJsonTrace) 27 http.HandleFunc("/trace_viewer_html", httpTraceViewerHTML) 28 } 29 30 // httpTrace serves either whole trace (goid==0) or trace for goid goroutine. 31 func httpTrace(w http.ResponseWriter, r *http.Request) { 32 _, err := parseTrace() 33 if err != nil { 34 http.Error(w, err.Error(), http.StatusInternalServerError) 35 return 36 } 37 if err := r.ParseForm(); err != nil { 38 http.Error(w, err.Error(), http.StatusInternalServerError) 39 return 40 } 41 html := strings.ReplaceAll(templTrace, "{{PARAMS}}", r.Form.Encode()) 42 w.Write([]byte(html)) 43 44 } 45 46 // See https://github.com/catapult-project/catapult/blob/master/tracing/docs/embedding-trace-viewer.md 47 // This is almost verbatim copy of: 48 // https://github.com/catapult-project/catapult/blob/master/tracing/bin/index.html 49 // on revision 5f9e4c3eaa555bdef18218a89f38c768303b7b6e. 50 var templTrace = ` 51 <html> 52 <head> 53 <link href="/trace_viewer_html" rel="import"> 54 <style type="text/css"> 55 html, body { 56 box-sizing: border-box; 57 overflow: hidden; 58 margin: 0px; 59 padding: 0; 60 width: 100%; 61 height: 100%; 62 } 63 #trace-viewer { 64 width: 100%; 65 height: 100%; 66 } 67 #trace-viewer:focus { 68 outline: none; 69 } 70 </style> 71 <script> 72 'use strict'; 73 (function() { 74 var viewer; 75 var url; 76 var model; 77 78 function load() { 79 var req = new XMLHttpRequest(); 80 var is_binary = /[.]gz$/.test(url) || /[.]zip$/.test(url); 81 req.overrideMimeType('text/plain; charset=x-user-defined'); 82 req.open('GET', url, true); 83 if (is_binary) 84 req.responseType = 'arraybuffer'; 85 86 req.onreadystatechange = function(event) { 87 if (req.readyState !== 4) 88 return; 89 90 window.setTimeout(function() { 91 if (req.status === 200) 92 onResult(is_binary ? req.response : req.responseText); 93 else 94 onResultFail(req.status); 95 }, 0); 96 }; 97 req.send(null); 98 } 99 100 function onResultFail(err) { 101 var overlay = new tr.ui.b.Overlay(); 102 overlay.textContent = err + ': ' + url + ' could not be loaded'; 103 overlay.title = 'Failed to fetch data'; 104 overlay.visible = true; 105 } 106 107 function onResult(result) { 108 model = new tr.Model(); 109 var opts = new tr.importer.ImportOptions(); 110 opts.shiftWorldToZero = false; 111 var i = new tr.importer.Import(model, opts); 112 var p = i.importTracesWithProgressDialog([result]); 113 p.then(onModelLoaded, onImportFail); 114 } 115 116 function onModelLoaded() { 117 viewer.model = model; 118 viewer.viewTitle = "trace"; 119 120 if (!model || model.bounds.isEmpty) 121 return; 122 var sel = window.location.hash.substr(1); 123 if (sel === '') 124 return; 125 var parts = sel.split(':'); 126 var range = new (tr.b.Range || tr.b.math.Range)(); 127 range.addValue(parseFloat(parts[0])); 128 range.addValue(parseFloat(parts[1])); 129 viewer.trackView.viewport.interestRange.set(range); 130 } 131 132 function onImportFail(err) { 133 var overlay = new tr.ui.b.Overlay(); 134 overlay.textContent = tr.b.normalizeException(err).message; 135 overlay.title = 'Import error'; 136 overlay.visible = true; 137 } 138 139 document.addEventListener('DOMContentLoaded', function() { 140 var container = document.createElement('track-view-container'); 141 container.id = 'track_view_container'; 142 143 viewer = document.createElement('tr-ui-timeline-view'); 144 viewer.track_view_container = container; 145 viewer.appendChild(container); 146 147 viewer.id = 'trace-viewer'; 148 viewer.globalMode = true; 149 document.body.appendChild(viewer); 150 151 url = '/jsontrace?{{PARAMS}}'; 152 load(); 153 }); 154 }()); 155 </script> 156 </head> 157 <body> 158 </body> 159 </html> 160 ` 161 162 // httpTraceViewerHTML serves static part of trace-viewer. 163 // This URL is queried from templTrace HTML. 164 func httpTraceViewerHTML(w http.ResponseWriter, r *http.Request) { 165 http.ServeFile(w, r, filepath.Join(runtime.GOROOT(), "misc", "trace", "trace_viewer_full.html")) 166 } 167 168 // httpJsonTrace serves json trace, requested from within templTrace HTML. 169 func httpJsonTrace(w http.ResponseWriter, r *http.Request) { 170 defer debug.FreeOSMemory() 171 defer reportMemoryUsage("after httpJsonTrace") 172 // This is an AJAX handler, so instead of http.Error we use log.Printf to log errors. 173 res, err := parseTrace() 174 if err != nil { 175 log.Printf("failed to parse trace: %v", err) 176 return 177 } 178 179 params := &traceParams{ 180 parsed: res, 181 endTime: math.MaxInt64, 182 } 183 184 if goids := r.FormValue("goid"); goids != "" { 185 // If goid argument is present, we are rendering a trace for this particular goroutine. 186 goid, err := strconv.ParseUint(goids, 10, 64) 187 if err != nil { 188 log.Printf("failed to parse goid parameter %q: %v", goids, err) 189 return 190 } 191 analyzeGoroutines(res.Events) 192 g, ok := gs[goid] 193 if !ok { 194 log.Printf("failed to find goroutine %d", goid) 195 return 196 } 197 params.mode = modeGoroutineOriented 198 params.startTime = g.StartTime 199 if g.EndTime != 0 { 200 params.endTime = g.EndTime 201 } else { // The goroutine didn't end. 202 params.endTime = lastTimestamp() 203 } 204 params.maing = goid 205 params.gs = trace.RelatedGoroutines(res.Events, goid) 206 } else if taskids := r.FormValue("taskid"); taskids != "" { 207 taskid, err := strconv.ParseUint(taskids, 10, 64) 208 if err != nil { 209 log.Printf("failed to parse taskid parameter %q: %v", taskids, err) 210 return 211 } 212 annotRes, _ := analyzeAnnotations() 213 task, ok := annotRes.tasks[taskid] 214 if !ok || len(task.events) == 0 { 215 log.Printf("failed to find task with id %d", taskid) 216 return 217 } 218 goid := task.events[0].G 219 params.mode = modeGoroutineOriented | modeTaskOriented 220 params.startTime = task.firstTimestamp() - 1 221 params.endTime = task.lastTimestamp() + 1 222 params.maing = goid 223 params.tasks = task.descendants() 224 gs := map[uint64]bool{} 225 for _, t := range params.tasks { 226 // find only directly involved goroutines 227 for k, v := range t.RelatedGoroutines(res.Events, 0) { 228 gs[k] = v 229 } 230 } 231 params.gs = gs 232 } else if taskids := r.FormValue("focustask"); taskids != "" { 233 taskid, err := strconv.ParseUint(taskids, 10, 64) 234 if err != nil { 235 log.Printf("failed to parse focustask parameter %q: %v", taskids, err) 236 return 237 } 238 annotRes, _ := analyzeAnnotations() 239 task, ok := annotRes.tasks[taskid] 240 if !ok || len(task.events) == 0 { 241 log.Printf("failed to find task with id %d", taskid) 242 return 243 } 244 params.mode = modeTaskOriented 245 params.startTime = task.firstTimestamp() - 1 246 params.endTime = task.lastTimestamp() + 1 247 params.tasks = task.descendants() 248 } 249 250 start := int64(0) 251 end := int64(math.MaxInt64) 252 if startStr, endStr := r.FormValue("start"), r.FormValue("end"); startStr != "" && endStr != "" { 253 // If start/end arguments are present, we are rendering a range of the trace. 254 start, err = strconv.ParseInt(startStr, 10, 64) 255 if err != nil { 256 log.Printf("failed to parse start parameter %q: %v", startStr, err) 257 return 258 } 259 end, err = strconv.ParseInt(endStr, 10, 64) 260 if err != nil { 261 log.Printf("failed to parse end parameter %q: %v", endStr, err) 262 return 263 } 264 } 265 266 c := viewerDataTraceConsumer(w, start, end) 267 if err := generateTrace(params, c); err != nil { 268 log.Printf("failed to generate trace: %v", err) 269 return 270 } 271 } 272 273 type Range struct { 274 Name string 275 Start int 276 End int 277 StartTime int64 278 EndTime int64 279 } 280 281 func (r Range) URL() string { 282 return fmt.Sprintf("/trace?start=%d&end=%d", r.Start, r.End) 283 } 284 285 // splitTrace splits the trace into a number of ranges, 286 // each resulting in approx 100MB of json output 287 // (trace viewer can hardly handle more). 288 func splitTrace(res trace.ParseResult) []Range { 289 params := &traceParams{ 290 parsed: res, 291 endTime: math.MaxInt64, 292 } 293 s, c := splittingTraceConsumer(100 << 20) // 100M 294 if err := generateTrace(params, c); err != nil { 295 dief("%v\n", err) 296 } 297 return s.Ranges 298 } 299 300 type splitter struct { 301 Ranges []Range 302 } 303 304 func splittingTraceConsumer(max int) (*splitter, traceConsumer) { 305 type eventSz struct { 306 Time float64 307 Sz int 308 } 309 310 var ( 311 data = ViewerData{Frames: make(map[string]ViewerFrame)} 312 313 sizes []eventSz 314 cw countingWriter 315 ) 316 317 s := new(splitter) 318 319 return s, traceConsumer{ 320 consumeTimeUnit: func(unit string) { 321 data.TimeUnit = unit 322 }, 323 consumeViewerEvent: func(v *ViewerEvent, required bool) { 324 if required { 325 // Store required events inside data 326 // so flush can include them in the required 327 // part of the trace. 328 data.Events = append(data.Events, v) 329 return 330 } 331 enc := json.NewEncoder(&cw) 332 enc.Encode(v) 333 sizes = append(sizes, eventSz{v.Time, cw.size + 1}) // +1 for ",". 334 cw.size = 0 335 }, 336 consumeViewerFrame: func(k string, v ViewerFrame) { 337 data.Frames[k] = v 338 }, 339 flush: func() { 340 // Calculate size of the mandatory part of the trace. 341 // This includes stack traces and thread names. 342 cw.size = 0 343 enc := json.NewEncoder(&cw) 344 enc.Encode(data) 345 minSize := cw.size 346 347 // Then calculate size of each individual event 348 // and group them into ranges. 349 sum := minSize 350 start := 0 351 for i, ev := range sizes { 352 if sum+ev.Sz > max { 353 startTime := time.Duration(sizes[start].Time * 1000) 354 endTime := time.Duration(ev.Time * 1000) 355 ranges = append(ranges, Range{ 356 Name: fmt.Sprintf("%v-%v", startTime, endTime), 357 Start: start, 358 End: i + 1, 359 StartTime: int64(startTime), 360 EndTime: int64(endTime), 361 }) 362 start = i + 1 363 sum = minSize 364 } else { 365 sum += ev.Sz + 1 366 } 367 } 368 if len(ranges) <= 1 { 369 s.Ranges = nil 370 return 371 } 372 373 if end := len(sizes) - 1; start < end { 374 ranges = append(ranges, Range{ 375 Name: fmt.Sprintf("%v-%v", time.Duration(sizes[start].Time*1000), time.Duration(sizes[end].Time*1000)), 376 Start: start, 377 End: end, 378 StartTime: int64(sizes[start].Time * 1000), 379 EndTime: int64(sizes[end].Time * 1000), 380 }) 381 } 382 s.Ranges = ranges 383 }, 384 } 385 } 386 387 type countingWriter struct { 388 size int 389 } 390 391 func (cw *countingWriter) Write(data []byte) (int, error) { 392 cw.size += len(data) 393 return len(data), nil 394 } 395 396 type traceParams struct { 397 parsed trace.ParseResult 398 mode traceviewMode 399 startTime int64 400 endTime int64 401 maing uint64 // for goroutine-oriented view, place this goroutine on the top row 402 gs map[uint64]bool // Goroutines to be displayed for goroutine-oriented or task-oriented view 403 tasks []*taskDesc // Tasks to be displayed. tasks[0] is the top-most task 404 } 405 406 type traceviewMode uint 407 408 const ( 409 modeGoroutineOriented traceviewMode = 1 << iota 410 modeTaskOriented 411 ) 412 413 type traceContext struct { 414 *traceParams 415 consumer traceConsumer 416 frameTree frameNode 417 frameSeq int 418 arrowSeq uint64 419 gcount uint64 420 421 heapStats, prevHeapStats heapStats 422 threadStats, prevThreadStats threadStats 423 gstates, prevGstates [gStateCount]int64 424 425 regionID int // last emitted region id. incremented in each emitRegion call. 426 } 427 428 type heapStats struct { 429 heapAlloc uint64 430 nextGC uint64 431 } 432 433 type threadStats struct { 434 insyscallRuntime int64 // system goroutine in syscall 435 insyscall int64 // user goroutine in syscall 436 prunning int64 // thread running P 437 } 438 439 type frameNode struct { 440 id int 441 children map[uint64]frameNode 442 } 443 444 type gState int 445 446 const ( 447 gDead gState = iota 448 gRunnable 449 gRunning 450 gWaiting 451 gWaitingGC 452 453 gStateCount 454 ) 455 456 type gInfo struct { 457 state gState // current state 458 name string // name chosen for this goroutine at first EvGoStart 459 isSystemG bool 460 start *trace.Event // most recent EvGoStart 461 markAssist *trace.Event // if non-nil, the mark assist currently running. 462 } 463 464 type ViewerData struct { 465 Events []*ViewerEvent `json:"traceEvents"` 466 Frames map[string]ViewerFrame `json:"stackFrames"` 467 TimeUnit string `json:"displayTimeUnit"` 468 469 // This is where mandatory part of the trace starts (e.g. thread names) 470 footer int 471 } 472 473 type ViewerEvent struct { 474 Name string `json:"name,omitempty"` 475 Phase string `json:"ph"` 476 Scope string `json:"s,omitempty"` 477 Time float64 `json:"ts"` 478 Dur float64 `json:"dur,omitempty"` 479 Pid uint64 `json:"pid"` 480 Tid uint64 `json:"tid"` 481 ID uint64 `json:"id,omitempty"` 482 Stack int `json:"sf,omitempty"` 483 EndStack int `json:"esf,omitempty"` 484 Arg interface{} `json:"args,omitempty"` 485 Cname string `json:"cname,omitempty"` 486 Category string `json:"cat,omitempty"` 487 } 488 489 type ViewerFrame struct { 490 Name string `json:"name"` 491 Parent int `json:"parent,omitempty"` 492 } 493 494 type NameArg struct { 495 Name string `json:"name"` 496 } 497 498 type TaskArg struct { 499 ID uint64 `json:"id"` 500 StartG uint64 `json:"start_g,omitempty"` 501 EndG uint64 `json:"end_g,omitempty"` 502 } 503 504 type RegionArg struct { 505 TaskID uint64 `json:"taskid,omitempty"` 506 } 507 508 type SortIndexArg struct { 509 Index int `json:"sort_index"` 510 } 511 512 type traceConsumer struct { 513 consumeTimeUnit func(unit string) 514 consumeViewerEvent func(v *ViewerEvent, required bool) 515 consumeViewerFrame func(key string, f ViewerFrame) 516 flush func() 517 } 518 519 const ( 520 procsSection = 0 // where Goroutines or per-P timelines are presented. 521 statsSection = 1 // where counters are presented. 522 tasksSection = 2 // where Task hierarchy & timeline is presented. 523 ) 524 525 // generateTrace generates json trace for trace-viewer: 526 // https://github.com/google/trace-viewer 527 // Trace format is described at: 528 // https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/view 529 // If mode==goroutineMode, generate trace for goroutine goid, otherwise whole trace. 530 // startTime, endTime determine part of the trace that we are interested in. 531 // gset restricts goroutines that are included in the resulting trace. 532 func generateTrace(params *traceParams, consumer traceConsumer) error { 533 defer consumer.flush() 534 535 ctx := &traceContext{traceParams: params} 536 ctx.frameTree.children = make(map[uint64]frameNode) 537 ctx.consumer = consumer 538 539 ctx.consumer.consumeTimeUnit("ns") 540 maxProc := 0 541 ginfos := make(map[uint64]*gInfo) 542 stacks := params.parsed.Stacks 543 544 getGInfo := func(g uint64) *gInfo { 545 info, ok := ginfos[g] 546 if !ok { 547 info = &gInfo{} 548 ginfos[g] = info 549 } 550 return info 551 } 552 553 // Since we make many calls to setGState, we record a sticky 554 // error in setGStateErr and check it after every event. 555 var setGStateErr error 556 setGState := func(ev *trace.Event, g uint64, oldState, newState gState) { 557 info := getGInfo(g) 558 if oldState == gWaiting && info.state == gWaitingGC { 559 // For checking, gWaiting counts as any gWaiting*. 560 oldState = info.state 561 } 562 if info.state != oldState && setGStateErr == nil { 563 setGStateErr = fmt.Errorf("expected G %d to be in state %d, but got state %d", g, oldState, newState) 564 } 565 ctx.gstates[info.state]-- 566 ctx.gstates[newState]++ 567 info.state = newState 568 } 569 570 for _, ev := range ctx.parsed.Events { 571 // Handle state transitions before we filter out events. 572 switch ev.Type { 573 case trace.EvGoStart, trace.EvGoStartLabel: 574 setGState(ev, ev.G, gRunnable, gRunning) 575 info := getGInfo(ev.G) 576 info.start = ev 577 case trace.EvProcStart: 578 ctx.threadStats.prunning++ 579 case trace.EvProcStop: 580 ctx.threadStats.prunning-- 581 case trace.EvGoCreate: 582 newG := ev.Args[0] 583 info := getGInfo(newG) 584 if info.name != "" { 585 return fmt.Errorf("duplicate go create event for go id=%d detected at offset %d", newG, ev.Off) 586 } 587 588 stk, ok := stacks[ev.Args[1]] 589 if !ok || len(stk) == 0 { 590 return fmt.Errorf("invalid go create event: missing stack information for go id=%d at offset %d", newG, ev.Off) 591 } 592 593 fname := stk[0].Fn 594 info.name = fmt.Sprintf("G%v %s", newG, fname) 595 info.isSystemG = isSystemGoroutine(fname) 596 597 ctx.gcount++ 598 setGState(ev, newG, gDead, gRunnable) 599 case trace.EvGoEnd: 600 ctx.gcount-- 601 setGState(ev, ev.G, gRunning, gDead) 602 case trace.EvGoUnblock: 603 setGState(ev, ev.Args[0], gWaiting, gRunnable) 604 case trace.EvGoSysExit: 605 setGState(ev, ev.G, gWaiting, gRunnable) 606 if getGInfo(ev.G).isSystemG { 607 ctx.threadStats.insyscallRuntime-- 608 } else { 609 ctx.threadStats.insyscall-- 610 } 611 case trace.EvGoSysBlock: 612 setGState(ev, ev.G, gRunning, gWaiting) 613 if getGInfo(ev.G).isSystemG { 614 ctx.threadStats.insyscallRuntime++ 615 } else { 616 ctx.threadStats.insyscall++ 617 } 618 case trace.EvGoSched, trace.EvGoPreempt: 619 setGState(ev, ev.G, gRunning, gRunnable) 620 case trace.EvGoStop, 621 trace.EvGoSleep, trace.EvGoBlock, trace.EvGoBlockSend, trace.EvGoBlockRecv, 622 trace.EvGoBlockSelect, trace.EvGoBlockSync, trace.EvGoBlockCond, trace.EvGoBlockNet: 623 setGState(ev, ev.G, gRunning, gWaiting) 624 case trace.EvGoBlockGC: 625 setGState(ev, ev.G, gRunning, gWaitingGC) 626 case trace.EvGCMarkAssistStart: 627 getGInfo(ev.G).markAssist = ev 628 case trace.EvGCMarkAssistDone: 629 getGInfo(ev.G).markAssist = nil 630 case trace.EvGoWaiting: 631 setGState(ev, ev.G, gRunnable, gWaiting) 632 case trace.EvGoInSyscall: 633 // Cancel out the effect of EvGoCreate at the beginning. 634 setGState(ev, ev.G, gRunnable, gWaiting) 635 if getGInfo(ev.G).isSystemG { 636 ctx.threadStats.insyscallRuntime++ 637 } else { 638 ctx.threadStats.insyscall++ 639 } 640 case trace.EvHeapAlloc: 641 ctx.heapStats.heapAlloc = ev.Args[0] 642 case trace.EvNextGC: 643 ctx.heapStats.nextGC = ev.Args[0] 644 } 645 if setGStateErr != nil { 646 return setGStateErr 647 } 648 if ctx.gstates[gRunnable] < 0 || ctx.gstates[gRunning] < 0 || ctx.threadStats.insyscall < 0 || ctx.threadStats.insyscallRuntime < 0 { 649 return fmt.Errorf("invalid state after processing %v: runnable=%d running=%d insyscall=%d insyscallRuntime=%d", ev, ctx.gstates[gRunnable], ctx.gstates[gRunning], ctx.threadStats.insyscall, ctx.threadStats.insyscallRuntime) 650 } 651 652 // Ignore events that are from uninteresting goroutines 653 // or outside of the interesting timeframe. 654 if ctx.gs != nil && ev.P < trace.FakeP && !ctx.gs[ev.G] { 655 continue 656 } 657 if !withinTimeRange(ev, ctx.startTime, ctx.endTime) { 658 continue 659 } 660 661 if ev.P < trace.FakeP && ev.P > maxProc { 662 maxProc = ev.P 663 } 664 665 // Emit trace objects. 666 switch ev.Type { 667 case trace.EvProcStart: 668 if ctx.mode&modeGoroutineOriented != 0 { 669 continue 670 } 671 ctx.emitInstant(ev, "proc start", "") 672 case trace.EvProcStop: 673 if ctx.mode&modeGoroutineOriented != 0 { 674 continue 675 } 676 ctx.emitInstant(ev, "proc stop", "") 677 case trace.EvGCStart: 678 ctx.emitSlice(ev, "GC") 679 case trace.EvGCDone: 680 case trace.EvGCSTWStart: 681 if ctx.mode&modeGoroutineOriented != 0 { 682 continue 683 } 684 ctx.emitSlice(ev, fmt.Sprintf("STW (%s)", ev.SArgs[0])) 685 case trace.EvGCSTWDone: 686 case trace.EvGCMarkAssistStart: 687 // Mark assists can continue past preemptions, so truncate to the 688 // whichever comes first. We'll synthesize another slice if 689 // necessary in EvGoStart. 690 markFinish := ev.Link 691 goFinish := getGInfo(ev.G).start.Link 692 fakeMarkStart := *ev 693 text := "MARK ASSIST" 694 if markFinish == nil || markFinish.Ts > goFinish.Ts { 695 fakeMarkStart.Link = goFinish 696 text = "MARK ASSIST (unfinished)" 697 } 698 ctx.emitSlice(&fakeMarkStart, text) 699 case trace.EvGCSweepStart: 700 slice := ctx.makeSlice(ev, "SWEEP") 701 if done := ev.Link; done != nil && done.Args[0] != 0 { 702 slice.Arg = struct { 703 Swept uint64 `json:"Swept bytes"` 704 Reclaimed uint64 `json:"Reclaimed bytes"` 705 }{done.Args[0], done.Args[1]} 706 } 707 ctx.emit(slice) 708 case trace.EvGoStart, trace.EvGoStartLabel: 709 info := getGInfo(ev.G) 710 if ev.Type == trace.EvGoStartLabel { 711 ctx.emitSlice(ev, ev.SArgs[0]) 712 } else { 713 ctx.emitSlice(ev, info.name) 714 } 715 if info.markAssist != nil { 716 // If we're in a mark assist, synthesize a new slice, ending 717 // either when the mark assist ends or when we're descheduled. 718 markFinish := info.markAssist.Link 719 goFinish := ev.Link 720 fakeMarkStart := *ev 721 text := "MARK ASSIST (resumed, unfinished)" 722 if markFinish != nil && markFinish.Ts < goFinish.Ts { 723 fakeMarkStart.Link = markFinish 724 text = "MARK ASSIST (resumed)" 725 } 726 ctx.emitSlice(&fakeMarkStart, text) 727 } 728 case trace.EvGoCreate: 729 ctx.emitArrow(ev, "go") 730 case trace.EvGoUnblock: 731 ctx.emitArrow(ev, "unblock") 732 case trace.EvGoSysCall: 733 ctx.emitInstant(ev, "syscall", "") 734 case trace.EvGoSysExit: 735 ctx.emitArrow(ev, "sysexit") 736 case trace.EvUserLog: 737 ctx.emitInstant(ev, formatUserLog(ev), "user event") 738 case trace.EvUserTaskCreate: 739 ctx.emitInstant(ev, "task start", "user event") 740 case trace.EvUserTaskEnd: 741 ctx.emitInstant(ev, "task end", "user event") 742 } 743 // Emit any counter updates. 744 ctx.emitThreadCounters(ev) 745 ctx.emitHeapCounters(ev) 746 ctx.emitGoroutineCounters(ev) 747 } 748 749 ctx.emitSectionFooter(statsSection, "STATS", 0) 750 751 if ctx.mode&modeTaskOriented != 0 { 752 ctx.emitSectionFooter(tasksSection, "TASKS", 1) 753 } 754 755 if ctx.mode&modeGoroutineOriented != 0 { 756 ctx.emitSectionFooter(procsSection, "G", 2) 757 } else { 758 ctx.emitSectionFooter(procsSection, "PROCS", 2) 759 } 760 761 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: procsSection, Tid: trace.GCP, Arg: &NameArg{"GC"}}) 762 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: trace.GCP, Arg: &SortIndexArg{-6}}) 763 764 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: procsSection, Tid: trace.NetpollP, Arg: &NameArg{"Network"}}) 765 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: trace.NetpollP, Arg: &SortIndexArg{-5}}) 766 767 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: procsSection, Tid: trace.TimerP, Arg: &NameArg{"Timers"}}) 768 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: trace.TimerP, Arg: &SortIndexArg{-4}}) 769 770 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: procsSection, Tid: trace.SyscallP, Arg: &NameArg{"Syscalls"}}) 771 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: trace.SyscallP, Arg: &SortIndexArg{-3}}) 772 773 // Display rows for Ps if we are in the default trace view mode (not goroutine-oriented presentation) 774 if ctx.mode&modeGoroutineOriented == 0 { 775 for i := 0; i <= maxProc; i++ { 776 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: procsSection, Tid: uint64(i), Arg: &NameArg{fmt.Sprintf("Proc %v", i)}}) 777 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: uint64(i), Arg: &SortIndexArg{i}}) 778 } 779 } 780 781 // Display task and its regions if we are in task-oriented presentation mode. 782 if ctx.mode&modeTaskOriented != 0 { 783 // sort tasks based on the task start time. 784 sortedTask := make([]*taskDesc, 0, len(ctx.tasks)) 785 for _, task := range ctx.tasks { 786 sortedTask = append(sortedTask, task) 787 } 788 sort.SliceStable(sortedTask, func(i, j int) bool { 789 ti, tj := sortedTask[i], sortedTask[j] 790 if ti.firstTimestamp() == tj.firstTimestamp() { 791 return ti.lastTimestamp() < tj.lastTimestamp() 792 } 793 return ti.firstTimestamp() < tj.firstTimestamp() 794 }) 795 796 for i, task := range sortedTask { 797 ctx.emitTask(task, i) 798 799 // If we are in goroutine-oriented mode, we draw regions. 800 // TODO(hyangah): add this for task/P-oriented mode (i.e., focustask view) too. 801 if ctx.mode&modeGoroutineOriented != 0 { 802 for _, s := range task.regions { 803 ctx.emitRegion(s) 804 } 805 } 806 } 807 } 808 809 // Display goroutine rows if we are either in goroutine-oriented mode. 810 if ctx.mode&modeGoroutineOriented != 0 { 811 for k, v := range ginfos { 812 if !ctx.gs[k] { 813 continue 814 } 815 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: procsSection, Tid: k, Arg: &NameArg{v.name}}) 816 } 817 // Row for the main goroutine (maing) 818 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: ctx.maing, Arg: &SortIndexArg{-2}}) 819 // Row for GC or global state (specified with G=0) 820 ctx.emitFooter(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: procsSection, Tid: 0, Arg: &SortIndexArg{-1}}) 821 } 822 823 return nil 824 } 825 826 func (ctx *traceContext) emit(e *ViewerEvent) { 827 ctx.consumer.consumeViewerEvent(e, false) 828 } 829 830 func (ctx *traceContext) emitFooter(e *ViewerEvent) { 831 ctx.consumer.consumeViewerEvent(e, true) 832 } 833 func (ctx *traceContext) emitSectionFooter(sectionID uint64, name string, priority int) { 834 ctx.emitFooter(&ViewerEvent{Name: "process_name", Phase: "M", Pid: sectionID, Arg: &NameArg{name}}) 835 ctx.emitFooter(&ViewerEvent{Name: "process_sort_index", Phase: "M", Pid: sectionID, Arg: &SortIndexArg{priority}}) 836 } 837 838 func (ctx *traceContext) time(ev *trace.Event) float64 { 839 // Trace viewer wants timestamps in microseconds. 840 return float64(ev.Ts) / 1000 841 } 842 843 func withinTimeRange(ev *trace.Event, s, e int64) bool { 844 if evEnd := ev.Link; evEnd != nil { 845 return ev.Ts <= e && evEnd.Ts >= s 846 } 847 return ev.Ts >= s && ev.Ts <= e 848 } 849 850 func tsWithinRange(ts, s, e int64) bool { 851 return s <= ts && ts <= e 852 } 853 854 func (ctx *traceContext) proc(ev *trace.Event) uint64 { 855 if ctx.mode&modeGoroutineOriented != 0 && ev.P < trace.FakeP { 856 return ev.G 857 } else { 858 return uint64(ev.P) 859 } 860 } 861 862 func (ctx *traceContext) emitSlice(ev *trace.Event, name string) { 863 ctx.emit(ctx.makeSlice(ev, name)) 864 } 865 866 func (ctx *traceContext) makeSlice(ev *trace.Event, name string) *ViewerEvent { 867 // If ViewerEvent.Dur is not a positive value, 868 // trace viewer handles it as a non-terminating time interval. 869 // Avoid it by setting the field with a small value. 870 durationUsec := ctx.time(ev.Link) - ctx.time(ev) 871 if ev.Link.Ts-ev.Ts <= 0 { 872 durationUsec = 0.0001 // 0.1 nanoseconds 873 } 874 sl := &ViewerEvent{ 875 Name: name, 876 Phase: "X", 877 Time: ctx.time(ev), 878 Dur: durationUsec, 879 Tid: ctx.proc(ev), 880 Stack: ctx.stack(ev.Stk), 881 EndStack: ctx.stack(ev.Link.Stk), 882 } 883 884 // grey out non-overlapping events if the event is not a global event (ev.G == 0) 885 if ctx.mode&modeTaskOriented != 0 && ev.G != 0 { 886 // include P information. 887 if t := ev.Type; t == trace.EvGoStart || t == trace.EvGoStartLabel { 888 type Arg struct { 889 P int 890 } 891 sl.Arg = &Arg{P: ev.P} 892 } 893 // grey out non-overlapping events. 894 overlapping := false 895 for _, task := range ctx.tasks { 896 if _, overlapped := task.overlappingDuration(ev); overlapped { 897 overlapping = true 898 break 899 } 900 } 901 if !overlapping { 902 sl.Cname = colorLightGrey 903 } 904 } 905 return sl 906 } 907 908 func (ctx *traceContext) emitTask(task *taskDesc, sortIndex int) { 909 taskRow := uint64(task.id) 910 taskName := task.name 911 durationUsec := float64(task.lastTimestamp()-task.firstTimestamp()) / 1e3 912 913 ctx.emitFooter(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: tasksSection, Tid: taskRow, Arg: &NameArg{fmt.Sprintf("T%d %s", task.id, taskName)}}) 914 ctx.emit(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: tasksSection, Tid: taskRow, Arg: &SortIndexArg{sortIndex}}) 915 ts := float64(task.firstTimestamp()) / 1e3 916 sl := &ViewerEvent{ 917 Name: taskName, 918 Phase: "X", 919 Time: ts, 920 Dur: durationUsec, 921 Pid: tasksSection, 922 Tid: taskRow, 923 Cname: pickTaskColor(task.id), 924 } 925 targ := TaskArg{ID: task.id} 926 if task.create != nil { 927 sl.Stack = ctx.stack(task.create.Stk) 928 targ.StartG = task.create.G 929 } 930 if task.end != nil { 931 sl.EndStack = ctx.stack(task.end.Stk) 932 targ.EndG = task.end.G 933 } 934 sl.Arg = targ 935 ctx.emit(sl) 936 937 if task.create != nil && task.create.Type == trace.EvUserTaskCreate && task.create.Args[1] != 0 { 938 ctx.arrowSeq++ 939 ctx.emit(&ViewerEvent{Name: "newTask", Phase: "s", Tid: task.create.Args[1], ID: ctx.arrowSeq, Time: ts, Pid: tasksSection}) 940 ctx.emit(&ViewerEvent{Name: "newTask", Phase: "t", Tid: taskRow, ID: ctx.arrowSeq, Time: ts, Pid: tasksSection}) 941 } 942 } 943 944 func (ctx *traceContext) emitRegion(s regionDesc) { 945 if s.Name == "" { 946 return 947 } 948 949 if !tsWithinRange(s.firstTimestamp(), ctx.startTime, ctx.endTime) && 950 !tsWithinRange(s.lastTimestamp(), ctx.startTime, ctx.endTime) { 951 return 952 } 953 954 ctx.regionID++ 955 regionID := ctx.regionID 956 957 id := s.TaskID 958 scopeID := fmt.Sprintf("%x", id) 959 name := s.Name 960 961 sl0 := &ViewerEvent{ 962 Category: "Region", 963 Name: name, 964 Phase: "b", 965 Time: float64(s.firstTimestamp()) / 1e3, 966 Tid: s.G, // only in goroutine-oriented view 967 ID: uint64(regionID), 968 Scope: scopeID, 969 Cname: pickTaskColor(s.TaskID), 970 } 971 if s.Start != nil { 972 sl0.Stack = ctx.stack(s.Start.Stk) 973 } 974 ctx.emit(sl0) 975 976 sl1 := &ViewerEvent{ 977 Category: "Region", 978 Name: name, 979 Phase: "e", 980 Time: float64(s.lastTimestamp()) / 1e3, 981 Tid: s.G, 982 ID: uint64(regionID), 983 Scope: scopeID, 984 Cname: pickTaskColor(s.TaskID), 985 Arg: RegionArg{TaskID: s.TaskID}, 986 } 987 if s.End != nil { 988 sl1.Stack = ctx.stack(s.End.Stk) 989 } 990 ctx.emit(sl1) 991 } 992 993 type heapCountersArg struct { 994 Allocated uint64 995 NextGC uint64 996 } 997 998 func (ctx *traceContext) emitHeapCounters(ev *trace.Event) { 999 if ctx.prevHeapStats == ctx.heapStats { 1000 return 1001 } 1002 diff := uint64(0) 1003 if ctx.heapStats.nextGC > ctx.heapStats.heapAlloc { 1004 diff = ctx.heapStats.nextGC - ctx.heapStats.heapAlloc 1005 } 1006 if tsWithinRange(ev.Ts, ctx.startTime, ctx.endTime) { 1007 ctx.emit(&ViewerEvent{Name: "Heap", Phase: "C", Time: ctx.time(ev), Pid: 1, Arg: &heapCountersArg{ctx.heapStats.heapAlloc, diff}}) 1008 } 1009 ctx.prevHeapStats = ctx.heapStats 1010 } 1011 1012 type goroutineCountersArg struct { 1013 Running uint64 1014 Runnable uint64 1015 GCWaiting uint64 1016 } 1017 1018 func (ctx *traceContext) emitGoroutineCounters(ev *trace.Event) { 1019 if ctx.prevGstates == ctx.gstates { 1020 return 1021 } 1022 if tsWithinRange(ev.Ts, ctx.startTime, ctx.endTime) { 1023 ctx.emit(&ViewerEvent{Name: "Goroutines", Phase: "C", Time: ctx.time(ev), Pid: 1, Arg: &goroutineCountersArg{uint64(ctx.gstates[gRunning]), uint64(ctx.gstates[gRunnable]), uint64(ctx.gstates[gWaitingGC])}}) 1024 } 1025 ctx.prevGstates = ctx.gstates 1026 } 1027 1028 type threadCountersArg struct { 1029 Running int64 1030 InSyscall int64 1031 } 1032 1033 func (ctx *traceContext) emitThreadCounters(ev *trace.Event) { 1034 if ctx.prevThreadStats == ctx.threadStats { 1035 return 1036 } 1037 if tsWithinRange(ev.Ts, ctx.startTime, ctx.endTime) { 1038 ctx.emit(&ViewerEvent{Name: "Threads", Phase: "C", Time: ctx.time(ev), Pid: 1, Arg: &threadCountersArg{ 1039 Running: ctx.threadStats.prunning, 1040 InSyscall: ctx.threadStats.insyscall}}) 1041 } 1042 ctx.prevThreadStats = ctx.threadStats 1043 } 1044 1045 func (ctx *traceContext) emitInstant(ev *trace.Event, name, category string) { 1046 if !tsWithinRange(ev.Ts, ctx.startTime, ctx.endTime) { 1047 return 1048 } 1049 1050 cname := "" 1051 if ctx.mode&modeTaskOriented != 0 { 1052 taskID, isUserAnnotation := isUserAnnotationEvent(ev) 1053 1054 show := false 1055 for _, task := range ctx.tasks { 1056 if isUserAnnotation && task.id == taskID || task.overlappingInstant(ev) { 1057 show = true 1058 break 1059 } 1060 } 1061 // grey out or skip if non-overlapping instant. 1062 if !show { 1063 if isUserAnnotation { 1064 return // don't display unrelated user annotation events. 1065 } 1066 cname = colorLightGrey 1067 } 1068 } 1069 var arg interface{} 1070 if ev.Type == trace.EvProcStart { 1071 type Arg struct { 1072 ThreadID uint64 1073 } 1074 arg = &Arg{ev.Args[0]} 1075 } 1076 ctx.emit(&ViewerEvent{ 1077 Name: name, 1078 Category: category, 1079 Phase: "I", 1080 Scope: "t", 1081 Time: ctx.time(ev), 1082 Tid: ctx.proc(ev), 1083 Stack: ctx.stack(ev.Stk), 1084 Cname: cname, 1085 Arg: arg}) 1086 } 1087 1088 func (ctx *traceContext) emitArrow(ev *trace.Event, name string) { 1089 if ev.Link == nil { 1090 // The other end of the arrow is not captured in the trace. 1091 // For example, a goroutine was unblocked but was not scheduled before trace stop. 1092 return 1093 } 1094 if ctx.mode&modeGoroutineOriented != 0 && (!ctx.gs[ev.Link.G] || ev.Link.Ts < ctx.startTime || ev.Link.Ts > ctx.endTime) { 1095 return 1096 } 1097 1098 if ev.P == trace.NetpollP || ev.P == trace.TimerP || ev.P == trace.SyscallP { 1099 // Trace-viewer discards arrows if they don't start/end inside of a slice or instant. 1100 // So emit a fake instant at the start of the arrow. 1101 ctx.emitInstant(&trace.Event{P: ev.P, Ts: ev.Ts}, "unblock", "") 1102 } 1103 1104 color := "" 1105 if ctx.mode&modeTaskOriented != 0 { 1106 overlapping := false 1107 // skip non-overlapping arrows. 1108 for _, task := range ctx.tasks { 1109 if _, overlapped := task.overlappingDuration(ev); overlapped { 1110 overlapping = true 1111 break 1112 } 1113 } 1114 if !overlapping { 1115 return 1116 } 1117 } 1118 1119 ctx.arrowSeq++ 1120 ctx.emit(&ViewerEvent{Name: name, Phase: "s", Tid: ctx.proc(ev), ID: ctx.arrowSeq, Time: ctx.time(ev), Stack: ctx.stack(ev.Stk), Cname: color}) 1121 ctx.emit(&ViewerEvent{Name: name, Phase: "t", Tid: ctx.proc(ev.Link), ID: ctx.arrowSeq, Time: ctx.time(ev.Link), Cname: color}) 1122 } 1123 1124 func (ctx *traceContext) stack(stk []*trace.Frame) int { 1125 return ctx.buildBranch(ctx.frameTree, stk) 1126 } 1127 1128 // buildBranch builds one branch in the prefix tree rooted at ctx.frameTree. 1129 func (ctx *traceContext) buildBranch(parent frameNode, stk []*trace.Frame) int { 1130 if len(stk) == 0 { 1131 return parent.id 1132 } 1133 last := len(stk) - 1 1134 frame := stk[last] 1135 stk = stk[:last] 1136 1137 node, ok := parent.children[frame.PC] 1138 if !ok { 1139 ctx.frameSeq++ 1140 node.id = ctx.frameSeq 1141 node.children = make(map[uint64]frameNode) 1142 parent.children[frame.PC] = node 1143 ctx.consumer.consumeViewerFrame(strconv.Itoa(node.id), ViewerFrame{fmt.Sprintf("%v:%v", frame.Fn, frame.Line), parent.id}) 1144 } 1145 return ctx.buildBranch(node, stk) 1146 } 1147 1148 func isSystemGoroutine(entryFn string) bool { 1149 // This mimics runtime.isSystemGoroutine as closely as 1150 // possible. 1151 return entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.") 1152 } 1153 1154 // firstTimestamp returns the timestamp of the first event record. 1155 func firstTimestamp() int64 { 1156 res, _ := parseTrace() 1157 if len(res.Events) > 0 { 1158 return res.Events[0].Ts 1159 } 1160 return 0 1161 } 1162 1163 // lastTimestamp returns the timestamp of the last event record. 1164 func lastTimestamp() int64 { 1165 res, _ := parseTrace() 1166 if n := len(res.Events); n > 1 { 1167 return res.Events[n-1].Ts 1168 } 1169 return 0 1170 } 1171 1172 type jsonWriter struct { 1173 w io.Writer 1174 enc *json.Encoder 1175 } 1176 1177 func viewerDataTraceConsumer(w io.Writer, start, end int64) traceConsumer { 1178 frames := make(map[string]ViewerFrame) 1179 enc := json.NewEncoder(w) 1180 written := 0 1181 index := int64(-1) 1182 1183 io.WriteString(w, "{") 1184 return traceConsumer{ 1185 consumeTimeUnit: func(unit string) { 1186 io.WriteString(w, `"displayTimeUnit":`) 1187 enc.Encode(unit) 1188 io.WriteString(w, ",") 1189 }, 1190 consumeViewerEvent: func(v *ViewerEvent, required bool) { 1191 index++ 1192 if !required && (index < start || index > end) { 1193 // not in the range. Skip! 1194 return 1195 } 1196 if written == 0 { 1197 io.WriteString(w, `"traceEvents": [`) 1198 } 1199 if written > 0 { 1200 io.WriteString(w, ",") 1201 } 1202 enc.Encode(v) 1203 // TODO: get rid of the extra \n inserted by enc.Encode. 1204 // Same should be applied to splittingTraceConsumer. 1205 written++ 1206 }, 1207 consumeViewerFrame: func(k string, v ViewerFrame) { 1208 frames[k] = v 1209 }, 1210 flush: func() { 1211 io.WriteString(w, `], "stackFrames":`) 1212 enc.Encode(frames) 1213 io.WriteString(w, `}`) 1214 }, 1215 } 1216 } 1217 1218 // Mapping from more reasonable color names to the reserved color names in 1219 // https://github.com/catapult-project/catapult/blob/master/tracing/tracing/base/color_scheme.html#L50 1220 // The chrome trace viewer allows only those as cname values. 1221 const ( 1222 colorLightMauve = "thread_state_uninterruptible" // 182, 125, 143 1223 colorOrange = "thread_state_iowait" // 255, 140, 0 1224 colorSeafoamGreen = "thread_state_running" // 126, 200, 148 1225 colorVistaBlue = "thread_state_runnable" // 133, 160, 210 1226 colorTan = "thread_state_unknown" // 199, 155, 125 1227 colorIrisBlue = "background_memory_dump" // 0, 180, 180 1228 colorMidnightBlue = "light_memory_dump" // 0, 0, 180 1229 colorDeepMagenta = "detailed_memory_dump" // 180, 0, 180 1230 colorBlue = "vsync_highlight_color" // 0, 0, 255 1231 colorGrey = "generic_work" // 125, 125, 125 1232 colorGreen = "good" // 0, 125, 0 1233 colorDarkGoldenrod = "bad" // 180, 125, 0 1234 colorPeach = "terrible" // 180, 0, 0 1235 colorBlack = "black" // 0, 0, 0 1236 colorLightGrey = "grey" // 221, 221, 221 1237 colorWhite = "white" // 255, 255, 255 1238 colorYellow = "yellow" // 255, 255, 0 1239 colorOlive = "olive" // 100, 100, 0 1240 colorCornflowerBlue = "rail_response" // 67, 135, 253 1241 colorSunsetOrange = "rail_animation" // 244, 74, 63 1242 colorTangerine = "rail_idle" // 238, 142, 0 1243 colorShamrockGreen = "rail_load" // 13, 168, 97 1244 colorGreenishYellow = "startup" // 230, 230, 0 1245 colorDarkGrey = "heap_dump_stack_frame" // 128, 128, 128 1246 colorTawny = "heap_dump_child_node_arrow" // 204, 102, 0 1247 colorLemon = "cq_build_running" // 255, 255, 119 1248 colorLime = "cq_build_passed" // 153, 238, 102 1249 colorPink = "cq_build_failed" // 238, 136, 136 1250 colorSilver = "cq_build_abandoned" // 187, 187, 187 1251 colorManzGreen = "cq_build_attempt_runnig" // 222, 222, 75 1252 colorKellyGreen = "cq_build_attempt_passed" // 108, 218, 35 1253 colorAnotherGrey = "cq_build_attempt_failed" // 187, 187, 187 1254 ) 1255 1256 var colorForTask = []string{ 1257 colorLightMauve, 1258 colorOrange, 1259 colorSeafoamGreen, 1260 colorVistaBlue, 1261 colorTan, 1262 colorMidnightBlue, 1263 colorIrisBlue, 1264 colorDeepMagenta, 1265 colorGreen, 1266 colorDarkGoldenrod, 1267 colorPeach, 1268 colorOlive, 1269 colorCornflowerBlue, 1270 colorSunsetOrange, 1271 colorTangerine, 1272 colorShamrockGreen, 1273 colorTawny, 1274 colorLemon, 1275 colorLime, 1276 colorPink, 1277 colorSilver, 1278 colorManzGreen, 1279 colorKellyGreen, 1280 } 1281 1282 func pickTaskColor(id uint64) string { 1283 idx := id % uint64(len(colorForTask)) 1284 return colorForTask[idx] 1285 }