Merge pull request #27790 from hashicorp/alisdair/ui-hook-miscolored

cli: Fix misapplied terminal colors on run logs
This commit is contained in:
Alisdair McDiarmid 2021-02-16 17:15:53 -05:00 committed by GitHub
commit 8fb319bc79
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 430 additions and 60 deletions

View File

@ -106,12 +106,12 @@ func (h *UiHook) PreApply(addr addrs.AbsResourceInstance, gen states.Generation,
idValue = ""
}
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][bold]%s: %s%s[reset]",
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s: %s%s[reset]"),
dispAddr,
operation,
stateIdSuffix,
)))
))
key := addr.String()
uiState := uiResourceState{
@ -164,13 +164,13 @@ func (h *UiHook) stillApplying(state uiResourceState) {
idSuffix = fmt.Sprintf("%s=%s, ", state.IDKey, truncateId(state.IDValue, maxIdLen))
}
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][bold]%s: %s [%s%s elapsed][reset]",
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s: %s [%s%s elapsed][reset]"),
state.DispAddr,
msg,
idSuffix,
time.Now().Round(time.Second).Sub(state.Start),
)))
))
}
}
@ -210,9 +210,9 @@ func (h *UiHook) PostApply(addr addrs.AbsResourceInstance, gen states.Generation
return terraform.HookActionContinue, nil
}
colorized := h.view.colorize.Color(fmt.Sprintf(
"[reset][bold]%s: %s after %s%s[reset]",
addr, msg, time.Now().Round(time.Second).Sub(state.Start), stateIdSuffix))
colorized := fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s: %s after %s%s"),
addr, msg, time.Now().Round(time.Second).Sub(state.Start), stateIdSuffix)
h.println(colorized)
@ -220,18 +220,20 @@ func (h *UiHook) PostApply(addr addrs.AbsResourceInstance, gen states.Generation
}
func (h *UiHook) PreProvisionInstanceStep(addr addrs.AbsResourceInstance, typeName string) (terraform.HookAction, error) {
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][bold]%s: Provisioning with '%s'...[reset]",
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s: Provisioning with '%s'...[reset]"),
addr, typeName,
)))
))
return terraform.HookActionContinue, nil
}
func (h *UiHook) ProvisionOutput(addr addrs.AbsResourceInstance, typeName string, msg string) {
var buf bytes.Buffer
buf.WriteString(h.view.colorize.Color("[reset]"))
prefix := fmt.Sprintf("%s (%s): ", addr, typeName)
prefix := fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s (%s):[reset] "),
addr, typeName,
)
s := bufio.NewScanner(strings.NewReader(msg))
s.Split(scanLines)
for s.Scan() {
@ -250,28 +252,30 @@ func (h *UiHook) PreRefresh(addr addrs.AbsResourceInstance, gen states.Generatio
stateIdSuffix = fmt.Sprintf(" [%s=%s]", k, v)
}
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][bold]%s: Refreshing state...%s",
addr, stateIdSuffix)))
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s: Refreshing state...%s"),
addr, stateIdSuffix))
return terraform.HookActionContinue, nil
}
func (h *UiHook) PreImportState(addr addrs.AbsResourceInstance, importID string) (terraform.HookAction, error) {
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][bold]%s: Importing from ID %q...",
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][bold]%s: Importing from ID %q..."),
addr, importID,
)))
))
return terraform.HookActionContinue, nil
}
func (h *UiHook) PostImportState(addr addrs.AbsResourceInstance, imported []providers.ImportedResource) (terraform.HookAction, error) {
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][bold][green]%s: Import prepared!", addr)))
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][bold][green]%s: Import prepared!"),
addr,
))
for _, s := range imported {
h.println(h.view.colorize.Color(fmt.Sprintf(
"[reset][green] Prepared %s for import",
h.println(fmt.Sprintf(
h.view.colorize.Color("[reset][green] Prepared %s for import"),
s.TypeName,
)))
))
}
return terraform.HookActionContinue, nil
@ -295,7 +299,7 @@ func scanLines(data []byte, atEOF bool) (advance int, token []byte, err error) {
return i + 1, dropCR(data[0:i]), nil
}
if i := bytes.IndexByte(data, '\r'); i >= 0 {
// We have a full newline-terminated line.
// We have a full carriage-return-terminated line.
return i + 1, dropCR(data[0:i]), nil
}
// If we're at EOF, we have a final, non-terminated line. Return it.

View File

@ -6,48 +6,107 @@ import (
"testing"
"time"
"strings"
"github.com/zclconf/go-cty/cty"
"github.com/hashicorp/terraform/addrs"
"github.com/hashicorp/terraform/command/arguments"
"github.com/hashicorp/terraform/internal/terminal"
"github.com/hashicorp/terraform/plans"
"github.com/hashicorp/terraform/providers"
"github.com/hashicorp/terraform/states"
"github.com/hashicorp/terraform/terraform"
)
// Test the PreApply hook for creating a new resource
func TestUiHookPreApply_create(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
h.resources = map[string]uiResourceState{
"test_instance.foo": {
Op: uiResourceCreate,
Start: time.Now(),
},
}
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
priorState := cty.NullVal(cty.Object(map[string]cty.Type{
"id": cty.String,
"bar": cty.List(cty.String),
}))
plannedNewState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("test"),
"bar": cty.ListVal([]cty.Value{
cty.StringVal("baz"),
}),
})
action, err := h.PreApply(addr, states.CurrentGen, plans.Create, priorState, plannedNewState)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
// stop the background writer
uiState := h.resources[addr.String()]
close(uiState.DoneCh)
<-uiState.done
expectedOutput := "test_instance.foo: Creating...\n"
result := done(t)
output := result.Stdout()
if output != expectedOutput {
t.Fatalf("Output didn't match.\nExpected: %q\nGiven: %q", expectedOutput, output)
}
expectedErrOutput := ""
errOutput := result.Stderr()
if errOutput != expectedErrOutput {
t.Fatalf("Error output didn't match.\nExpected: %q\nGiven: %q", expectedErrOutput, errOutput)
}
}
// Test the PreApply hook's use of a periodic timer to display "still working"
// log lines
func TestUiHookPreApply_periodicTimer(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
h.periodicUiTimer = 1 * time.Second
h.resources = map[string]uiResourceState{
"data.aws_availability_zones.available": uiResourceState{
Op: uiResourceDestroy,
"test_instance.foo": {
Op: uiResourceModify,
Start: time.Now(),
},
}
addr := addrs.Resource{
Mode: addrs.DataResourceMode,
Type: "aws_availability_zones",
Name: "available",
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
priorState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("2017-03-05 10:56:59.298784526 +0000 UTC"),
"names": cty.ListVal([]cty.Value{
cty.StringVal("us-east-1a"),
cty.StringVal("us-east-1b"),
cty.StringVal("us-east-1c"),
cty.StringVal("us-east-1d"),
"id": cty.StringVal("test"),
"bar": cty.ListValEmpty(cty.String),
})
plannedNewState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("test"),
"bar": cty.ListVal([]cty.Value{
cty.StringVal("baz"),
}),
})
plannedNewState := cty.NullVal(cty.Object(map[string]cty.Type{
"id": cty.String,
"names": cty.List(cty.String),
}))
action, err := h.PreApply(addr, states.CurrentGen, plans.Delete, priorState, plannedNewState)
action, err := h.PreApply(addr, states.CurrentGen, plans.Update, priorState, plannedNewState)
if err != nil {
t.Fatal(err)
}
@ -62,10 +121,10 @@ func TestUiHookPreApply_periodicTimer(t *testing.T) {
close(uiState.DoneCh)
<-uiState.done
expectedOutput := `data.aws_availability_zones.available: Destroying... [id=2017-03-05 10:56:59.298784526 +0000 UTC]
data.aws_availability_zones.available: Still destroying... [id=2017-03-05 10:56:59.298784526 +0000 UTC, 1s elapsed]
data.aws_availability_zones.available: Still destroying... [id=2017-03-05 10:56:59.298784526 +0000 UTC, 2s elapsed]
data.aws_availability_zones.available: Still destroying... [id=2017-03-05 10:56:59.298784526 +0000 UTC, 3s elapsed]
expectedOutput := `test_instance.foo: Modifying... [id=test]
test_instance.foo: Still modifying... [id=test, 1s elapsed]
test_instance.foo: Still modifying... [id=test, 2s elapsed]
test_instance.foo: Still modifying... [id=test, 3s elapsed]
`
result := done(t)
output := result.Stdout()
@ -80,38 +139,38 @@ data.aws_availability_zones.available: Still destroying... [id=2017-03-05 10:56:
}
}
// Test the PreApply hook's destroy path, including passing a deposed key as
// the gen argument.
func TestUiHookPreApply_destroy(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
h.resources = map[string]uiResourceState{
"data.aws_availability_zones.available": uiResourceState{
"test_instance.foo": {
Op: uiResourceDestroy,
Start: time.Now(),
},
}
addr := addrs.Resource{
Mode: addrs.DataResourceMode,
Type: "aws_availability_zones",
Name: "available",
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
priorState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("2017-03-05 10:56:59.298784526 +0000 UTC"),
"names": cty.ListVal([]cty.Value{
cty.StringVal("us-east-1a"),
cty.StringVal("us-east-1b"),
cty.StringVal("us-east-1c"),
cty.StringVal("us-east-1d"),
"id": cty.StringVal("abc123"),
"verbs": cty.ListVal([]cty.Value{
cty.StringVal("boop"),
}),
})
plannedNewState := cty.NullVal(cty.Object(map[string]cty.Type{
"id": cty.String,
"names": cty.List(cty.String),
"verbs": cty.List(cty.String),
}))
action, err := h.PreApply(addr, states.CurrentGen, plans.Delete, priorState, plannedNewState)
key := states.NewDeposedKey()
action, err := h.PreApply(addr, key, plans.Delete, priorState, plannedNewState)
if err != nil {
t.Fatal(err)
}
@ -125,7 +184,7 @@ func TestUiHookPreApply_destroy(t *testing.T) {
<-uiState.done
result := done(t)
expectedOutput := "data.aws_availability_zones.available: Destroying... [id=2017-03-05 10:56:59.298784526 +0000 UTC]\n"
expectedOutput := fmt.Sprintf("test_instance.foo (%s): Destroying... [id=abc123]\n", key)
output := result.Stdout()
if output != expectedOutput {
t.Fatalf("Output didn't match.\nExpected: %q\nGiven: %q", expectedOutput, output)
@ -138,12 +197,67 @@ func TestUiHookPreApply_destroy(t *testing.T) {
}
}
// Verify that colorize is called on format strings, not user input, by adding
// valid color codes as resource names and IDs.
func TestUiHookPostApply_colorInterpolation(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
view.Configure(&arguments.View{NoColor: false})
h := NewUiHook(view)
h.resources = map[string]uiResourceState{
"test_instance.foo[\"[red]\"]": {
Op: uiResourceCreate,
Start: time.Now(),
},
}
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.StringKey("[red]")).Absolute(addrs.RootModuleInstance)
newState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("[blue]"),
})
action, err := h.PostApply(addr, states.CurrentGen, newState, nil)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
reset := "\x1b[0m"
bold := "\x1b[1m"
wantPrefix := reset + bold + `test_instance.foo["[red]"]: Creation complete after`
wantSuffix := "[id=[blue]]" + reset + "\n"
output := result.Stdout()
if !strings.HasPrefix(output, wantPrefix) {
t.Fatalf("wrong output prefix\n got: %#v\nwant: %#v", output, wantPrefix)
}
if !strings.HasSuffix(output, wantSuffix) {
t.Fatalf("wrong output suffix\n got: %#v\nwant: %#v", output, wantSuffix)
}
expectedErrOutput := ""
errOutput := result.Stderr()
if errOutput != expectedErrOutput {
t.Fatalf("Error output didn't match.\nExpected: %q\nGiven: %q", expectedErrOutput, errOutput)
}
}
// Test that the PostApply hook renders a total time.
func TestUiHookPostApply_emptyState(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
h.resources = map[string]uiResourceState{
"data.google_compute_zones.available": uiResourceState{
"data.google_compute_zones.available": {
Op: uiResourceDestroy,
Start: time.Now(),
},
@ -182,6 +296,258 @@ func TestUiHookPostApply_emptyState(t *testing.T) {
}
}
func TestPreProvisionInstanceStep(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
action, err := h.PreProvisionInstanceStep(addr, "local-exec")
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
if got, want := result.Stdout(), "test_instance.foo: Provisioning with 'local-exec'...\n"; got != want {
t.Fatalf("unexpected output\n got: %q\nwant: %q", got, want)
}
}
// Test ProvisionOutput, including lots of edge cases for the output
// whitespace/line ending logic.
func TestProvisionOutput(t *testing.T) {
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
testCases := map[string]struct {
provisioner string
input string
wantOutput string
}{
"single line": {
"local-exec",
"foo\n",
"test_instance.foo (local-exec): foo\n",
},
"multiple lines": {
"x",
`foo
bar
baz
`,
`test_instance.foo (x): foo
test_instance.foo (x): bar
test_instance.foo (x): baz
`,
},
"trailing whitespace": {
"x",
"foo \nbar\n",
"test_instance.foo (x): foo\ntest_instance.foo (x): bar\n",
},
"blank lines": {
"x",
"foo\n\nbar\n\n\nbaz\n",
`test_instance.foo (x): foo
test_instance.foo (x): bar
test_instance.foo (x): baz
`,
},
"no final newline": {
"x",
`foo
bar`,
`test_instance.foo (x): foo
test_instance.foo (x): bar
`,
},
"CR, no LF": {
"MacOS 9?",
"foo\rbar\r",
`test_instance.foo (MacOS 9?): foo
test_instance.foo (MacOS 9?): bar
`,
},
"CRLF": {
"winrm",
"foo\r\nbar\r\n",
`test_instance.foo (winrm): foo
test_instance.foo (winrm): bar
`,
},
}
for name, tc := range testCases {
t.Run(name, func(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
h.ProvisionOutput(addr, tc.provisioner, tc.input)
result := done(t)
if got := result.Stdout(); got != tc.wantOutput {
t.Fatalf("unexpected output\n got: %q\nwant: %q", got, tc.wantOutput)
}
})
}
}
// Test the PreRefresh hook in the normal path where the resource exists with
// an ID key and value in the state.
func TestPreRefresh(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
priorState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("test"),
"bar": cty.ListValEmpty(cty.String),
})
action, err := h.PreRefresh(addr, states.CurrentGen, priorState)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
if got, want := result.Stdout(), "test_instance.foo: Refreshing state... [id=test]\n"; got != want {
t.Fatalf("unexpected output\n got: %q\nwant: %q", got, want)
}
}
// Test that PreRefresh still works if no ID key and value can be determined
// from state.
func TestPreRefresh_noID(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
priorState := cty.ObjectVal(map[string]cty.Value{
"bar": cty.ListValEmpty(cty.String),
})
action, err := h.PreRefresh(addr, states.CurrentGen, priorState)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
if got, want := result.Stdout(), "test_instance.foo: Refreshing state...\n"; got != want {
t.Fatalf("unexpected output\n got: %q\nwant: %q", got, want)
}
}
// Test the very simple PreImportState hook.
func TestPreImportState(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
action, err := h.PreImportState(addr, "test")
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
if got, want := result.Stdout(), "test_instance.foo: Importing from ID \"test\"...\n"; got != want {
t.Fatalf("unexpected output\n got: %q\nwant: %q", got, want)
}
}
// Test the PostImportState UI hook. Again, this hook behaviour seems odd to
// me (see below), so please don't consider these tests as justification for
// keeping this behaviour.
func TestPostImportState(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
// The "Prepared [...] for import" lines display the type name of each of
// the imported resources passed to the hook. I'm not sure how it's
// possible for an import to result in a different resource type name than
// the target address, but the hook works like this so we're covering it.
imported := []providers.ImportedResource{
{
TypeName: "test_some_instance",
State: cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("test"),
}),
},
{
TypeName: "test_other_instance",
State: cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("test"),
}),
},
}
action, err := h.PostImportState(addr, imported)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
want := `test_instance.foo: Import prepared!
Prepared test_some_instance for import
Prepared test_other_instance for import
`
if got := result.Stdout(); got != want {
t.Fatalf("unexpected output\n got: %q\nwant: %q", got, want)
}
}
func TestTruncateId(t *testing.T) {
testCases := []struct {
Input string