resilien
/
terraform
2
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

cli: Fix misapplied terminal colors on run logs 

Due to calling the Colorize function with the full string instead of the
format string, plan/apply logs which include resource instance keys or
IDs which happen to match color formatting would be rendered
incorrectly.

This commit fixes this by only colorizing the known-safe format string.
We also add full test coverage for the UI hook, although only one of the
hooks is tested for this color bugfix due to verbosity of the test.

We also add the bold coloring to the provisioner output prefix, which
seems to have been an oversight.
This commit is contained in:
Alisdair McDiarmid 2021-02-16 11:33:03 -05:00
parent 1ae3d30383
commit 0aa227e0e3
2 changed files with 430 additions and 60 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

56
command/views/hook_ui.go
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.

434
command/views/hook_ui_test.go
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