1package progressui 2 3import ( 4 "bytes" 5 "context" 6 "fmt" 7 "io" 8 "os" 9 "sort" 10 "strconv" 11 "strings" 12 "time" 13 14 "github.com/containerd/console" 15 "github.com/jaguilar/vt100" 16 "github.com/moby/buildkit/client" 17 "github.com/morikuni/aec" 18 digest "github.com/opencontainers/go-digest" 19 "github.com/tonistiigi/units" 20 "golang.org/x/time/rate" 21) 22 23func DisplaySolveStatus(ctx context.Context, phase string, c console.Console, w io.Writer, ch chan *client.SolveStatus) error { 24 25 modeConsole := c != nil 26 27 disp := &display{c: c, phase: phase} 28 printer := &textMux{w: w} 29 30 if disp.phase == "" { 31 disp.phase = "Building" 32 } 33 34 t := newTrace(w, modeConsole) 35 36 tickerTimeout := 150 * time.Millisecond 37 displayTimeout := 100 * time.Millisecond 38 39 if v := os.Getenv("TTY_DISPLAY_RATE"); v != "" { 40 if r, err := strconv.ParseInt(v, 10, 64); err == nil { 41 tickerTimeout = time.Duration(r) * time.Millisecond 42 displayTimeout = time.Duration(r) * time.Millisecond 43 } 44 } 45 46 var done bool 47 ticker := time.NewTicker(tickerTimeout) 48 defer ticker.Stop() 49 50 displayLimiter := rate.NewLimiter(rate.Every(displayTimeout), 1) 51 52 var height int 53 width, _ := disp.getSize() 54 for { 55 select { 56 case <-ctx.Done(): 57 return ctx.Err() 58 case <-ticker.C: 59 case ss, ok := <-ch: 60 if ok { 61 t.update(ss, width) 62 } else { 63 done = true 64 } 65 } 66 67 if modeConsole { 68 width, height = disp.getSize() 69 if done { 70 disp.print(t.displayInfo(), width, height, true) 71 t.printErrorLogs(c) 72 return nil 73 } else if displayLimiter.Allow() { 74 ticker.Stop() 75 ticker = time.NewTicker(tickerTimeout) 76 disp.print(t.displayInfo(), width, height, false) 77 } 78 } else { 79 if done || displayLimiter.Allow() { 80 printer.print(t) 81 if done { 82 t.printErrorLogs(w) 83 return nil 84 } 85 ticker.Stop() 86 ticker = time.NewTicker(tickerTimeout) 87 } 88 } 89 } 90} 91 92const termHeight = 6 93const termPad = 10 94 95type displayInfo struct { 96 startTime time.Time 97 jobs []*job 98 countTotal int 99 countCompleted int 100} 101 102type job struct { 103 startTime *time.Time 104 completedTime *time.Time 105 name string 106 status string 107 hasError bool 108 isCanceled bool 109 vertex *vertex 110 showTerm bool 111} 112 113type trace struct { 114 w io.Writer 115 localTimeDiff time.Duration 116 vertexes []*vertex 117 byDigest map[digest.Digest]*vertex 118 nextIndex int 119 updates map[digest.Digest]struct{} 120 modeConsole bool 121} 122 123type vertex struct { 124 *client.Vertex 125 statuses []*status 126 byID map[string]*status 127 indent string 128 index int 129 130 logs [][]byte 131 logsPartial bool 132 logsOffset int 133 prev *client.Vertex 134 events []string 135 lastBlockTime *time.Time 136 count int 137 statusUpdates map[string]struct{} 138 139 jobs []*job 140 jobCached bool 141 142 term *vt100.VT100 143 termBytes int 144 termCount int 145} 146 147func (v *vertex) update(c int) { 148 if v.count == 0 { 149 now := time.Now() 150 v.lastBlockTime = &now 151 } 152 v.count += c 153} 154 155type status struct { 156 *client.VertexStatus 157} 158 159func newTrace(w io.Writer, modeConsole bool) *trace { 160 return &trace{ 161 byDigest: make(map[digest.Digest]*vertex), 162 updates: make(map[digest.Digest]struct{}), 163 w: w, 164 modeConsole: modeConsole, 165 } 166} 167 168func (t *trace) triggerVertexEvent(v *client.Vertex) { 169 if v.Started == nil { 170 return 171 } 172 173 var old client.Vertex 174 vtx := t.byDigest[v.Digest] 175 if v := vtx.prev; v != nil { 176 old = *v 177 } 178 179 changed := false 180 if v.Digest != old.Digest { 181 changed = true 182 } 183 if v.Name != old.Name { 184 changed = true 185 } 186 if v.Started != old.Started { 187 if v.Started != nil && old.Started == nil || !v.Started.Equal(*old.Started) { 188 changed = true 189 } 190 } 191 if v.Completed != old.Completed && v.Completed != nil { 192 changed = true 193 } 194 if v.Cached != old.Cached { 195 changed = true 196 } 197 if v.Error != old.Error { 198 changed = true 199 } 200 201 if changed { 202 vtx.update(1) 203 t.updates[v.Digest] = struct{}{} 204 } 205 206 t.byDigest[v.Digest].prev = v 207} 208 209func (t *trace) update(s *client.SolveStatus, termWidth int) { 210 for _, v := range s.Vertexes { 211 prev, ok := t.byDigest[v.Digest] 212 if !ok { 213 t.nextIndex++ 214 t.byDigest[v.Digest] = &vertex{ 215 byID: make(map[string]*status), 216 statusUpdates: make(map[string]struct{}), 217 index: t.nextIndex, 218 } 219 if t.modeConsole { 220 t.byDigest[v.Digest].term = vt100.NewVT100(termHeight, termWidth-termPad) 221 } 222 } 223 t.triggerVertexEvent(v) 224 if v.Started != nil && (prev == nil || prev.Started == nil) { 225 if t.localTimeDiff == 0 { 226 t.localTimeDiff = time.Since(*v.Started) 227 } 228 t.vertexes = append(t.vertexes, t.byDigest[v.Digest]) 229 } 230 // allow a duplicate initial vertex that shouldn't reset state 231 if !(prev != nil && prev.Started != nil && v.Started == nil) { 232 t.byDigest[v.Digest].Vertex = v 233 } 234 t.byDigest[v.Digest].jobCached = false 235 } 236 for _, s := range s.Statuses { 237 v, ok := t.byDigest[s.Vertex] 238 if !ok { 239 continue // shouldn't happen 240 } 241 v.jobCached = false 242 prev, ok := v.byID[s.ID] 243 if !ok { 244 v.byID[s.ID] = &status{VertexStatus: s} 245 } 246 if s.Started != nil && (prev == nil || prev.Started == nil) { 247 v.statuses = append(v.statuses, v.byID[s.ID]) 248 } 249 v.byID[s.ID].VertexStatus = s 250 v.statusUpdates[s.ID] = struct{}{} 251 t.updates[v.Digest] = struct{}{} 252 v.update(1) 253 } 254 for _, l := range s.Logs { 255 v, ok := t.byDigest[l.Vertex] 256 if !ok { 257 continue // shouldn't happen 258 } 259 v.jobCached = false 260 if v.term != nil { 261 if v.term.Width != termWidth { 262 v.term.Resize(termHeight, termWidth-termPad) 263 } 264 v.termBytes += len(l.Data) 265 v.term.Write(l.Data) // error unhandled on purpose. don't trust vt100 266 } 267 i := 0 268 complete := split(l.Data, byte('\n'), func(dt []byte) { 269 if v.logsPartial && len(v.logs) != 0 && i == 0 { 270 v.logs[len(v.logs)-1] = append(v.logs[len(v.logs)-1], dt...) 271 } else { 272 ts := time.Duration(0) 273 if v.Started != nil { 274 ts = l.Timestamp.Sub(*v.Started) 275 } 276 prec := 1 277 sec := ts.Seconds() 278 if sec < 10 { 279 prec = 3 280 } else if sec < 100 { 281 prec = 2 282 } 283 v.logs = append(v.logs, []byte(fmt.Sprintf("#%d %s %s", v.index, fmt.Sprintf("%.[2]*[1]f", sec, prec), dt))) 284 } 285 i++ 286 }) 287 v.logsPartial = !complete 288 t.updates[v.Digest] = struct{}{} 289 v.update(1) 290 } 291} 292 293func (t *trace) printErrorLogs(f io.Writer) { 294 for _, v := range t.vertexes { 295 if v.Error != "" && !strings.HasSuffix(v.Error, context.Canceled.Error()) { 296 fmt.Fprintln(f, "------") 297 fmt.Fprintf(f, " > %s:\n", v.Name) 298 for _, l := range v.logs { 299 f.Write(l) 300 fmt.Fprintln(f) 301 } 302 fmt.Fprintln(f, "------") 303 } 304 } 305} 306 307func (t *trace) displayInfo() (d displayInfo) { 308 d.startTime = time.Now() 309 if t.localTimeDiff != 0 { 310 d.startTime = (*t.vertexes[0].Started).Add(t.localTimeDiff) 311 } 312 d.countTotal = len(t.byDigest) 313 for _, v := range t.byDigest { 314 if v.Completed != nil { 315 d.countCompleted++ 316 } 317 } 318 319 for _, v := range t.vertexes { 320 if v.jobCached { 321 d.jobs = append(d.jobs, v.jobs...) 322 continue 323 } 324 var jobs []*job 325 j := &job{ 326 startTime: addTime(v.Started, t.localTimeDiff), 327 completedTime: addTime(v.Completed, t.localTimeDiff), 328 name: strings.Replace(v.Name, "\t", " ", -1), 329 vertex: v, 330 } 331 if v.Error != "" { 332 if strings.HasSuffix(v.Error, context.Canceled.Error()) { 333 j.isCanceled = true 334 j.name = "CANCELED " + j.name 335 } else { 336 j.hasError = true 337 j.name = "ERROR " + j.name 338 } 339 } 340 if v.Cached { 341 j.name = "CACHED " + j.name 342 } 343 j.name = v.indent + j.name 344 jobs = append(jobs, j) 345 for _, s := range v.statuses { 346 j := &job{ 347 startTime: addTime(s.Started, t.localTimeDiff), 348 completedTime: addTime(s.Completed, t.localTimeDiff), 349 name: v.indent + "=> " + s.ID, 350 } 351 if s.Total != 0 { 352 j.status = fmt.Sprintf("%.2f / %.2f", units.Bytes(s.Current), units.Bytes(s.Total)) 353 } else if s.Current != 0 { 354 j.status = fmt.Sprintf("%.2f", units.Bytes(s.Current)) 355 } 356 jobs = append(jobs, j) 357 } 358 d.jobs = append(d.jobs, jobs...) 359 v.jobs = jobs 360 v.jobCached = true 361 } 362 363 return d 364} 365 366func split(dt []byte, sep byte, fn func([]byte)) bool { 367 if len(dt) == 0 { 368 return false 369 } 370 for { 371 if len(dt) == 0 { 372 return true 373 } 374 idx := bytes.IndexByte(dt, sep) 375 if idx == -1 { 376 fn(dt) 377 return false 378 } 379 fn(dt[:idx]) 380 dt = dt[idx+1:] 381 } 382} 383 384func addTime(tm *time.Time, d time.Duration) *time.Time { 385 if tm == nil { 386 return nil 387 } 388 t := (*tm).Add(d) 389 return &t 390} 391 392type display struct { 393 c console.Console 394 phase string 395 lineCount int 396 repeated bool 397} 398 399func (disp *display) getSize() (int, int) { 400 width := 80 401 height := 10 402 if disp.c != nil { 403 size, err := disp.c.Size() 404 if err == nil && size.Width > 0 && size.Height > 0 { 405 width = int(size.Width) 406 height = int(size.Height) 407 } 408 } 409 return width, height 410} 411 412func setupTerminals(jobs []*job, height int, all bool) []*job { 413 var candidates []*job 414 numInUse := 0 415 for _, j := range jobs { 416 if j.vertex != nil && j.vertex.termBytes > 0 && j.completedTime == nil { 417 candidates = append(candidates, j) 418 } 419 if j.completedTime == nil { 420 numInUse++ 421 } 422 } 423 sort.Slice(candidates, func(i, j int) bool { 424 idxI := candidates[i].vertex.termBytes + candidates[i].vertex.termCount*50 425 idxJ := candidates[j].vertex.termBytes + candidates[j].vertex.termCount*50 426 return idxI > idxJ 427 }) 428 429 numFree := height - 2 - numInUse 430 numToHide := 0 431 termLimit := termHeight + 3 432 433 for i := 0; numFree > termLimit && i < len(candidates); i++ { 434 candidates[i].showTerm = true 435 numToHide += candidates[i].vertex.term.UsedHeight() 436 numFree -= termLimit 437 } 438 439 if !all { 440 jobs = wrapHeight(jobs, height-2-numToHide) 441 } 442 443 return jobs 444} 445 446func (disp *display) print(d displayInfo, width, height int, all bool) { 447 // this output is inspired by Buck 448 d.jobs = setupTerminals(d.jobs, height, all) 449 b := aec.EmptyBuilder 450 for i := 0; i <= disp.lineCount; i++ { 451 b = b.Up(1) 452 } 453 if !disp.repeated { 454 b = b.Down(1) 455 } 456 disp.repeated = true 457 fmt.Fprint(disp.c, b.Column(0).ANSI) 458 459 statusStr := "" 460 if d.countCompleted > 0 && d.countCompleted == d.countTotal && all { 461 statusStr = "FINISHED" 462 } 463 464 fmt.Fprint(disp.c, aec.Hide) 465 defer fmt.Fprint(disp.c, aec.Show) 466 467 out := fmt.Sprintf("[+] %s %.1fs (%d/%d) %s", disp.phase, time.Since(d.startTime).Seconds(), d.countCompleted, d.countTotal, statusStr) 468 out = align(out, "", width) 469 fmt.Fprintln(disp.c, out) 470 lineCount := 0 471 for _, j := range d.jobs { 472 endTime := time.Now() 473 if j.completedTime != nil { 474 endTime = *j.completedTime 475 } 476 if j.startTime == nil { 477 continue 478 } 479 dt := endTime.Sub(*j.startTime).Seconds() 480 if dt < 0.05 { 481 dt = 0 482 } 483 pfx := " => " 484 timer := fmt.Sprintf(" %3.1fs\n", dt) 485 status := j.status 486 showStatus := false 487 488 left := width - len(pfx) - len(timer) - 1 489 if status != "" { 490 if left+len(status) > 20 { 491 showStatus = true 492 left -= len(status) + 1 493 } 494 } 495 if left < 12 { // too small screen to show progress 496 continue 497 } 498 name := j.name 499 if len(name) > left { 500 name = name[:left] 501 } 502 503 out := pfx + name 504 if showStatus { 505 out += " " + status 506 } 507 508 out = align(out, timer, width) 509 if j.completedTime != nil { 510 color := aec.BlueF 511 if j.isCanceled { 512 color = aec.YellowF 513 } else if j.hasError { 514 color = aec.RedF 515 } 516 out = aec.Apply(out, color) 517 } 518 fmt.Fprint(disp.c, out) 519 lineCount++ 520 if j.showTerm { 521 term := j.vertex.term 522 term.Resize(termHeight, width-termPad) 523 for _, l := range term.Content { 524 if !isEmpty(l) { 525 out := aec.Apply(fmt.Sprintf(" => => # %s\n", string(l)), aec.Faint) 526 fmt.Fprint(disp.c, out) 527 lineCount++ 528 } 529 } 530 j.vertex.termCount++ 531 j.showTerm = false 532 } 533 } 534 // override previous content 535 if diff := disp.lineCount - lineCount; diff > 0 { 536 for i := 0; i < diff; i++ { 537 fmt.Fprintln(disp.c, strings.Repeat(" ", width)) 538 } 539 fmt.Fprint(disp.c, aec.EmptyBuilder.Up(uint(diff)).Column(0).ANSI) 540 } 541 disp.lineCount = lineCount 542} 543 544func isEmpty(l []rune) bool { 545 for _, r := range l { 546 if r != ' ' { 547 return false 548 } 549 } 550 return true 551} 552 553func align(l, r string, w int) string { 554 return fmt.Sprintf("%-[2]*[1]s %[3]s", l, w-len(r)-1, r) 555} 556 557func wrapHeight(j []*job, limit int) []*job { 558 if limit < 0 { 559 return nil 560 } 561 var wrapped []*job 562 wrapped = append(wrapped, j...) 563 if len(j) > limit { 564 wrapped = wrapped[len(j)-limit:] 565 566 // wrap things around if incomplete jobs were cut 567 var invisible []*job 568 for _, j := range j[:len(j)-limit] { 569 if j.completedTime == nil { 570 invisible = append(invisible, j) 571 } 572 } 573 574 if l := len(invisible); l > 0 { 575 rewrapped := make([]*job, 0, len(wrapped)) 576 for _, j := range wrapped { 577 if j.completedTime == nil || l <= 0 { 578 rewrapped = append(rewrapped, j) 579 } 580 l-- 581 } 582 freespace := len(wrapped) - len(rewrapped) 583 wrapped = append(invisible[len(invisible)-freespace:], rewrapped...) 584 } 585 } 586 return wrapped 587} 588