fix flaky test TestJSONHook_EphemeralOp_progress (#37451)

pull/37471/head
Samsondeen 8 months ago committed by GitHub
parent 423cacdfe2
commit 1ce7d800c0
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194

@ -6,9 +6,9 @@ package views
import (
"errors"
"fmt"
"strings"
"sync"
"testing"
"testing/synctest"
"time"
"github.com/zclconf/go-cty/cty"
@ -415,110 +415,107 @@ func TestJSONHook_EphemeralOp(t *testing.T) {
}
func TestJSONHook_EphemeralOp_progress(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
hook := newJSONHook(NewJSONView(NewView(streams)))
hook.periodicUiTimer = 1 * time.Second
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "boop",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
action, err := hook.PreEphemeralOp(testJSONHookResourceID(addr), plans.Open)
testHookReturnValues(t, action, err)
time.Sleep(2005 * time.Millisecond)
action, err = hook.PostEphemeralOp(testJSONHookResourceID(addr), plans.Open, nil)
testHookReturnValues(t, action, err)
want := []map[string]interface{}{
{
"@level": "info",
"@message": "test_instance.boop: Opening...",
"@module": "terraform.ui",
"type": "ephemeral_op_start",
"hook": map[string]interface{}{
"action": string("open"),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
syncTest, streams, done := streamableSyncTest(t)
syncTest(t, func(t *testing.T) {
start := time.Now()
hook := newJSONHook(NewJSONView(NewView(streams)))
hook.periodicUiTimer = 1 * time.Second
t.Log(time.Since(start))
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "boop",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
action, err := hook.PreEphemeralOp(testJSONHookResourceID(addr), plans.Open)
testHookReturnValues(t, action, err)
time.Sleep(2005 * time.Millisecond)
action, err = hook.PostEphemeralOp(testJSONHookResourceID(addr), plans.Open, nil)
testHookReturnValues(t, action, err)
want := []map[string]interface{}{
{
"@level": "info",
"@message": "test_instance.boop: Opening...",
"@module": "terraform.ui",
"type": "ephemeral_op_start",
"hook": map[string]interface{}{
"action": string("open"),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
},
},
},
},
{
"@level": "info",
"@message": "test_instance.boop: Still opening... [1s elapsed]",
"@module": "terraform.ui",
"type": "ephemeral_op_progress",
"hook": map[string]interface{}{
"action": string("open"),
"elapsed_seconds": float64(1),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
{
"@level": "info",
"@message": "test_instance.boop: Still opening... [1s elapsed]",
"@module": "terraform.ui",
"type": "ephemeral_op_progress",
"hook": map[string]interface{}{
"action": string("open"),
"elapsed_seconds": float64(1),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
},
},
},
},
{
"@level": "info",
"@message": "test_instance.boop: Still opening... [2s elapsed]",
"@module": "terraform.ui",
"type": "ephemeral_op_progress",
"hook": map[string]interface{}{
"action": string("open"),
"elapsed_seconds": float64(2),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
{
"@level": "info",
"@message": "test_instance.boop: Still opening... [2s elapsed]",
"@module": "terraform.ui",
"type": "ephemeral_op_progress",
"hook": map[string]interface{}{
"action": string("open"),
"elapsed_seconds": float64(2),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
},
},
},
},
{
"@level": "info",
"@message": "test_instance.boop: Opening complete after 2s",
"@module": "terraform.ui",
"type": "ephemeral_op_complete",
"hook": map[string]interface{}{
"action": string("open"),
"elapsed_seconds": float64(2),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
{
"@level": "info",
"@message": "test_instance.boop: Opening complete after 2s",
"@module": "terraform.ui",
"type": "ephemeral_op_complete",
"hook": map[string]interface{}{
"action": string("open"),
"elapsed_seconds": float64(2),
"resource": map[string]interface{}{
"addr": string("test_instance.boop"),
"implied_provider": string("test"),
"module": string(""),
"resource": string("test_instance.boop"),
"resource_key": nil,
"resource_name": string("boop"),
"resource_type": string("test_instance"),
},
},
},
},
}
stdout := done(t).Stdout()
// time.Sleep can take longer than declared time
// so we only test the first lines we expect to see after sleeping
lines := strings.SplitN(stdout, "\n", 4)
firstLines := strings.Join(lines[:4], "\n")
testJSONViewOutputEquals(t, firstLines, want)
}
stdout := done(t).Stdout()
testJSONViewOutputEquals(t, stdout, want)
})
}
func TestJSONHook_EphemeralOp_error(t *testing.T) {
@ -821,3 +818,10 @@ func testHookReturnValues(t *testing.T, action terraform.HookAction, err error)
t.Fatalf("Expected hook to continue, given: %#v", action)
}
}
// streamableSyncTest is a helper to ensure that the long-running streaming goroutines are started outside of the synctest bubble.
// Otherwise, the sync bubble will be unable to advance time, and the main goroutine will become infinitely paused on any time.Sleep operation.
func streamableSyncTest(t *testing.T) (func(t *testing.T, f func(*testing.T)), *terminal.Streams, func(*testing.T) *terminal.TestOutput) {
streams, done := terminal.StreamsForTesting(t)
return synctest.Test, streams, done
}

@ -93,66 +93,67 @@ func TestUiHookPreApply_create(t *testing.T) {
// 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{
"test_instance.foo": {
Op: uiResourceModify,
Start: time.Now(),
},
}
syncTest, streams, done := streamableSyncTest(t)
syncTest(t, func(t *testing.T) {
view := NewView(streams)
h := NewUiHook(view)
h.periodicUiTimer = 1 * time.Second
h.resources = map[string]uiResourceState{
"test_instance.foo": {
Op: uiResourceModify,
Start: time.Now(),
},
}
addr := addrs.Resource{
Mode: addrs.ManagedResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
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),
})
plannedNewState := cty.ObjectVal(map[string]cty.Value{
"id": cty.StringVal("test"),
"bar": cty.ListVal([]cty.Value{
cty.StringVal("baz"),
}),
})
priorState := cty.ObjectVal(map[string]cty.Value{
"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"),
}),
})
action, err := h.PreApply(testUiHookResourceID(addr), addrs.NotDeposed, plans.Update, priorState, plannedNewState)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
action, err := h.PreApply(testUiHookResourceID(addr), addrs.NotDeposed, plans.Update, priorState, plannedNewState)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
time.Sleep(3005 * time.Millisecond)
time.Sleep(3005 * time.Millisecond)
// stop the background writer
uiState := h.resources[addr.String()]
close(uiState.DoneCh)
<-uiState.done
// stop the background writer
uiState := h.resources[addr.String()]
close(uiState.DoneCh)
<-uiState.done
expectedOutput := `test_instance.foo: Modifying... [id=test]
expectedOutput := `test_instance.foo: Modifying... [id=test]
test_instance.foo: Still modifying... [id=test, 00m01s elapsed]
test_instance.foo: Still modifying... [id=test, 00m02s elapsed]
test_instance.foo: Still modifying... [id=test, 00m03s elapsed]
`
result := done(t)
output := result.Stdout()
// we do not test for equality because time.Sleep can take longer than declared time
if !strings.HasPrefix(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)
}
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 destroy path, including passing a deposed key as
@ -735,52 +736,54 @@ ephemeral.test_instance.foo: Closing complete after 0s
}
func TestUiHookEphemeralOp_progress(t *testing.T) {
streams, done := terminal.StreamsForTesting(t)
view := NewView(streams)
h := NewUiHook(view)
h.periodicUiTimer = 1 * time.Second
addr := addrs.Resource{
Mode: addrs.EphemeralResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
action, err := h.PreEphemeralOp(testUiHookResourceID(addr), plans.Open)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
start := time.Now()
time.Sleep(2005 * time.Millisecond)
elapsed := time.Since(start).Round(time.Second)
action, err = h.PostEphemeralOp(testUiHookResourceID(addr), plans.Open, nil)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
stdout := result.Stdout()
// we do not test for equality because time.Sleep can take longer than declared time
wantPrefix := `ephemeral.test_instance.foo: Opening...
syncTest, streams, done := streamableSyncTest(t)
syncTest(t, func(t *testing.T) {
view := NewView(streams)
h := NewUiHook(view)
h.periodicUiTimer = 1 * time.Second
addr := addrs.Resource{
Mode: addrs.EphemeralResourceMode,
Type: "test_instance",
Name: "foo",
}.Instance(addrs.NoKey).Absolute(addrs.RootModuleInstance)
action, err := h.PreEphemeralOp(testUiHookResourceID(addr), plans.Open)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
start := time.Now()
time.Sleep(2005 * time.Millisecond)
elapsed := time.Since(start).Round(time.Second)
action, err = h.PostEphemeralOp(testUiHookResourceID(addr), plans.Open, nil)
if err != nil {
t.Fatal(err)
}
if action != terraform.HookActionContinue {
t.Fatalf("Expected hook to continue, given: %#v", action)
}
result := done(t)
stdout := result.Stdout()
// we do not test for equality because time.Sleep can take longer than declared time
wantPrefix := `ephemeral.test_instance.foo: Opening...
ephemeral.test_instance.foo: Still opening... [00m01s elapsed]
ephemeral.test_instance.foo: Still opening... [00m02s elapsed]`
if !strings.HasPrefix(stdout, wantPrefix) {
t.Fatalf("unexpected prefix\n got: %q\nwant: %q", stdout, wantPrefix)
}
wantSuffix := fmt.Sprintf(`ephemeral.test_instance.foo: Opening complete after %s
if !strings.HasPrefix(stdout, wantPrefix) {
t.Fatalf("unexpected prefix\n got: %q\nwant: %q", stdout, wantPrefix)
}
wantSuffix := fmt.Sprintf(`ephemeral.test_instance.foo: Opening complete after %s
`, elapsed)
if !strings.HasSuffix(stdout, wantSuffix) {
t.Fatalf("unexpected prefix\n got: %q\nwant: %q", stdout, wantSuffix)
}
if !strings.HasSuffix(stdout, wantSuffix) {
t.Fatalf("unexpected prefix\n got: %q\nwant: %q", stdout, wantSuffix)
}
})
}
func TestUiHookEphemeralOp_error(t *testing.T) {

Loading…
Cancel
Save