github.com/hxx258456/ccgo@v0.0.5-0.20230213014102-48b35f46f66f/net/trace/events.go (about) 1 // Copyright 2015 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 trace 6 7 import ( 8 "bytes" 9 "fmt" 10 "html/template" 11 "io" 12 "log" 13 "runtime" 14 "sort" 15 "strconv" 16 "strings" 17 "sync" 18 "sync/atomic" 19 "text/tabwriter" 20 "time" 21 22 http "github.com/hxx258456/ccgo/gmhttp" 23 ) 24 25 const maxEventsPerLog = 100 26 27 type bucket struct { 28 MaxErrAge time.Duration 29 String string 30 } 31 32 var buckets = []bucket{ 33 {0, "total"}, 34 {10 * time.Second, "errs<10s"}, 35 {1 * time.Minute, "errs<1m"}, 36 {10 * time.Minute, "errs<10m"}, 37 {1 * time.Hour, "errs<1h"}, 38 {10 * time.Hour, "errs<10h"}, 39 {24000 * time.Hour, "errors"}, 40 } 41 42 // RenderEvents renders the HTML page typically served at /debug/events. 43 // It does not do any auth checking. The request may be nil. 44 // 45 // Most users will use the Events handler. 46 func RenderEvents(w http.ResponseWriter, req *http.Request, sensitive bool) { 47 now := time.Now() 48 data := &struct { 49 Families []string // family names 50 Buckets []bucket 51 Counts [][]int // eventLog count per family/bucket 52 53 // Set when a bucket has been selected. 54 Family string 55 Bucket int 56 EventLogs eventLogs 57 Expanded bool 58 }{ 59 Buckets: buckets, 60 } 61 62 data.Families = make([]string, 0, len(families)) 63 famMu.RLock() 64 for name := range families { 65 data.Families = append(data.Families, name) 66 } 67 famMu.RUnlock() 68 sort.Strings(data.Families) 69 70 // Count the number of eventLogs in each family for each error age. 71 data.Counts = make([][]int, len(data.Families)) 72 for i, name := range data.Families { 73 // TODO(sameer): move this loop under the family lock. 74 f := getEventFamily(name) 75 data.Counts[i] = make([]int, len(data.Buckets)) 76 for j, b := range data.Buckets { 77 data.Counts[i][j] = f.Count(now, b.MaxErrAge) 78 } 79 } 80 81 if req != nil { 82 var ok bool 83 data.Family, data.Bucket, ok = parseEventsArgs(req) 84 if !ok { 85 // No-op 86 } else { 87 data.EventLogs = getEventFamily(data.Family).Copy(now, buckets[data.Bucket].MaxErrAge) 88 } 89 if data.EventLogs != nil { 90 defer data.EventLogs.Free() 91 sort.Sort(data.EventLogs) 92 } 93 if exp, err := strconv.ParseBool(req.FormValue("exp")); err == nil { 94 data.Expanded = exp 95 } 96 } 97 98 famMu.RLock() 99 defer famMu.RUnlock() 100 if err := eventsTmpl().Execute(w, data); err != nil { 101 log.Printf("net/trace: Failed executing template: %v", err) 102 } 103 } 104 105 func parseEventsArgs(req *http.Request) (fam string, b int, ok bool) { 106 fam, bStr := req.FormValue("fam"), req.FormValue("b") 107 if fam == "" || bStr == "" { 108 return "", 0, false 109 } 110 b, err := strconv.Atoi(bStr) 111 if err != nil || b < 0 || b >= len(buckets) { 112 return "", 0, false 113 } 114 return fam, b, true 115 } 116 117 // An EventLog provides a log of events associated with a specific object. 118 type EventLog interface { 119 // Printf formats its arguments with fmt.Sprintf and adds the 120 // result to the event log. 121 Printf(format string, a ...interface{}) 122 123 // Errorf is like Printf, but it marks this event as an error. 124 Errorf(format string, a ...interface{}) 125 126 // Finish declares that this event log is complete. 127 // The event log should not be used after calling this method. 128 Finish() 129 } 130 131 // NewEventLog returns a new EventLog with the specified family name 132 // and title. 133 func NewEventLog(family, title string) EventLog { 134 el := newEventLog() 135 el.ref() 136 el.Family, el.Title = family, title 137 el.Start = time.Now() 138 el.events = make([]logEntry, 0, maxEventsPerLog) 139 el.stack = make([]uintptr, 32) 140 n := runtime.Callers(2, el.stack) 141 el.stack = el.stack[:n] 142 143 getEventFamily(family).add(el) 144 return el 145 } 146 147 func (el *eventLog) Finish() { 148 getEventFamily(el.Family).remove(el) 149 el.unref() // matches ref in New 150 } 151 152 var ( 153 famMu sync.RWMutex 154 families = make(map[string]*eventFamily) // family name => family 155 ) 156 157 func getEventFamily(fam string) *eventFamily { 158 famMu.Lock() 159 defer famMu.Unlock() 160 f := families[fam] 161 if f == nil { 162 f = &eventFamily{} 163 families[fam] = f 164 } 165 return f 166 } 167 168 type eventFamily struct { 169 mu sync.RWMutex 170 eventLogs eventLogs 171 } 172 173 func (f *eventFamily) add(el *eventLog) { 174 f.mu.Lock() 175 f.eventLogs = append(f.eventLogs, el) 176 f.mu.Unlock() 177 } 178 179 func (f *eventFamily) remove(el *eventLog) { 180 f.mu.Lock() 181 defer f.mu.Unlock() 182 for i, el0 := range f.eventLogs { 183 if el == el0 { 184 copy(f.eventLogs[i:], f.eventLogs[i+1:]) 185 f.eventLogs = f.eventLogs[:len(f.eventLogs)-1] 186 return 187 } 188 } 189 } 190 191 func (f *eventFamily) Count(now time.Time, maxErrAge time.Duration) (n int) { 192 f.mu.RLock() 193 defer f.mu.RUnlock() 194 for _, el := range f.eventLogs { 195 if el.hasRecentError(now, maxErrAge) { 196 n++ 197 } 198 } 199 return 200 } 201 202 func (f *eventFamily) Copy(now time.Time, maxErrAge time.Duration) (els eventLogs) { 203 f.mu.RLock() 204 defer f.mu.RUnlock() 205 els = make(eventLogs, 0, len(f.eventLogs)) 206 for _, el := range f.eventLogs { 207 if el.hasRecentError(now, maxErrAge) { 208 el.ref() 209 els = append(els, el) 210 } 211 } 212 return 213 } 214 215 type eventLogs []*eventLog 216 217 // Free calls unref on each element of the list. 218 func (els eventLogs) Free() { 219 for _, el := range els { 220 el.unref() 221 } 222 } 223 224 // eventLogs may be sorted in reverse chronological order. 225 func (els eventLogs) Len() int { return len(els) } 226 func (els eventLogs) Less(i, j int) bool { return els[i].Start.After(els[j].Start) } 227 func (els eventLogs) Swap(i, j int) { els[i], els[j] = els[j], els[i] } 228 229 // A logEntry is a timestamped log entry in an event log. 230 type logEntry struct { 231 When time.Time 232 Elapsed time.Duration // since previous event in log 233 NewDay bool // whether this event is on a different day to the previous event 234 What string 235 IsErr bool 236 } 237 238 // WhenString returns a string representation of the elapsed time of the event. 239 // It will include the date if midnight was crossed. 240 func (e logEntry) WhenString() string { 241 if e.NewDay { 242 return e.When.Format("2006/01/02 15:04:05.000000") 243 } 244 return e.When.Format("15:04:05.000000") 245 } 246 247 // An eventLog represents an active event log. 248 type eventLog struct { 249 // Family is the top-level grouping of event logs to which this belongs. 250 Family string 251 252 // Title is the title of this event log. 253 Title string 254 255 // Timing information. 256 Start time.Time 257 258 // Call stack where this event log was created. 259 stack []uintptr 260 261 // Append-only sequence of events. 262 // 263 // TODO(sameer): change this to a ring buffer to avoid the array copy 264 // when we hit maxEventsPerLog. 265 mu sync.RWMutex 266 events []logEntry 267 LastErrorTime time.Time 268 discarded int 269 270 refs int32 // how many buckets this is in 271 } 272 273 func (el *eventLog) reset() { 274 // Clear all but the mutex. Mutexes may not be copied, even when unlocked. 275 el.Family = "" 276 el.Title = "" 277 el.Start = time.Time{} 278 el.stack = nil 279 el.events = nil 280 el.LastErrorTime = time.Time{} 281 el.discarded = 0 282 el.refs = 0 283 } 284 285 func (el *eventLog) hasRecentError(now time.Time, maxErrAge time.Duration) bool { 286 if maxErrAge == 0 { 287 return true 288 } 289 el.mu.RLock() 290 defer el.mu.RUnlock() 291 return now.Sub(el.LastErrorTime) < maxErrAge 292 } 293 294 // delta returns the elapsed time since the last event or the log start, 295 // and whether it spans midnight. 296 // L >= el.mu 297 func (el *eventLog) delta(t time.Time) (time.Duration, bool) { 298 if len(el.events) == 0 { 299 return t.Sub(el.Start), false 300 } 301 prev := el.events[len(el.events)-1].When 302 return t.Sub(prev), prev.Day() != t.Day() 303 304 } 305 306 func (el *eventLog) Printf(format string, a ...interface{}) { 307 el.printf(false, format, a...) 308 } 309 310 func (el *eventLog) Errorf(format string, a ...interface{}) { 311 el.printf(true, format, a...) 312 } 313 314 func (el *eventLog) printf(isErr bool, format string, a ...interface{}) { 315 e := logEntry{When: time.Now(), IsErr: isErr, What: fmt.Sprintf(format, a...)} 316 el.mu.Lock() 317 e.Elapsed, e.NewDay = el.delta(e.When) 318 if len(el.events) < maxEventsPerLog { 319 el.events = append(el.events, e) 320 } else { 321 // Discard the oldest event. 322 if el.discarded == 0 { 323 // el.discarded starts at two to count for the event it 324 // is replacing, plus the next one that we are about to 325 // drop. 326 el.discarded = 2 327 } else { 328 el.discarded++ 329 } 330 // TODO(sameer): if this causes allocations on a critical path, 331 // change eventLog.What to be a fmt.Stringer, as in trace.go. 332 el.events[0].What = fmt.Sprintf("(%d events discarded)", el.discarded) 333 // The timestamp of the discarded meta-event should be 334 // the time of the last event it is representing. 335 el.events[0].When = el.events[1].When 336 copy(el.events[1:], el.events[2:]) 337 el.events[maxEventsPerLog-1] = e 338 } 339 if e.IsErr { 340 el.LastErrorTime = e.When 341 } 342 el.mu.Unlock() 343 } 344 345 func (el *eventLog) ref() { 346 atomic.AddInt32(&el.refs, 1) 347 } 348 349 func (el *eventLog) unref() { 350 if atomic.AddInt32(&el.refs, -1) == 0 { 351 freeEventLog(el) 352 } 353 } 354 355 func (el *eventLog) When() string { 356 return el.Start.Format("2006/01/02 15:04:05.000000") 357 } 358 359 func (el *eventLog) ElapsedTime() string { 360 elapsed := time.Since(el.Start) 361 return fmt.Sprintf("%.6f", elapsed.Seconds()) 362 } 363 364 func (el *eventLog) Stack() string { 365 buf := new(bytes.Buffer) 366 tw := tabwriter.NewWriter(buf, 1, 8, 1, '\t', 0) 367 printStackRecord(tw, el.stack) 368 tw.Flush() 369 return buf.String() 370 } 371 372 // printStackRecord prints the function + source line information 373 // for a single stack trace. 374 // Adapted from runtime/pprof/pprof.go. 375 func printStackRecord(w io.Writer, stk []uintptr) { 376 for _, pc := range stk { 377 f := runtime.FuncForPC(pc) 378 if f == nil { 379 continue 380 } 381 file, line := f.FileLine(pc) 382 name := f.Name() 383 // Hide runtime.goexit and any runtime functions at the beginning. 384 if strings.HasPrefix(name, "runtime.") { 385 continue 386 } 387 fmt.Fprintf(w, "# %s\t%s:%d\n", name, file, line) 388 } 389 } 390 391 func (el *eventLog) Events() []logEntry { 392 el.mu.RLock() 393 defer el.mu.RUnlock() 394 return el.events 395 } 396 397 // freeEventLogs is a freelist of *eventLog 398 var freeEventLogs = make(chan *eventLog, 1000) 399 400 // newEventLog returns a event log ready to use. 401 func newEventLog() *eventLog { 402 select { 403 case el := <-freeEventLogs: 404 return el 405 default: 406 return new(eventLog) 407 } 408 } 409 410 // freeEventLog adds el to freeEventLogs if there's room. 411 // This is non-blocking. 412 func freeEventLog(el *eventLog) { 413 el.reset() 414 select { 415 case freeEventLogs <- el: 416 default: 417 } 418 } 419 420 var eventsTmplCache *template.Template 421 var eventsTmplOnce sync.Once 422 423 func eventsTmpl() *template.Template { 424 eventsTmplOnce.Do(func() { 425 eventsTmplCache = template.Must(template.New("events").Funcs(template.FuncMap{ 426 "elapsed": elapsed, 427 "trimSpace": strings.TrimSpace, 428 }).Parse(eventsHTML)) 429 }) 430 return eventsTmplCache 431 } 432 433 const eventsHTML = ` 434 <html> 435 <head> 436 <title>events</title> 437 </head> 438 <style type="text/css"> 439 body { 440 font-family: sans-serif; 441 } 442 table#req-status td.family { 443 padding-right: 2em; 444 } 445 table#req-status td.active { 446 padding-right: 1em; 447 } 448 table#req-status td.empty { 449 color: #aaa; 450 } 451 table#reqs { 452 margin-top: 1em; 453 } 454 table#reqs tr.first { 455 {{if $.Expanded}}font-weight: bold;{{end}} 456 } 457 table#reqs td { 458 font-family: monospace; 459 } 460 table#reqs td.when { 461 text-align: right; 462 white-space: nowrap; 463 } 464 table#reqs td.elapsed { 465 padding: 0 0.5em; 466 text-align: right; 467 white-space: pre; 468 width: 10em; 469 } 470 address { 471 font-size: smaller; 472 margin-top: 5em; 473 } 474 </style> 475 <body> 476 477 <h1>/debug/events</h1> 478 479 <table id="req-status"> 480 {{range $i, $fam := .Families}} 481 <tr> 482 <td class="family">{{$fam}}</td> 483 484 {{range $j, $bucket := $.Buckets}} 485 {{$n := index $.Counts $i $j}} 486 <td class="{{if not $bucket.MaxErrAge}}active{{end}}{{if not $n}}empty{{end}}"> 487 {{if $n}}<a href="?fam={{$fam}}&b={{$j}}{{if $.Expanded}}&exp=1{{end}}">{{end}} 488 [{{$n}} {{$bucket.String}}] 489 {{if $n}}</a>{{end}} 490 </td> 491 {{end}} 492 493 </tr>{{end}} 494 </table> 495 496 {{if $.EventLogs}} 497 <hr /> 498 <h3>Family: {{$.Family}}</h3> 499 500 {{if $.Expanded}}<a href="?fam={{$.Family}}&b={{$.Bucket}}">{{end}} 501 [Summary]{{if $.Expanded}}</a>{{end}} 502 503 {{if not $.Expanded}}<a href="?fam={{$.Family}}&b={{$.Bucket}}&exp=1">{{end}} 504 [Expanded]{{if not $.Expanded}}</a>{{end}} 505 506 <table id="reqs"> 507 <tr><th>When</th><th>Elapsed</th></tr> 508 {{range $el := $.EventLogs}} 509 <tr class="first"> 510 <td class="when">{{$el.When}}</td> 511 <td class="elapsed">{{$el.ElapsedTime}}</td> 512 <td>{{$el.Title}} 513 </tr> 514 {{if $.Expanded}} 515 <tr> 516 <td class="when"></td> 517 <td class="elapsed"></td> 518 <td><pre>{{$el.Stack|trimSpace}}</pre></td> 519 </tr> 520 {{range $el.Events}} 521 <tr> 522 <td class="when">{{.WhenString}}</td> 523 <td class="elapsed">{{elapsed .Elapsed}}</td> 524 <td>.{{if .IsErr}}E{{else}}.{{end}}. {{.What}}</td> 525 </tr> 526 {{end}} 527 {{end}} 528 {{end}} 529 </table> 530 {{end}} 531 </body> 532 </html> 533 `