From eadb0fbee0c545711467f8ae3bc54bfb8931866e Mon Sep 17 00:00:00 2001 From: Joe Onorato Date: Sat, 24 Jun 2023 15:03:28 -0700 Subject: [PATCH] After a build action fails, stop printing more output. Often the slow commands (errorprone happens to be particularly bad) print a lot, so this should make it easier to find the error without lots of scrolling. This doesn't attempt to parse the output and re-display errors, so if a command prints a thousand warnings with one error in the middle, it'll still be hard to find the error. Bug: 277114612 Test: cd build/soong/ui/terminal ; go test Change-Id: I6c8285fc2c6e4fc345de57b2c15bc5e7d46b1d1f --- ui/terminal/smart_status.go | 34 ++++++-- ui/terminal/status_test.go | 156 ++++++++++++++++++++++++++++++++++++ 2 files changed, 185 insertions(+), 5 deletions(-) diff --git a/ui/terminal/smart_status.go b/ui/terminal/smart_status.go index 06a4064ff..3880b04a8 100644 --- a/ui/terminal/smart_status.go +++ b/ui/terminal/smart_status.go @@ -53,6 +53,13 @@ type smartStatusOutput struct { done chan bool sigwinch chan os.Signal sigwinchHandled chan bool + + // Once there is a failure, we stop printing command output so the error + // is easier to find + haveFailures bool + // If we are dropping errors, then at the end, we report a message to go + // look in the verbose log if you want that command output. + postFailureActionCount int } // NewSmartStatusOutput returns a StatusOutput that represents the @@ -165,12 +172,20 @@ func (s *smartStatusOutput) FinishAction(result status.ActionResult, counts stat } } + s.statusLine(progress) + + // Stop printing when there are failures, but don't skip actions that also have their own errors. if output != "" { - s.statusLine(progress) - s.requestLine() - s.print(output) - } else { - s.statusLine(progress) + if !s.haveFailures || result.Error != nil { + s.requestLine() + s.print(output) + } else { + s.postFailureActionCount++ + } + } + + if result.Error != nil { + s.haveFailures = true } } @@ -187,6 +202,15 @@ func (s *smartStatusOutput) Flush() { s.stopSigwinch() + if s.postFailureActionCount > 0 { + s.requestLine() + if s.postFailureActionCount == 1 { + s.print(fmt.Sprintf("There was 1 action that completed after the action that failed. See verbose.log.gz for its output.")) + } else { + s.print(fmt.Sprintf("There were %d actions that completed after the action that failed. See verbose.log.gz for their output.", s.postFailureActionCount)) + } + } + s.requestLine() s.runningActions = nil diff --git a/ui/terminal/status_test.go b/ui/terminal/status_test.go index b9057d298..8dd180967 100644 --- a/ui/terminal/status_test.go +++ b/ui/terminal/status_test.go @@ -295,3 +295,159 @@ func TestSmartStatusOutputWidthChange(t *testing.T) { t.Errorf("want:\n%q\ngot:\n%q", w, g) } } + +func TestSmartStatusDoesntHideAfterSucecss(t *testing.T) { + os.Setenv(tableHeightEnVar, "") + + smart := &fakeSmartTerminal{termWidth: 40} + stat := NewStatusOutput(smart, "", false, false, false) + smartStat := stat.(*smartStatusOutput) + smartStat.sigwinchHandled = make(chan bool) + + runner := newRunner(stat, 2) + + action1 := &status.Action{Description: "action1"} + result1 := status.ActionResult{ + Action: action1, + Output: "Output1", + } + + action2 := &status.Action{Description: "action2"} + result2 := status.ActionResult{ + Action: action2, + Output: "Output2", + } + + runner.startAction(action1) + runner.startAction(action2) + runner.finishAction(result1) + runner.finishAction(result2) + + stat.Flush() + + w := "\r\x1b[1m[ 0% 0/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 0% 0/2] action2\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action1\x1b[0m\x1b[K\nOutput1\n\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\nOutput2\n" + + if g := smart.String(); g != w { + t.Errorf("want:\n%q\ngot:\n%q", w, g) + } +} + +func TestSmartStatusHideAfterFailure(t *testing.T) { + os.Setenv(tableHeightEnVar, "") + + smart := &fakeSmartTerminal{termWidth: 40} + stat := NewStatusOutput(smart, "", false, false, false) + smartStat := stat.(*smartStatusOutput) + smartStat.sigwinchHandled = make(chan bool) + + runner := newRunner(stat, 2) + + action1 := &status.Action{Description: "action1"} + result1 := status.ActionResult{ + Action: action1, + Output: "Output1", + Error: fmt.Errorf("Error1"), + } + + action2 := &status.Action{Description: "action2"} + result2 := status.ActionResult{ + Action: action2, + Output: "Output2", + } + + runner.startAction(action1) + runner.startAction(action2) + runner.finishAction(result1) + runner.finishAction(result2) + + stat.Flush() + + w := "\r\x1b[1m[ 0% 0/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 0% 0/2] action2\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action1\x1b[0m\x1b[K\nFAILED: \nOutput1\n\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\nThere was 1 action that completed after the action that failed. See verbose.log.gz for its output.\n" + + if g := smart.String(); g != w { + t.Errorf("want:\n%q\ngot:\n%q", w, g) + } +} + +func TestSmartStatusHideAfterFailurePlural(t *testing.T) { + os.Setenv(tableHeightEnVar, "") + + smart := &fakeSmartTerminal{termWidth: 40} + stat := NewStatusOutput(smart, "", false, false, false) + smartStat := stat.(*smartStatusOutput) + smartStat.sigwinchHandled = make(chan bool) + + runner := newRunner(stat, 2) + + action1 := &status.Action{Description: "action1"} + result1 := status.ActionResult{ + Action: action1, + Output: "Output1", + Error: fmt.Errorf("Error1"), + } + + action2 := &status.Action{Description: "action2"} + result2 := status.ActionResult{ + Action: action2, + Output: "Output2", + } + + action3 := &status.Action{Description: "action3"} + result3 := status.ActionResult{ + Action: action3, + Output: "Output3", + } + + runner.startAction(action1) + runner.startAction(action2) + runner.startAction(action3) + runner.finishAction(result1) + runner.finishAction(result2) + runner.finishAction(result3) + + stat.Flush() + + w := "\r\x1b[1m[ 0% 0/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 0% 0/2] action2\x1b[0m\x1b[K\r\x1b[1m[ 0% 0/2] action3\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action1\x1b[0m\x1b[K\nFAILED: \nOutput1\n\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\r\x1b[1m[150% 3/2] action3\x1b[0m\x1b[K\nThere were 2 actions that completed after the action that failed. See verbose.log.gz for their output.\n" + + if g := smart.String(); g != w { + t.Errorf("want:\n%q\ngot:\n%q", w, g) + } +} + +func TestSmartStatusDontHideErrorAfterFailure(t *testing.T) { + os.Setenv(tableHeightEnVar, "") + + smart := &fakeSmartTerminal{termWidth: 40} + stat := NewStatusOutput(smart, "", false, false, false) + smartStat := stat.(*smartStatusOutput) + smartStat.sigwinchHandled = make(chan bool) + + runner := newRunner(stat, 2) + + action1 := &status.Action{Description: "action1"} + result1 := status.ActionResult{ + Action: action1, + Output: "Output1", + Error: fmt.Errorf("Error1"), + } + + action2 := &status.Action{Description: "action2"} + result2 := status.ActionResult{ + Action: action2, + Output: "Output2", + Error: fmt.Errorf("Error1"), + } + + runner.startAction(action1) + runner.startAction(action2) + runner.finishAction(result1) + runner.finishAction(result2) + + stat.Flush() + + w := "\r\x1b[1m[ 0% 0/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 0% 0/2] action2\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action1\x1b[0m\x1b[K\nFAILED: \nOutput1\n\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\nFAILED: \nOutput2\n" + + if g := smart.String(); g != w { + t.Errorf("want:\n%q\ngot:\n%q", w, g) + } +}