From 54e13d161e739db635711d9d6a441ef73dd5133e Mon Sep 17 00:00:00 2001 From: Tommy Reilly Date: Mon, 23 Jan 2023 22:06:27 -0500 Subject: [PATCH] logictest: fix retry on query that returns a fleeting error Fixes: #95664 Release note: None Epic: CRDB-20535 --- .../tests/3node-tenant/generated_test.go | 7 +++++++ pkg/sql/logictest/logic.go | 18 ++++++++---------- pkg/sql/logictest/testdata/logic_test/retry | 15 +++++++++++++++ .../tests/fakedist-disk/generated_test.go | 7 +++++++ .../tests/fakedist-vec-off/generated_test.go | 7 +++++++ .../logictest/tests/fakedist/generated_test.go | 7 +++++++ .../generated_test.go | 7 +++++++ .../tests/local-vec-off/generated_test.go | 7 +++++++ .../logictest/tests/local/generated_test.go | 7 +++++++ pkg/testutils/soon.go | 16 +++++++++------- 10 files changed, 81 insertions(+), 17 deletions(-) create mode 100644 pkg/sql/logictest/testdata/logic_test/retry diff --git a/pkg/ccl/logictestccl/tests/3node-tenant/generated_test.go b/pkg/ccl/logictestccl/tests/3node-tenant/generated_test.go index 6d8f99d14179..be6397ad5cc4 100644 --- a/pkg/ccl/logictestccl/tests/3node-tenant/generated_test.go +++ b/pkg/ccl/logictestccl/tests/3node-tenant/generated_test.go @@ -1449,6 +1449,13 @@ func TestTenantLogic_reset( runLogicTest(t, "reset") } +func TestTenantLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestTenantLogic_returning( t *testing.T, ) { diff --git a/pkg/sql/logictest/logic.go b/pkg/sql/logictest/logic.go index 4bf6bdf89845..8b8b45642965 100644 --- a/pkg/sql/logictest/logic.go +++ b/pkg/sql/logictest/logic.go @@ -3123,12 +3123,7 @@ func (t *logicTest) verifyError( ) (bool, error) { if expectErr == "" && expectErrCode == "" && err != nil { t.maybeSkipOnRetry(err) - cont := t.unexpectedError(sql, pos, err) - if cont { - // unexpectedError() already reported via t.Errorf. no need for more. - err = nil - } - return cont, err + return t.unexpectedError(sql, pos, err) } if expectNotice != "" { foundNotice := strings.Join(t.noticeBuffer, "\n") @@ -3215,7 +3210,7 @@ func formatErr(err error) string { // when -allow-prepare-fail is specified. The argument "sql" is "" to indicate the // work is done on behalf of a statement, which always fail upon an // unexpected error. -func (t *logicTest) unexpectedError(sql string, pos string, err error) bool { +func (t *logicTest) unexpectedError(sql string, pos string, err error) (bool, error) { if *allowPrepareFail && sql != "" { // This is a query and -allow-prepare-fail is set. Try to prepare // the query. If prepare fails, this means we (probably) do not @@ -3227,14 +3222,17 @@ func (t *logicTest) unexpectedError(sql string, pos string, err error) bool { t.outf("\t-- fails prepare: %s", formatErr(err)) } t.signalIgnoredError(err, pos, sql) - return true + return true, nil } if err := stmt.Close(); err != nil { t.Errorf("%s: %s\nerror when closing prepared statement: %s", sql, pos, formatErr(err)) } } - t.Errorf("%s: %s\nexpected success, but found\n%s", pos, sql, formatErr(err)) - return false + // N.B. We return an error instead of calling t.Errorf because this query + // could be asking for a retry. We still use t.Errorf above because + // stmt.Close error is probably a sign of bigger issues and not + // something retryable. + return false, fmt.Errorf("%s: %s\nexpected success, but found\n%s", pos, sql, formatErr(err)) } func (t *logicTest) execStatement(stmt logicStatement) (bool, error) { diff --git a/pkg/sql/logictest/testdata/logic_test/retry b/pkg/sql/logictest/testdata/logic_test/retry new file mode 100644 index 000000000000..06d7b7861b2a --- /dev/null +++ b/pkg/sql/logictest/testdata/logic_test/retry @@ -0,0 +1,15 @@ +statement ok +CREATE SEQUENCE s START 1 INCREMENT 1; +SELECT nextval('s') + +# Unit test for bug #95664, retry on a query producing an error should +# try again and succeed if err doesn't happen again. +query I retry +SELECT + CASE subq.val + WHEN 2 THEN crdb_internal.force_error('bad', 'wrong') + ELSE 0 + END +FROM (SELECT nextval('s') AS val) subq +---- +0 diff --git a/pkg/sql/logictest/tests/fakedist-disk/generated_test.go b/pkg/sql/logictest/tests/fakedist-disk/generated_test.go index 47766181a95b..f063f7c1018e 100644 --- a/pkg/sql/logictest/tests/fakedist-disk/generated_test.go +++ b/pkg/sql/logictest/tests/fakedist-disk/generated_test.go @@ -1430,6 +1430,13 @@ func TestLogic_reset( runLogicTest(t, "reset") } +func TestLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestLogic_returning( t *testing.T, ) { diff --git a/pkg/sql/logictest/tests/fakedist-vec-off/generated_test.go b/pkg/sql/logictest/tests/fakedist-vec-off/generated_test.go index 7aed138e125b..1ed95c3e9141 100644 --- a/pkg/sql/logictest/tests/fakedist-vec-off/generated_test.go +++ b/pkg/sql/logictest/tests/fakedist-vec-off/generated_test.go @@ -1430,6 +1430,13 @@ func TestLogic_reset( runLogicTest(t, "reset") } +func TestLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestLogic_returning( t *testing.T, ) { diff --git a/pkg/sql/logictest/tests/fakedist/generated_test.go b/pkg/sql/logictest/tests/fakedist/generated_test.go index dc2a2c990652..aabbee91bed6 100644 --- a/pkg/sql/logictest/tests/fakedist/generated_test.go +++ b/pkg/sql/logictest/tests/fakedist/generated_test.go @@ -1444,6 +1444,13 @@ func TestLogic_reset( runLogicTest(t, "reset") } +func TestLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestLogic_returning( t *testing.T, ) { diff --git a/pkg/sql/logictest/tests/local-legacy-schema-changer/generated_test.go b/pkg/sql/logictest/tests/local-legacy-schema-changer/generated_test.go index 76f32853792b..aa2ce22a5fb9 100644 --- a/pkg/sql/logictest/tests/local-legacy-schema-changer/generated_test.go +++ b/pkg/sql/logictest/tests/local-legacy-schema-changer/generated_test.go @@ -1402,6 +1402,13 @@ func TestLogic_reset( runLogicTest(t, "reset") } +func TestLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestLogic_returning( t *testing.T, ) { diff --git a/pkg/sql/logictest/tests/local-vec-off/generated_test.go b/pkg/sql/logictest/tests/local-vec-off/generated_test.go index e8f3caf8aeae..0da606fd62c9 100644 --- a/pkg/sql/logictest/tests/local-vec-off/generated_test.go +++ b/pkg/sql/logictest/tests/local-vec-off/generated_test.go @@ -1437,6 +1437,13 @@ func TestLogic_reset( runLogicTest(t, "reset") } +func TestLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestLogic_returning( t *testing.T, ) { diff --git a/pkg/sql/logictest/tests/local/generated_test.go b/pkg/sql/logictest/tests/local/generated_test.go index 3b8ae8265e1f..8569be3004de 100644 --- a/pkg/sql/logictest/tests/local/generated_test.go +++ b/pkg/sql/logictest/tests/local/generated_test.go @@ -1570,6 +1570,13 @@ func TestLogic_reset( runLogicTest(t, "reset") } +func TestLogic_retry( + t *testing.T, +) { + defer leaktest.AfterTest(t)() + runLogicTest(t, "retry") +} + func TestLogic_returning( t *testing.T, ) { diff --git a/pkg/testutils/soon.go b/pkg/testutils/soon.go index 33eb35f1547c..f268a06f9e92 100644 --- a/pkg/testutils/soon.go +++ b/pkg/testutils/soon.go @@ -31,10 +31,11 @@ const ( RaceSucceedsSoonDuration = DefaultSucceedsSoonDuration * 5 ) -// SucceedsSoon fails the test (with t.Fatal) unless the supplied -// function runs without error within a preset maximum duration. The -// function is invoked immediately at first and then successively with -// an exponential backoff starting at 1ns and ending at around 1s. +// SucceedsSoon fails the test (with t.Fatal) unless the supplied function runs +// without error within a preset maximum duration. The function is invoked +// immediately at first and then successively with an exponential backoff +// starting at 1ns and ending at DefaultSucceedsSoonDuration (or +// RaceSucceedsSoonDuration if race is enabled). func SucceedsSoon(t TB, fn func() error) { t.Helper() SucceedsWithin(t, fn, succeedsSoonDuration()) @@ -43,7 +44,8 @@ func SucceedsSoon(t TB, fn func() error) { // SucceedsSoonError returns an error unless the supplied function runs without // error within a preset maximum duration. The function is invoked immediately // at first and then successively with an exponential backoff starting at 1ns -// and ending at around 1s. +// and ending at DefaultSucceedsSoonDuration (or RaceSucceedsSoonDuration if +// race is enabled). func SucceedsSoonError(fn func() error) error { return SucceedsWithinError(fn, succeedsSoonDuration()) } @@ -51,7 +53,7 @@ func SucceedsSoonError(fn func() error) error { // SucceedsWithin fails the test (with t.Fatal) unless the supplied // function runs without error within the given duration. The function // is invoked immediately at first and then successively with an -// exponential backoff starting at 1ns and ending at around 1s. +// exponential backoff starting at 1ns and ending at duration. func SucceedsWithin(t TB, fn func() error, duration time.Duration) { t.Helper() if err := SucceedsWithinError(fn, duration); err != nil { @@ -62,7 +64,7 @@ func SucceedsWithin(t TB, fn func() error, duration time.Duration) { // SucceedsWithinError returns an error unless the supplied function // runs without error within the given duration. The function is // invoked immediately at first and then successively with an -// exponential backoff starting at 1ns and ending at around 1s. +// exponential backoff starting at 1ns and ending at duration. func SucceedsWithinError(fn func() error, duration time.Duration) error { tBegin := timeutil.Now() wrappedFn := func() error {