cockroachdb / pebble

RocksDB/LevelDB inspired key-value database in Go
BSD 3-Clause "New" or "Revised" License
4.95k stars 458 forks source link

github.com/cockroachdb/pebble/internal/metamorphic: TestMetaTwoInstance failed #4131

Closed cockroach-teamcity closed 2 weeks ago

cockroach-teamcity commented 3 weeks ago

github.com/cockroachdb/pebble/internal/metamorphic.TestMetaTwoInstance failed with artifacts on refs/heads/master @ 71bb6ba29095:

        iter20.SeekLT("exlxiaw@3", "") // [false] <nil> #3138
        iter20.Last() // [true,"omgc",<no point>,["omgc","tusyvljv@1")=>{""="kndcvqcsuegp","@9"="rnnrfzfycyppxbyywvn"}*] <nil> #3166
        iter20.SeekGE("jilwthysnty@7", "") // [true,"leytqraym@9",<no point>,["leytqraym@9","ndjxwnqxiykn")=>{""="kndcvqcsuegp","@9"="ppobfjw"}*] <nil> #3176
        iter20.SetBounds("", "jdpkkpywvk@7") // <nil> #3182
        // 05:26:12.926 INFO: [JOB 70] compacted(default) L0 [000038 000049] (5.4KB) Score=100.00 + L6 [000042] (1.6KB) Score=0.00 -> L6 [000050] (2.7KB), in 0.0s (0.0s total), output rate 544KB/s
        iter30.Prev("") // [true,"kqbgbhegr",<no point>,["kqbgbhegr","mcptdj@9")=>{""="kndcvqcsuegp","@9"="ppobfjw","@8"="fijop","@4"="egcekdmwyko"}*] <nil> #3257
        iter30.SetBounds("pvtdfmhftakb@1", "udty@7") // <nil> #3259
        iter20.SeekLT("jdpkkpywvk@7", "") // [true,"hxylycxmyft",<no point>,["hxylycxmyft","jdpkkpywvk@7")=>{"@9"="yjhlwayywydotfkv"}*] <nil> #3183
        iter21.Next("") // [false] <nil> #3132
        // 05:26:12.927 INFO: [JOB 108] compacting: sstable created 000071
        iter22.Next("") // [true,"hphdgdyyf",<no point>,["hphdgdyyf","hxylycxmyft")=>{""="ccjtckcyocobv"}*] <nil> #2987
        iter22.Next("") // [true,"hxylycxmyft",<no point>,["hxylycxmyft","jilwthysnty@7")=>{"@9"="yjhlwayywydotfkv"}*] <nil> #3003
        // 05:26:12.929 INFO: [JOB 72] WAL deleted 000047
        db2.LogData("u") // <nil> #3062
        db1.Delete("wqusxjuldlk@6") // <nil> #3016
        iter29.Last() // [true,"yfibrmosts",<no point>,["yfibrmosts","yzbbrcrl")=>{"@7"="bqxwmdfxcqzulrv","@3"="msuxzothagfdqgxtyele"}*] <nil> #3216
        iter21.SetBounds("", "hpnqr@6") // <nil> #3170
        iter20.Next("") // [false] <nil> #3184
        // 05:26:12.929 INFO: [JOB 108] compacted(elision-only) L6 [000070] (2.3KB) Score=0.00 + L6 [] (0B) Score=0.00 -> L6 [000071] (1.5KB), in 0.0s (0.0s total), output rate 302KB/s
        iter20.Prev("") // [true,"hxylycxmyft",<no point>,["hxylycxmyft","jdpkkpywvk@7")=>{"@9"="yjhlwayywydotfkv"}*] <nil> #3185
        iter21.SeekLT("hpnqr@6", "") // [true,"hpbhhsryttfj",<no point>,["hpbhhsryttfj","hpnqr@6")=>{"@9"="yjhlwayywydotfkv"}*] <nil> #3171
        // 05:26:12.930 INFO: [JOB 108] sstable deleted 000070
        iter20.InternalNext() // switching from reverse to forward via internalNext is prohibited #3188
        iter21.Prev("") // [true,"hgdvmaju@5","axedhzixv",["exlxiaw","hpbhhsryttfj")=>{"@9"="yjhlwayywydotfkv","@7"="odgiylhedf"}*] <nil> #3172
        iter20.SeekGE("bzuwaamepf@6", "") // [true,"hphdgdyyf",<no point>,["hphdgdyyf","hxylycxmyft")=>{""="ccjtckcyocobv"}*] <nil> #3193
        iter20.Next("") // [true,"hxylycxmyft",<no point>,["hxylycxmyft","jdpkkpywvk@7")=>{"@9"="yjhlwayywydotfkv"}*] <nil> #3204
        iter20.SeekGE("mcptdj@2", "") // [false] <nil> #3209
        iter21.SeekGE("jkbz@9", "pmhwbicl@7") // [invalid] <nil> #3174
        iter20.First() // [true,"afjmkhwqj",<no point>,["afjmkhwqj","awzouxzoybm")=>{""="ccjtckcyocobv"}*] <nil> #3213
        iter20.SetBounds("viifwwi", "yzbbrcrl@8") // <nil> #3236
        iter21.First() // [true,"aizpxbgfaahp@7","tidahnnicfsirhtp",<no range>] <nil> #3178
        iter20.SeekGE("hpnqr@6", "") // [true,"viifwwi",<no point>,["viifwwi","wmzivwx")=>{""="kndcvqcsuegp","@9"="rnnrfzfycyppxbyywvn"}*] <nil> #3251
        iter20.SetBounds("nzyjipu@3", "ofijhd@9") // <nil> #3262
        iter21.Prev("tusyvljv@3") // [invalid] <nil> #3205
        iter20.SeekLT("ofijhd@9", "") // [true,"nzyjipu@3",<no point>,["nzyjipu@3","ofijhd@9")=>{""="kndcvqcsuegp"}*] <nil> #3263
        iter20.Next("") // [false] <nil> #3264
        iter20.Next("") // [false] <nil> #3265
        iter20.Prev("") // [true,"nzyjipu@3",<no point>,["nzyjipu@3","ofijhd@9")=>{""="kndcvqcsuegp"}*] <nil> #3266
        iter21.First() // [true,"aizpxbgfaahp@7","tidahnnicfsirhtp",<no range>] <nil> #3206
        db1.Delete("hpbhhsryttfj@2") // <nil> #3021
        iter21.Prev("") // [false] <nil> #3208
        iter21.NextPrefix() // [false] NextPrefix not permitted with upper bound hpnqr@6 #3219
        iter29.SetBounds("bwkoyxadgpw@6", "wldfbinnn@8") // <nil> #3228
        db1.Get("pvtdfmhftakb@1") // [""] pebble: not found #3024
        db1.Delete("kqbgbhegr") // <nil> #3033
        iter21.SeekLT("iidpz@9", "") // [true,"hpbhhsryttfj",<no point>,["hpbhhsryttfj","hpnqr@6")=>{"@9"="yjhlwayywydotfkv"}*] <nil> #3225
        iter30.SeekGE("pvtdfmhftakb@1", "") // [true,"pvtdfmhftakb@1",<no point>,["pvtdfmhftakb@1","sqnjppip")=>{"@9"="rnnrfzfycyppxbyywvn","@8"="fijop","@4"="egcekdmwyko"}*] <nil> #3260

        To reduce:  go test ./internal/metamorphic -tags invariants -run 'TestMetaTwoInstance$' --run-dir /artifacts/meta/241104-052554.3303162653962/standard-027 --try-to-reduce -v
        --- FAIL: TestMetaTwoInstance/execution/standard-027 (2.94s)
Help

To reproduce, try: ```bash go test -tags 'invariants' -exec 'stress -p 1' -timeout 0 -test.v -run 'TestMetaTwoInstance$' ./internal/metamorphic -seed 1730697954330043506 -ops "uniform:5000-10000" ```

This test on roachdash | Improve this report!

Jira issue: PEBBLE-294

jbowens commented 2 weeks ago
=== NAME  TestMetaTwoInstance/execution/standard-027
    meta.go:241: 
        ===== SEED =====
        1730697954330043506
        ===== ERR =====
        exit status 66
        ===== OUT =====
        ==================
        WARNING: DATA RACE
        Write at 0x00c0030c07e0 by goroutine 190:
          github.com/cockroachdb/pebble/sstable.(*singleLevelIterator[go.shape.struct { github.com/cockroachdb/pebble/sstable/rowblk.iter github.com/cockroachdb/pebble/sstable/rowblk.Iter },go.shape.*github.com/cockroachdb/pebble/sstable/rowblk.IndexIter,go.shape.eb7c958227f421b2b34e33f9383baa8eb4cd132ad8ad1af0ac397c32eec3846d,go.shape.*github.com/cockroachdb/pebble/sstable/rowblk.Iter]).resetForReuse()
              external/com_github_cockroachdb_pebble/sstable/reader_iter_single_lvl.go:388 +0xb9
          github.com/cockroachdb/pebble/sstable.(*singleLevelIterator[go.shape.struct { github.com/cockroachdb/pebble/sstable/rowblk.iter github.com/cockroachdb/pebble/sstable/rowblk.Iter },go.shape.*github.com/cockroachdb/pebble/sstable/rowblk.IndexIter,go.shape.eb7c958227f421b2b34e33f9383baa8eb4cd132ad8ad1af0ac397c32eec3846d,go.shape.*github.com/cockroachdb/pebble/sstable/rowblk.Iter]).Close()
              external/com_github_cockroachdb_pebble/sstable/reader_iter_single_lvl.go:1564 +0x8c
          github.com/cockroachdb/pebble/sstable.(*singleLevelIterator[github.com/cockroachdb/pebble/sstable/rowblk.IndexIter,*github.com/cockroachdb/pebble/sstable/rowblk.IndexIter,github.com/cockroachdb/pebble/sstable/rowblk.Iter,*github.com/cockroachdb/pebble/sstable/rowblk.Iter]).Close()
              external/com_github_cockroachdb_pebble/sstable/reader_iter_single_lvl.go:1561 +0x36
          github.com/cockroachdb/pebble.(*getIter).Next()
              external/com_github_cockroachdb_pebble/get_iter.go:123 +0x3e2
          github.com/cockroachdb/pebble.(*getIter).First()
              external/com_github_cockroachdb_pebble/get_iter.go:71 +0x26
          github.com/cockroachdb/pebble.(*Iterator).iterFirstWithinBounds()
              external/com_github_cockroachdb_pebble/iterator.go:2099 +0x185
          github.com/cockroachdb/pebble.(*Iterator).First()
              external/com_github_cockroachdb_pebble/iterator.go:1651 +0x2bd
          github.com/cockroachdb/pebble.(*DB).getInternal()
              external/com_github_cockroachdb_pebble/db.go:618 +0x784
          github.com/cockroachdb/pebble.(*DB).Get()
              external/com_github_cockroachdb_pebble/db.go:539 +0x64
          github.com/cockroachdb/pebble/metamorphic.(*getOp).run.func1()
              external/com_github_cockroachdb_pebble/metamorphic/ops.go:1092 +0x8b
          github.com/cockroachdb/pebble/metamorphic.withRetries()
              external/com_github_cockroachdb_pebble/metamorphic/retryable.go:29 +0x2e
          github.com/cockroachdb/pebble/metamorphic.(*Test).withRetries()
              external/com_github_cockroachdb_pebble/metamorphic/test.go:249 +0x1ac
          github.com/cockroachdb/pebble/metamorphic.(*getOp).run()
              external/com_github_cockroachdb_pebble/metamorphic/ops.go:1091 +0xa7
          github.com/cockroachdb/pebble/metamorphic.(*Test).runOp()
              external/com_github_cockroachdb_pebble/metamorphic/test.go:435 +0x23b
          github.com/cockroachdb/pebble/metamorphic.Execute.func1()
              external/com_github_cockroachdb_pebble/metamorphic/meta.go:630 +0x224
          golang.org/x/sync/errgroup.(*Group).Go.func1()
              external/org_golang_x_sync/errgroup/errgroup.go:78 +0x91

        Previous read at 0x00c0030c07e0 by goroutine 194:
          github.com/cockroachdb/pebble/internal/base.(*LazyValue).Len()
              external/com_github_cockroachdb_pebble/internal/base/lazy_value.go:239 +0x1a6
          github.com/cockroachdb/pebble.(*Iterator).maybeSampleRead()
              external/com_github_cockroachdb_pebble/iterator.go:812 +0x127
          github.com/cockroachdb/pebble.(*Iterator).SeekLTWithLimit()
              external/com_github_cockroachdb_pebble/iterator.go:1616 +0xba7
          github.com/cockroachdb/pebble.(*Iterator).SeekLT()
              external/com_github_cockroachdb_pebble/iterator.go:1531 +0x78
          github.com/cockroachdb/pebble/metamorphic.(*retryableIter).SeekLT.func1()
              external/com_github_cockroachdb_pebble/metamorphic/retryable.go:159 +0x12
          github.com/cockroachdb/pebble/metamorphic.(*retryableIter).withRetry()
              external/com_github_cockroachdb_pebble/metamorphic/retryable.go:47 +0x43
          github.com/cockroachdb/pebble/metamorphic.(*retryableIter).SeekLT()
              external/com_github_cockroachdb_pebble/metamorphic/retryable.go:159 +0xbb
          github.com/cockroachdb/pebble/metamorphic.(*iterSeekLTOp).run()
              external/com_github_cockroachdb_pebble/metamorphic/ops.go:1532 +0x191
          github.com/cockroachdb/pebble/metamorphic.(*Test).runOp()
              external/com_github_cockroachdb_pebble/metamorphic/test.go:435 +0x23b
          github.com/cockroachdb/pebble/metamorphic.Execute.func1()
              external/com_github_cockroachdb_pebble/metamorphic/meta.go:630 +0x224
          golang.org/x/sync/errgroup.(*Group).Go.func1()
              external/org_golang_x_sync/errgroup/errgroup.go:78 +0x91

        Goroutine 190 (running) created at:
          golang.org/x/sync/errgroup.(*Group).Go()
              external/org_golang_x_sync/errgroup/errgroup.go:75 +0x124
          github.com/cockroachdb/pebble/metamorphic.Execute()
              external/com_github_cockroachdb_pebble/metamorphic/meta.go:607 +0xa8
          github.com/cockroachdb/pebble/metamorphic.RunOnce()
              external/com_github_cockroachdb_pebble/metamorphic/meta.go:565 +0x1d84
          github.com/cockroachdb/pebble/internal/metamorphic.runTestMeta()
              external/com_github_cockroachdb_pebble/internal/metamorphic/meta_test.go:87 +0x6b7
          github.com/cockroachdb/pebble/internal/metamorphic.TestMetaTwoInstance()
              external/com_github_cockroachdb_pebble/internal/metamorphic/meta_test.go:58 +0x2b
          testing.tRunner()
              GOROOT/src/testing/testing.go:1689 +0x21e
          testing.(*T).Run.gowrap1()
              GOROOT/src/testing/testing.go:1742 +0x44

        Goroutine 194 (running) created at:
          golang.org/x/sync/errgroup.(*Group).Go()
              external/org_golang_x_sync/errgroup/errgroup.go:75 +0x124
          github.com/cockroachdb/pebble/metamorphic.Execute()
              external/com_github_cockroachdb_pebble/metamorphic/meta.go:607 +0xa8
          github.com/cockroachdb/pebble/metamorphic.RunOnce()
              external/com_github_cockroachdb_pebble/metamorphic/meta.go:565 +0x1d84
          github.com/cockroachdb/pebble/internal/metamorphic.runTestMeta()
              external/com_github_cockroachdb_pebble/internal/metamorphic/meta_test.go:87 +0x6b7
          github.com/cockroachdb/pebble/internal/metamorphic.TestMetaTwoInstance()
              external/com_github_cockroachdb_pebble/internal/metamorphic/meta_test.go:58 +0x2b
          testing.tRunner()
              GOROOT/src/testing/testing.go:1689 +0x21e
          testing.(*T).Run.gowrap1()
              GOROOT/src/testing/testing.go:1742 +0x44
        ==================
jbowens commented 2 weeks ago

@RaduBerinde Is this LazyValue.Len() race related to the refactor to remove the allocation? Also appeared here: https://github.com/cockroachdb/pebble/issues/4114#issuecomment-2457881947

RaduBerinde commented 2 weeks ago

Hm, very likely, I'll take a look.