sql: TestSchemaChangeEvalContext failed #54775

cockroach-teamcity · 2020-09-25T01:53:18Z

(sql).TestSchemaChangeEvalContext failed on master@66a076f89e92becc1d7e1a2ecfd39c275165e2d8:

=== RUN   TestSchemaChangeEvalContext
--- FAIL: TestSchemaChangeEvalContext (2.49s)
    test_log_scope.go:154: test logs captured to: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext982620575
    test_log_scope.go:63: use -show-logs to present logs inline
=== RUN   TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp;
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext982620575
    --- FAIL: TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp; (0.98s)
        schema_changer_test.go:3814: read the wrong number of rows: e = 1, v = 2

More

Parameters:

GOFLAGS=-json

make stressrace TESTS=TestSchemaChangeEvalContext PKG=./pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

The text was updated successfully, but these errors were encountered:

yuzefovich · 2020-09-25T03:53:12Z

This flake is caused by #54755.

cockroach-teamcity · 2020-09-25T06:31:29Z

(sql).TestSchemaChangeEvalContext failed on master@66a076f89e92becc1d7e1a2ecfd39c275165e2d8:

=== RUN   TestSchemaChangeEvalContext
--- FAIL: TestSchemaChangeEvalContext (1.21s)
    test_log_scope.go:154: test logs captured to: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext678903418
    test_log_scope.go:63: use -show-logs to present logs inline
=== RUN   TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp;
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext678903418
    --- FAIL: TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp; (0.48s)
        schema_changer_test.go:3814: read the wrong number of rows: e = 1, v = 2

More

Parameters:

TAGS=
GOFLAGS=-parallel=4

make stressrace TESTS=TestSchemaChangeEvalContext PKG=./pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

cockroach-teamcity · 2020-09-25T06:55:29Z

(sql).TestSchemaChangeEvalContext failed on master@66a076f89e92becc1d7e1a2ecfd39c275165e2d8:

=== RUN   TestSchemaChangeEvalContext
--- FAIL: TestSchemaChangeEvalContext (20.48s)
    test_log_scope.go:154: test logs captured to: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext019750148
    test_log_scope.go:63: use -show-logs to present logs inline
=== RUN   TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp;
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext019750148
    --- FAIL: TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp; (8.60s)
        schema_changer_test.go:3814: read the wrong number of rows: e = 1, v = 2

More

Parameters:

TAGS=
GOFLAGS=-race -parallel=2

make stressrace TESTS=TestSchemaChangeEvalContext PKG=./pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

rytaft · 2020-09-25T13:44:29Z

Ran into this here: https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_UnitTests/2323471?

Refs: cockroachdb#54775 Reason: flaky test Generated by bin/skip-test. Release justification: non-production code changes Release note: None

54768: opt: update cost of index join and statistics of array contains operation r=rytaft a=rytaft **opt: update statistics of array contains operation to match json contains** Prior to this commit, the selectivity of `j @> '{"a": "b"}'::json` was calculated as `1/9`, while the selectivity of `a @> array[1]` was calculated as `1/3`. Both of these predicates essentially represent one "path" that can be queried in an inverted index, so they should have the same selectivity. Furthermore, multiple paths should be more selective, so in the same way that the predicate `j @> '{"a": "b", "c": "d"}'::json` has selectivity `(1/9 * 1/9)`, `a @> array[1,2]` should similarly have selectivity `(1/9 * 1/9)`. This commit updates the logic in the statistics builder so that this is the case. Release note (performance improvement): Improved the selectivity estimate for array contains predicates (e.g., `arr @> ARRAY[1]`) in the optimizer. This improves the optimizer's cardinality estimation for queries containing these predicates, and may result in better query plans in some cases. **opt: update cost of index join to match cost of lookup join** Prior to this commit, the cost of an index join was much less than the cost of an equivalent lookup join. Since index joins have the same implementation as lookup joins when the lookup columns form a key in the lookup table, the two operators should have the same cost. This commit updates the coster so that this is the case. Informs #46677 Release note (performance improvement): Updated the cost model in the optimizer to make index joins more expensive and better reflect the reality of their cost. As a result, the optimizer will choose index joins less frequently, generally resulting in more efficient query plans. 54772: workload: bump the tpcc fixture version; create statistics when making fixtures r=RaduBerinde a=RaduBerinde #### workload: bump the tpcc fixture version The TPCC fixtures need refreshing: they contain FK indexes that we no longer need, and they are missing stats for some of the tables. This commit bumps the fixture version and incorporates the `deprecated-fk-indexes` flag into the fixture name. Release note: None #### workload: create statistics when making fixtures `workload make` imports a workload and then creates the backup (that can be later used by `workload load`). This change adds functionality to call CREATE STATISTICS on all tables before creating the backup. This can be turned off using a flag. Release note: None I am in the process of regenerating the fixtures with the new version. Informs #54702. Informs #50911. 54784: deps: bump cockroachdb/redact r=andreimatei a=knz To pick up the pointer formatting fix from cockroachdb/redact#9 Release note: None 54804: sql: skip TestSchemaChangeEvalContext r=yuzefovich a=yuzefovich Refs: #54775 Reason: flaky test Generated by bin/skip-test. Release justification: non-production code changes Release note: None Co-authored-by: Rebecca Taft <[email protected]> Co-authored-by: Radu Berinde <[email protected]> Co-authored-by: Raphael 'kena' Poss <[email protected]> Co-authored-by: Yahor Yuzefovich <[email protected]>

cockroach-teamcity · 2020-09-25T23:10:04Z

(sql).TestSchemaChangeEvalContext failed on master@21f67e8534737f68ba9aad79aae8e24c1a6bdaba:

=== RUN   TestSchemaChangeEvalContext
--- FAIL: TestSchemaChangeEvalContext (22.35s)
    test_log_scope.go:154: test logs captured to: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext175641954
    test_log_scope.go:63: use -show-logs to present logs inline
=== RUN   TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp;
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestSchemaChangeEvalContext175641954
    --- FAIL: TestSchemaChangeEvalContext/ALTER_TABLE_t.test_ADD_COLUMN_x_TIMESTAMP_DEFAULT_current_timestamp; (10.04s)
        schema_changer_test.go:3814: read the wrong number of rows: e = 1, v = 2

More

Parameters:

GOFLAGS=-json

make stressrace TESTS=TestSchemaChangeEvalContext PKG=./pkg/sql TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

ajwerner · 2020-09-28T14:04:08Z

I'm not convinced this is fixed by #54755

ajwerner · 2020-09-28T20:19:39Z

Alright, this bug was revealed by a different bug introduced in #54755. The bug introduced there was that we'd clobber subtracting spans. The bug that it reveals is that different iterations of the backfill will use a different timestamp.

We grab readAsOf by reading the clock prior to the dist backfill. We, however, checkpoint the backfill progress as we go. That means that if the backfill were to restart on a different node, we'd pick a different timestamp at which to perform the backfill. Perhaps that's safe because any of these timestamps should be after the index is in DELETE_AND_WRITE_ONLY but it still seems alarming. My first instinct was that this is hazardous but upon further reflection, it should be fine. The real problem arises when we need to write utilize the timestamp inside of a function. For that we'll need to derive the timestamp to use from a property of the job itself.

cockroach/pkg/sql/backfill.go

Line 614 in db9c393

readAsOf := sc.clock.Now()

thoszhang · 2020-09-28T21:27:31Z

I'm not sure I understand the relationship between #54755 and this bug. Why exactly did this test pass before?

ajwerner · 2020-09-28T21:31:14Z

It passed before because we'd only ever go through the loop one time (I don't think that that was the intention of the test, but it rotted). I introduced a bug whereby we'd go through the loop multiple times (it's a bad bug but easy to fix). When I send a PR in a few minutes, things should become clearer.

54900: sql: fix a bug tracking spans in a backfill r=lucy-zhang a=ajwerner Fixes a bug introduced in #54755 whereby we'd always subtract from the original set of spans rather than from the updated set of spans meaning that we could backfill the same span multiple times. Fixes #54775. Release note: None Co-authored-by: Andrew Werner <[email protected]>

Fixes a bug introduced in #54755 whereby we'd always subtract from the original set of spans rather than from the updated set of spans meaning that we could backfill the same span multiple times. Fixes #54775. Release note: None

cockroach-teamcity added branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Sep 25, 2020

cockroach-teamcity added this to the 20.2 milestone Sep 25, 2020

cockroach-teamcity assigned andreimatei Sep 25, 2020

yuzefovich assigned ajwerner and unassigned andreimatei Sep 25, 2020

rytaft mentioned this issue Sep 25, 2020

opt: update cost of index join and statistics of array contains operation #54768

Merged

yuzefovich added a commit to yuzefovich/cockroach that referenced this issue Sep 25, 2020

sql: skip TestSchemaChangeEvalContext

b7b7a6e

Refs: cockroachdb#54775 Reason: flaky test Generated by bin/skip-test. Release justification: non-production code changes Release note: None

yuzefovich mentioned this issue Sep 25, 2020

sql: skip TestSchemaChangeEvalContext #54804

Merged

This was referenced Sep 28, 2020

sql: ensure backfills use the same timestamp in their evalContext #54891

Closed

sql: fix a bug tracking spans in a backfill #54900

Merged

craig bot closed this as completed in 6cec366 Sep 29, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

sql: TestSchemaChangeEvalContext failed #54775

sql: TestSchemaChangeEvalContext failed #54775

cockroach-teamcity commented Sep 25, 2020

yuzefovich commented Sep 25, 2020

cockroach-teamcity commented Sep 25, 2020

cockroach-teamcity commented Sep 25, 2020

rytaft commented Sep 25, 2020

cockroach-teamcity commented Sep 25, 2020

ajwerner commented Sep 28, 2020

ajwerner commented Sep 28, 2020

thoszhang commented Sep 28, 2020

ajwerner commented Sep 28, 2020

sql: TestSchemaChangeEvalContext failed #54775

sql: TestSchemaChangeEvalContext failed #54775

Comments

cockroach-teamcity commented Sep 25, 2020

yuzefovich commented Sep 25, 2020

cockroach-teamcity commented Sep 25, 2020

cockroach-teamcity commented Sep 25, 2020

rytaft commented Sep 25, 2020

cockroach-teamcity commented Sep 25, 2020

ajwerner commented Sep 28, 2020

ajwerner commented Sep 28, 2020

thoszhang commented Sep 28, 2020

ajwerner commented Sep 28, 2020