Files
build_soong/ui/terminal/status_test.go
cherokeeMeta f7119b57ac Highlight build failures in soong output
Summary: When build failures occur, it can be hard to find where the error message begins. We now highlight "FAILURE" in red to make it easier to see what exactly has failed in the output.

Test: execute automated tests with m nothing --no-skip-soong-tests, can also manually test with a build failure and observe red text in the output

Change-Id: Iad3b94cc1c385f0afdebdf12c44843db04ff2bdc
Signed-off-by: Cherokee Toole <cherokee@meta.com>
2024-07-16 18:18:33 +00:00

454 lines
14 KiB
Go

// Copyright 2018 Google Inc. All rights reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package terminal
import (
"bytes"
"fmt"
"os"
"syscall"
"testing"
"android/soong/ui/status"
)
func TestStatusOutput(t *testing.T) {
tests := []struct {
name string
calls func(stat status.StatusOutput)
smart string
simple string
}{
{
name: "two actions",
calls: twoActions,
smart: "\r\x1b[1m[ 0% 0/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action2\x1b[0m\x1b[K\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\n",
simple: "[ 50% 1/2] action1\n[100% 2/2] action2\n",
},
{
name: "two parallel actions",
calls: twoParallelActions,
smart: "\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\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\n",
simple: "[ 50% 1/2] action1\n[100% 2/2] action2\n",
},
{
name: "action with output",
calls: actionsWithOutput,
smart: "\r\x1b[1m[ 0% 0/3] action1\x1b[0m\x1b[K\r\x1b[1m[ 33% 1/3] action1\x1b[0m\x1b[K\r\x1b[1m[ 33% 1/3] action2\x1b[0m\x1b[K\r\x1b[1m[ 66% 2/3] action2\x1b[0m\x1b[K\noutput1\noutput2\n\r\x1b[1m[ 66% 2/3] action3\x1b[0m\x1b[K\r\x1b[1m[100% 3/3] action3\x1b[0m\x1b[K\n",
simple: "[ 33% 1/3] action1\n[ 66% 2/3] action2\noutput1\noutput2\n[100% 3/3] action3\n",
},
{
name: "action with output without newline",
calls: actionsWithOutputWithoutNewline,
smart: "\r\x1b[1m[ 0% 0/3] action1\x1b[0m\x1b[K\r\x1b[1m[ 33% 1/3] action1\x1b[0m\x1b[K\r\x1b[1m[ 33% 1/3] action2\x1b[0m\x1b[K\r\x1b[1m[ 66% 2/3] action2\x1b[0m\x1b[K\noutput1\noutput2\n\r\x1b[1m[ 66% 2/3] action3\x1b[0m\x1b[K\r\x1b[1m[100% 3/3] action3\x1b[0m\x1b[K\n",
simple: "[ 33% 1/3] action1\n[ 66% 2/3] action2\noutput1\noutput2\n[100% 3/3] action3\n",
},
{
name: "action with error",
calls: actionsWithError,
smart: "\r\x1b[1m[ 0% 0/3] action1\x1b[0m\x1b[K\r\x1b[1m[ 33% 1/3] action1\x1b[0m\x1b[K\r\x1b[1m[ 33% 1/3] action2\x1b[0m\x1b[K\r\x1b[1m[ 66% 2/3] action2\x1b[0m\x1b[K\n\x1b[31m\x1b[1mFAILED:\x1b[0m f1 f2\ntouch f1 f2\nerror1\nerror2\n\r\x1b[1m[ 66% 2/3] action3\x1b[0m\x1b[K\r\x1b[1m[100% 3/3] action3\x1b[0m\x1b[K\n",
simple: "[ 33% 1/3] action1\n[ 66% 2/3] action2\nFAILED: f1 f2\ntouch f1 f2\nerror1\nerror2\n[100% 3/3] action3\n",
},
{
name: "action with empty description",
calls: actionWithEmptyDescription,
smart: "\r\x1b[1m[ 0% 0/1] command1\x1b[0m\x1b[K\r\x1b[1m[100% 1/1] command1\x1b[0m\x1b[K\n",
simple: "[100% 1/1] command1\n",
},
{
name: "messages",
calls: actionsWithMessages,
smart: "\r\x1b[1m[ 0% 0/2] action1\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action1\x1b[0m\x1b[K\r\x1b[1mstatus\x1b[0m\x1b[K\r\x1b[Kprint\n\x1b[31m\x1b[1mFAILED:\x1b[0m error\n\r\x1b[1m[ 50% 1/2] action2\x1b[0m\x1b[K\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\n",
simple: "[ 50% 1/2] action1\nstatus\nprint\nFAILED: error\n[100% 2/2] action2\n",
},
{
name: "action with long description",
calls: actionWithLongDescription,
smart: "\r\x1b[1m[ 0% 0/2] action with very long descrip\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action with very long descrip\x1b[0m\x1b[K\n",
simple: "[ 50% 1/2] action with very long description to test eliding\n",
},
{
name: "action with output with ansi codes",
calls: actionWithOutputWithAnsiCodes,
smart: "\r\x1b[1m[ 0% 0/1] action1\x1b[0m\x1b[K\r\x1b[1m[100% 1/1] action1\x1b[0m\x1b[K\n\x1b[31mcolor\x1b[0m\n\x1b[31mcolor message\x1b[0m\n",
simple: "[100% 1/1] action1\ncolor\ncolor message\n",
},
}
os.Setenv(tableHeightEnVar, "")
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Run("smart", func(t *testing.T) {
smart := &fakeSmartTerminal{termWidth: 40}
stat := NewStatusOutput(smart, "", false, false, false)
tt.calls(stat)
stat.Flush()
if g, w := smart.String(), tt.smart; g != w {
t.Errorf("want:\n%q\ngot:\n%q", w, g)
}
})
t.Run("simple", func(t *testing.T) {
simple := &bytes.Buffer{}
stat := NewStatusOutput(simple, "", false, false, false)
tt.calls(stat)
stat.Flush()
if g, w := simple.String(), tt.simple; g != w {
t.Errorf("want:\n%q\ngot:\n%q", w, g)
}
})
t.Run("force simple", func(t *testing.T) {
smart := &fakeSmartTerminal{termWidth: 40}
stat := NewStatusOutput(smart, "", true, false, false)
tt.calls(stat)
stat.Flush()
if g, w := smart.String(), tt.simple; g != w {
t.Errorf("want:\n%q\ngot:\n%q", w, g)
}
})
})
}
}
type runner struct {
counts status.Counts
stat status.StatusOutput
}
func newRunner(stat status.StatusOutput, totalActions int) *runner {
return &runner{
counts: status.Counts{TotalActions: totalActions},
stat: stat,
}
}
func (r *runner) startAction(action *status.Action) {
r.counts.StartedActions++
r.counts.RunningActions++
r.stat.StartAction(action, r.counts)
}
func (r *runner) finishAction(result status.ActionResult) {
r.counts.FinishedActions++
r.counts.RunningActions--
r.stat.FinishAction(result, r.counts)
}
func (r *runner) finishAndStartAction(result status.ActionResult, action *status.Action) {
r.counts.FinishedActions++
r.stat.FinishAction(result, r.counts)
r.counts.StartedActions++
r.stat.StartAction(action, r.counts)
}
var (
action1 = &status.Action{Description: "action1"}
result1 = status.ActionResult{Action: action1}
action2 = &status.Action{Description: "action2"}
result2 = status.ActionResult{Action: action2}
action3 = &status.Action{Description: "action3"}
result3 = status.ActionResult{Action: action3}
)
func twoActions(stat status.StatusOutput) {
runner := newRunner(stat, 2)
runner.startAction(action1)
runner.finishAction(result1)
runner.startAction(action2)
runner.finishAction(result2)
}
func twoParallelActions(stat status.StatusOutput) {
runner := newRunner(stat, 2)
runner.startAction(action1)
runner.startAction(action2)
runner.finishAction(result1)
runner.finishAction(result2)
}
func actionsWithOutput(stat status.StatusOutput) {
result2WithOutput := status.ActionResult{Action: action2, Output: "output1\noutput2\n"}
runner := newRunner(stat, 3)
runner.startAction(action1)
runner.finishAction(result1)
runner.startAction(action2)
runner.finishAction(result2WithOutput)
runner.startAction(action3)
runner.finishAction(result3)
}
func actionsWithOutputWithoutNewline(stat status.StatusOutput) {
result2WithOutputWithoutNewline := status.ActionResult{Action: action2, Output: "output1\noutput2"}
runner := newRunner(stat, 3)
runner.startAction(action1)
runner.finishAction(result1)
runner.startAction(action2)
runner.finishAction(result2WithOutputWithoutNewline)
runner.startAction(action3)
runner.finishAction(result3)
}
func actionsWithError(stat status.StatusOutput) {
action2WithError := &status.Action{Description: "action2", Outputs: []string{"f1", "f2"}, Command: "touch f1 f2"}
result2WithError := status.ActionResult{Action: action2WithError, Output: "error1\nerror2\n", Error: fmt.Errorf("error1")}
runner := newRunner(stat, 3)
runner.startAction(action1)
runner.finishAction(result1)
runner.startAction(action2WithError)
runner.finishAction(result2WithError)
runner.startAction(action3)
runner.finishAction(result3)
}
func actionWithEmptyDescription(stat status.StatusOutput) {
action1 := &status.Action{Command: "command1"}
result1 := status.ActionResult{Action: action1}
runner := newRunner(stat, 1)
runner.startAction(action1)
runner.finishAction(result1)
}
func actionsWithMessages(stat status.StatusOutput) {
runner := newRunner(stat, 2)
runner.startAction(action1)
runner.finishAction(result1)
stat.Message(status.VerboseLvl, "verbose")
stat.Message(status.StatusLvl, "status")
stat.Message(status.PrintLvl, "print")
stat.Message(status.ErrorLvl, "error")
runner.startAction(action2)
runner.finishAction(result2)
}
func actionWithLongDescription(stat status.StatusOutput) {
action1 := &status.Action{Description: "action with very long description to test eliding"}
result1 := status.ActionResult{Action: action1}
runner := newRunner(stat, 2)
runner.startAction(action1)
runner.finishAction(result1)
}
func actionWithOutputWithAnsiCodes(stat status.StatusOutput) {
result1WithOutputWithAnsiCodes := status.ActionResult{Action: action1, Output: "\x1b[31mcolor\x1b[0m"}
runner := newRunner(stat, 1)
runner.startAction(action1)
runner.finishAction(result1WithOutputWithAnsiCodes)
stat.Message(status.PrintLvl, "\x1b[31mcolor message\x1b[0m")
}
func TestSmartStatusOutputWidthChange(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)
action := &status.Action{Description: "action with very long description to test eliding"}
result := status.ActionResult{Action: action}
runner.startAction(action)
smart.termWidth = 30
// Fake a SIGWINCH
smartStat.sigwinch <- syscall.SIGWINCH
<-smartStat.sigwinchHandled
runner.finishAction(result)
stat.Flush()
w := "\r\x1b[1m[ 0% 0/2] action with very long descrip\x1b[0m\x1b[K\r\x1b[1m[ 50% 1/2] action with very lo\x1b[0m\x1b[K\n"
if g := smart.String(); g != w {
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\n\x1b[31m\x1b[1mFAILED:\x1b[0m \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\n\x1b[31m\x1b[1mFAILED:\x1b[0m \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\n\x1b[31m\x1b[1mFAILED:\x1b[0m \nOutput1\n\r\x1b[1m[100% 2/2] action2\x1b[0m\x1b[K\n\x1b[31m\x1b[1mFAILED:\x1b[0m \nOutput2\n"
if g := smart.String(); g != w {
t.Errorf("want:\n%q\ngot:\n%q", w, g)
}
}