Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

github.com/cockroachdb/pebble/internal/metamorphic: TestMeta failed #3681

Open
cockroach-teamcity opened this issue Jun 21, 2024 · 6 comments
Open

github.com/cockroachdb/pebble/internal/metamorphic: TestMeta failed #3681

cockroach-teamcity opened this issue Jun 21, 2024 · 6 comments
Assignees
@RaduBerinde
Labels
A-storage branch-master C-test-failure O-metamorphic O-robot T-storage
Projects
(Deprecated) Storage

Comments

@cockroach-teamcity
Copy link
Member

cockroach-teamcity commented Jun 21, 2024 •
edited by cockroach-jira-scripts
Loading

github.com/cockroachdb/pebble/internal/metamorphic.TestMeta failed with artifacts on refs/heads/master @ a654bd3e78ec:

        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 026622
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 027040
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 027537
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 027733
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 027916
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 028371
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 028622
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 029119
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 029553
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 029671
        // 12:17:49.899 INFO: [JOB 9946] sstable deleted 030134
        // 12:17:49.914 INFO: [JOB 9953] compacting: sstable created 030445
        // 12:17:49.924 INFO: [JOB 9950] compacted(download,copy) L0 [028055] (846B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [030444] (791B), in 0.0s (10.8s total), output rate 469KB/s
        // 12:17:55.218 INFO: [JOB 9955] compacting(download,copy) L0 [027236] (846B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:17:55.239 INFO: [JOB 9953] compacted(default) L0 [020806 021214 021533 021781 022021 022238 022802 023094 023236 023586 024063 024421 025234 025382 025995 026356 026640 027058 027555 027751 027939 028389 028640 028793 029142 029573 030155] (24KB) Score=12625.00 + L1 [] (0B) Score=0.00 -> L1 [030445] (1.2KB), in 0.0s (5.3s total), output rate 80KB/s
        // 12:18:00.526 INFO: [JOB 9957] compacting(move) L2 [030440] (1.3KB) Score=6.38 + L3 [] (0B) Score=5.30; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:00.527 INFO: [JOB 9953] sstable deleted 025995
        // 12:18:00.527 INFO: [JOB 9953] sstable deleted 026356
        // 12:18:00.527 INFO: [JOB 9953] sstable deleted 026640
        // 12:18:00.527 INFO: [JOB 9953] sstable deleted 027058
        // 12:18:00.527 INFO: [JOB 9953] sstable deleted 027555
        // 12:18:00.527 INFO: [JOB 9953] sstable deleted 027751
        // 12:18:00.531 INFO: [JOB 9952] compacted(move) L1 [030443] (1.3KB) Score=5.46 + L2 [] (0B) Score=4.87 -> L2 [030443] (1.3KB), in 0.0s (16.0s total), output rate 238MB/s
        // 12:18:05.971 INFO: [JOB 9958] compacting(default) L3 [029857] (1.1KB) Score=5.77 + L4 [] (0B) Score=4.94; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:05.971 INFO: [JOB 9953] sstable deleted 027939
        // 12:18:05.971 INFO: [JOB 9953] sstable deleted 028389
        // 12:18:05.972 INFO: [JOB 9953] sstable deleted 028640
        // 12:18:05.972 INFO: [JOB 9953] sstable deleted 028793
        // 12:18:05.972 INFO: [JOB 9953] sstable deleted 029142
        // 12:18:05.972 INFO: [JOB 9953] sstable deleted 029573
        // 12:18:05.972 INFO: [JOB 9953] sstable deleted 030155
        // 12:18:05.972 INFO: [JOB 9958] compacting: sstable created 030447
        // 12:18:05.991 INFO: [JOB 9955] compacted(download,copy) L0 [027236] (846B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [030446] (791B), in 0.0s (10.8s total), output rate 362KB/s
        // 12:18:11.275 INFO: [JOB 9960] compacting(download,copy) L0 [027823] (846B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:11.278 INFO: [JOB 9958] compacted(default) L3 [029857] (1.1KB) Score=5.77 + L4 [] (0B) Score=4.94 -> L4 [030447] (1.1KB), in 0.0s (5.3s total), output rate 797KB/s
        // 12:18:16.766 INFO: [JOB 9962] compacting(move) L1 [030445] (1.2KB) Score=5.54 + L2 [] (0B) Score=5.13; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:16.787 INFO: [JOB 9960] compacted(download,copy) L0 [027823] (846B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [030448] (791B), in 5.5s (5.5s total), output rate 144B/s
        // 12:18:22.060 INFO: [JOB 9964] compacting(download,copy) L0 [029076] (846B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:22.060 INFO: [JOB 9960] sstable deleted 029857
        // 12:18:22.063 INFO: [JOB 9962] compacted(move) L1 [030445] (1.2KB) Score=5.54 + L2 [] (0B) Score=5.13 -> L2 [030445] (1.2KB), in 0.0s (5.3s total), output rate 137MB/s
        // 12:18:27.302 INFO: [JOB 9965] compacting(default) L0 [021205 021523 020960 021769 021770 021771 022009 022011 022012 022227 022228 022229 022791 022792 022793 023083 023084 023085 023225 023226 023227 023575 023576 023577 024052 024053 024054 024410 024411 024412 025223 025224 025225 025371 025372 025373 025453 025633 025979 025980 025981 025982 025983 025984 025985 026337 026338 026339 026340 026342 026343 026345 026537 026623 026624 026625 026626 026627 026628 026629 026630 027041 027042 027043 027044 027045 027046 027047 027048 027538 027539 027540 027541 027542 027543 027544 027545 027734 027735 027736 027737 027738 027739 027740 027741 027918 027919 027921 027922 027923 027925 027926 027928 028372 028373 028374 028375 028376 028377 028378 028379 028623 028624 028625 028626 028627 028628 028629 028630 028781 029120 029121 029123 029124 029125 029127 029128 029129 029130 029131 029554 029555 029556 029557 029558 029559 029560 029561 029562 029563 030135 030136 030137 030138 030140 030141 030142 030143 030144] (122KB) Score=12582.81 + L1 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:27.326 INFO: [JOB 9964] compacted(download,copy) L0 [029076] (846B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [030449] (791B), in 5.2s (5.3s total), output rate 150B/s
        // 12:18:32.739 INFO: [JOB 9967] compacting(download,copy) L0 [029082] (846B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 12:18:32.740 INFO: [JOB 9965] compacting: sstable created 030451
        // 12:18:32.743 INFO: [JOB 9957] compacted(move) L2 [030440] (1.3KB) Score=6.38 + L3 [] (0B) Score=5.30 -> L3 [030440] (1.3KB), in 0.0s (32.2s total), output rate 172MB/s
        
        To reduce:  go test ./internal/metamorphic -tags invariants -run 'TestMeta$' --run-dir /artifacts/meta/240621-115706.6123867796705/random-008 --try-to-reduce -v
        --- FAIL: TestMeta/execution/random-008 (1272.84s)
=== RUN   TestMeta/execution
    --- FAIL: TestMeta/execution (0.00s)
Help

To reproduce, try: 

go test -tags 'invariants' -exec 'stress -p 1' -timeout 0 -test.v -run 'TestMeta$' ./internal/metamorphic -seed 1718971026612135615 -ops "uniform:5000-10000"

This test on roachdash | Improve this report!

Jira issue: PEBBLE-39
@blathers-crl blathers-crl bot added this to Incoming in (Deprecated) Storage Jun 21, 2024
@RaduBerinde
Copy link
Member 

panic: operation took longer than 4m0s: db1.Download("hgqyqadrcz@34" /* start */, "owdocdk@100" /* end */, true /* viaBackingFileDownload */)

@RaduBerinde RaduBerinde self-assigned this Jun 21, 2024
@itsbilal
Copy link
Member

On the plus side I think we can close #3635 now, seeing as my change to bump up the stress per-run timeout resulted in this (more actionable) timeout of the download operation.

This was referenced Jun 23, 2024
Closed
Closed
@cockroach-teamcity
Copy link
Member Author

github.com/cockroachdb/pebble/internal/metamorphic.TestMeta failed with artifacts on refs/heads/master @ 3ef2e5b1f693:

        // 09:05:15.000 INFO: [JOB 684] compacted(download,copy) L0 [018916] (868B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024067] (812B), in 0.0s (4.8s total), output rate 199KB/s
        // 09:05:19.712 INFO: [JOB 687] compacting(download,copy) L0 [016130] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:19.712 INFO: [JOB 688] compacting(download,copy) L0 [014471] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:19.734 INFO: [JOB 678] compacted(default) L0 [012461 012806 013281 013868 014358 014693 014956 015453 015723 016036 016499 016907 017347 017642 017871 018178 018613 019125 019572 020128 020332 020791 021306 021608 022323 022607 023200 023650] (24KB) Score=33.27 + L3 [] (0B) Score=16.91 -> L3 [024065] (1.1KB), in 4.9s (23.5s total), output rate 238B/s
        // 09:05:24.351 INFO: [JOB 678] sstable deleted 022323
        // 09:05:24.351 INFO: [JOB 678] sstable deleted 022607
        // 09:05:24.351 INFO: [JOB 678] sstable deleted 023200
        // 09:05:24.351 INFO: [JOB 678] sstable deleted 023650
        // 09:05:24.371 INFO: [JOB 688] compacted(download,copy) L0 [014471] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024069] (798B), in 0.0s (4.7s total), output rate 198KB/s
        // 09:05:28.902 INFO: [JOB 691] compacting(download,copy) L0 [009056] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:28.902 INFO: [JOB 692] compacting(default) multilevelL3 [024065] (1.1KB) Score=35.77 + L4 [] (0B) Score=14.19 + L5 [] (0B) Score=101.93; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:28.903 INFO: [JOB 692] compacting: sstable created 024071
        // 09:05:28.924 INFO: [JOB 687] compacted(download,copy) L0 [016130] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024068] (798B), in 0.0s (9.2s total), output rate 187KB/s
        // 09:05:33.641 INFO: [JOB 694] compacting(download,copy) L0 [024021] (868B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:33.664 INFO: [JOB 691] compacted(download,copy) L0 [009056] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024070] (798B), in 0.0s (4.8s total), output rate 197KB/s
        // 09:05:38.228 INFO: [JOB 696] compacting(download,copy) L0 [022060] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:38.250 INFO: [JOB 694] compacted(download,copy) L0 [024021] (868B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024072] (812B), in 0.0s (4.6s total), output rate 158KB/s
        // 09:05:42.944 INFO: [JOB 698] compacting(download,copy) L0 [021058] (868B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:42.966 INFO: [JOB 696] compacted(download,copy) L0 [022060] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024073] (798B), in 0.0s (4.7s total), output rate 192KB/s
        // 09:05:47.636 INFO: [JOB 700] compacting(download,copy) L0 [024027] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:47.659 INFO: [JOB 698] compacted(download,copy) L0 [021058] (868B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024074] (812B), in 0.0s (4.7s total), output rate 194KB/s
        // 09:05:52.289 INFO: [JOB 702] compacting(download,copy) L0 [014162] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:52.312 INFO: [JOB 700] compacted(download,copy) L0 [024027] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024075] (798B), in 0.0s (4.7s total), output rate 205KB/s
        // 09:05:56.882 INFO: [JOB 704] compacting(download,copy) L0 [017583] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:05:56.903 INFO: [JOB 702] compacted(download,copy) L0 [014162] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024076] (798B), in 0.0s (4.6s total), output rate 156KB/s
        // 09:06:01.665 INFO: [JOB 704] compacted(download,copy) L0 [017583] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024077] (798B), in 0.0s (4.8s total), output rate 187KB/s
        // 09:06:06.286 INFO: [JOB 706] compacting(download,copy) L0 [017923] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:06:06.295 INFO: [JOB 692] compacted(default) multilevelL3 [024065] (1.1KB) Score=35.77 + L4 [] (0B) Score=14.19 + L5 [] (0B) Score=101.93 -> L5 [024071] (1.1KB), in 0.0s (37.4s total), output rate 1.2MB/s
        // 09:06:10.883 INFO: [JOB 692] sstable deleted 024065
        // 09:06:10.908 INFO: [JOB 706] compacted(download,copy) L0 [017923] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024078] (798B), in 0.0s (4.6s total), output rate 121KB/s
        // 09:06:15.490 INFO: [JOB 710] compacting(download,copy) L0 [018911] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:06:15.490 INFO: [JOB 711] compacting(default) L0 [012457 012801 013277 013864 014354 014689 014952 015449 015719 016032 016495 016903 017343 017637 017867 018172 018607 019117 019564 020120 020324 020783 021299 021600 022315 022599 023192 023642] (24KB) Score=33.18 + L3 [] (0B) Score=16.89; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:06:15.504 INFO: [JOB 711] compacting: sstable created 024080
        // 09:06:15.517 INFO: [JOB 710] compacted(download,copy) L0 [018911] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024079] (798B), in 0.0s (0.0s total), output rate 190KB/s
        // 09:06:20.036 INFO: [JOB 713] compacting(download,copy) L0 [020166] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:06:20.058 INFO: [JOB 711] compacted(default) L0 [012457 012801 013277 013864 014354 014689 014952 015449 015719 016032 016495 016903 017343 017637 017867 018172 018607 019117 019564 020120 020324 020783 021299 021600 022315 022599 023192 023642] (24KB) Score=33.18 + L3 [] (0B) Score=16.89 -> L3 [024080] (1.1KB), in 0.0s (4.6s total), output rate 66KB/s
        // 09:06:24.898 INFO: [JOB 711] sstable deleted 022315
        // 09:06:24.898 INFO: [JOB 711] sstable deleted 022599
        // 09:06:24.899 INFO: [JOB 711] sstable deleted 023192
        // 09:06:24.899 INFO: [JOB 711] sstable deleted 023642
        // 09:06:24.919 INFO: [JOB 713] compacted(download,copy) L0 [020166] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024081] (798B), in 0.0s (4.9s total), output rate 189KB/s
        // 09:06:29.634 INFO: [JOB 716] compacting(download,copy) L0 [020565] (853B) Score=0.00 + L0 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 09:06:29.634 INFO: [JOB 717] compacting(default) L5 [024055 020281] (2.5KB) Score=103.66 + L6 [018101] (1.4KB) Score=0.01; OverlappingRatio: Single 0.57, Multi 0.00
        // 09:06:29.649 INFO: [JOB 717] compacting: sstable created 024083
        // 09:06:29.659 INFO: [JOB 716] compacted(download,copy) L0 [020565] (853B) Score=0.00 + L0 [] (0B) Score=0.00 -> L0 [024082] (798B), in 0.0s (0.0s total), output rate 196KB/s
        
        To reduce:  go test ./internal/metamorphic -tags invariants -run 'TestMeta$' --run-dir /artifacts/meta/240630-084959.5912243176475/random-018 --try-to-reduce -v
        --- FAIL: TestMeta/execution/random-018 (982.46s)
=== RUN   TestMeta/execution
    --- FAIL: TestMeta/execution (0.00s)
Help

To reproduce, try: 

go test -tags 'invariants' -exec 'stress -p 1' -timeout 0 -test.v -run 'TestMeta$' ./internal/metamorphic -seed 1719737399591744012 -ops "uniform:5000-10000"

This test on roachdash | Improve this report!

@cockroach-teamcity
Copy link
Member Author

github.com/cockroachdb/pebble/internal/metamorphic.TestMeta failed with artifacts on refs/heads/master @ 4981bd0e5e95:

        // 07:32:08.418 INFO: [JOB 511] compacting: sstable created 024464
        // 07:32:08.429 INFO: [JOB 511] compacted(default) L4 [024461] (1.2KB) Score=7.96 + L5 [] (0B) Score=72.65 -> L5 [024464] (1.2KB), in 0.0s (0.0s total), output rate 114KB/s
        // 07:32:12.013 INFO: [JOB 511] sstable deleted 024461
        // 07:32:12.013 INFO: [JOB 513] compacting(move) L3 [024463] (1.2KB) Score=6.72 + L4 [] (0B) Score=7.14; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:12.015 INFO: [JOB 513] compacted(move) L3 [024463] (1.2KB) Score=6.72 + L4 [] (0B) Score=7.14 -> L4 [024463] (1.2KB), in 0.0s (0.0s total), output rate 236MB/s
        // 07:32:15.706 INFO: [JOB 514] compacting(default) L0 [012391 012656 013021 013422 014054 014359 014462 014755 014823 015116 015906 016330 016594 016926 017261 017432 018077 018593 019569 020208 020739 021447 022271 022501 023363 023907 024092] (23KB) Score=630.37 + L3 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:15.728 INFO: [JOB 514] compacting: sstable created 024465
        // 07:32:15.746 INFO: [JOB 514] compacted(default) L0 [012391 012656 013021 013422 014054 014359 014462 014755 014823 015116 015906 016330 016594 016926 017261 017432 018077 018593 019569 020208 020739 021447 022271 022501 023363 023907 024092] (23KB) Score=630.37 + L3 [] (0B) Score=0.00 -> L3 [024465] (1.2KB), in 0.0s (0.0s total), output rate 50KB/s
        // 07:32:18.974 INFO: [JOB 516] compacting(default) L4 [024463] (1.2KB) Score=7.88 + L5 [] (0B) Score=73.40; OverlappingRatio: Single 0.00, Multi 1.98
        // 07:32:18.976 INFO: [JOB 516] compacting: sstable created 024466
        // 07:32:18.981 INFO: [JOB 516] compacted(default) L4 [024463] (1.2KB) Score=7.88 + L5 [] (0B) Score=73.40 -> L5 [024466] (1.2KB), in 0.0s (0.0s total), output rate 234KB/s
        // 07:32:22.525 INFO: [JOB 518] compacting(move) L3 [024465] (1.2KB) Score=6.59 + L4 [] (0B) Score=7.04; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:22.526 INFO: [JOB 516] sstable deleted 024463
        // 07:32:22.528 INFO: [JOB 518] compacted(move) L3 [024465] (1.2KB) Score=6.59 + L4 [] (0B) Score=7.04 -> L4 [024465] (1.2KB), in 0.0s (0.0s total), output rate 242MB/s
        // 07:32:26.246 INFO: [JOB 519] compacting(default) L0 [012393 012658 013024 013424 014056 014361 014464 014757 014826 015118 015908 016332 016596 016928 017263 017434 018079 018595 019571 020210 020741 021449 022273 022503 023365 023909 024094] (23KB) Score=627.73 + L3 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:26.290 INFO: [JOB 519] compacting: sstable created 024467
        // 07:32:26.309 INFO: [JOB 519] compacted(default) L0 [012393 012658 013024 013424 014056 014361 014464 014757 014826 015118 015908 016332 016596 016928 017263 017434 018079 018595 019571 020210 020741 021449 022273 022503 023365 023909 024094] (23KB) Score=627.73 + L3 [] (0B) Score=0.00 -> L3 [024467] (1.2KB), in 0.0s (0.1s total), output rate 25KB/s
        // 07:32:29.763 INFO: [JOB 521] compacting(default) L4 [024465] (1.2KB) Score=7.75 + L5 [] (0B) Score=74.19; OverlappingRatio: Single 0.00, Multi 1.13
        // 07:32:29.766 INFO: [JOB 521] compacting: sstable created 024468
        // 07:32:29.771 INFO: [JOB 521] compacted(default) L4 [024465] (1.2KB) Score=7.75 + L5 [] (0B) Score=74.19 -> L5 [024468] (1.2KB), in 0.0s (0.0s total), output rate 221KB/s
        // 07:32:33.255 INFO: [JOB 521] sstable deleted 024465
        // 07:32:33.255 INFO: [JOB 523] compacting(move) L3 [024467] (1.2KB) Score=6.35 + L4 [] (0B) Score=6.94; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:33.257 INFO: [JOB 523] compacted(move) L3 [024467] (1.2KB) Score=6.35 + L4 [] (0B) Score=6.94 -> L4 [024467] (1.2KB), in 0.0s (0.0s total), output rate 278MB/s
        // 07:32:36.760 INFO: [JOB 524] compacting(default) L0 [012394 012659 013025 013425 014057 014362 014465 014758 014827 015119 015909 016333 016597 016929 017264 017435 018080 018596 019572 020211 020742 021450 022274 022504 023366 023910 024095] (23KB) Score=625.10 + L3 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:36.826 INFO: [JOB 524] compacting: sstable created 024469
        // 07:32:36.845 INFO: [JOB 524] compacted(default) L0 [012394 012659 013025 013425 014057 014362 014465 014758 014827 015119 015909 016333 016597 016929 017264 017435 018080 018596 019572 020211 020742 021450 022274 022504 023366 023910 024095] (23KB) Score=625.10 + L3 [] (0B) Score=0.00 -> L3 [024469] (1.2KB), in 0.1s (0.1s total), output rate 17KB/s
        // 07:32:40.211 INFO: write stall ending
        // 07:32:40.211 INFO: [JOB 527] compacting(default) L4 [024462] (1.2KB) Score=7.61 + L5 [] (0B) Score=74.95; OverlappingRatio: Single 0.00, Multi 1.14
        // 07:32:40.214 INFO: [JOB 525] WAL created 024470
        // 07:32:40.214 INFO: [JOB 528] flushing 1 memtable (414B) to L0
        // 07:32:40.214 INFO: [JOB 528] flushing: sstable created 024471
        // 07:32:40.215 INFO: [JOB 528] flushing: sstable created 024472
        // 07:32:40.216 INFO: [JOB 527] compacting: sstable created 024473
        // 07:32:40.229 INFO: [JOB 528] flushing: sstable created 024474
        // 07:32:40.231 INFO: [JOB 527] compacted(default) L4 [024462] (1.2KB) Score=7.61 + L5 [] (0B) Score=74.95 -> L5 [024473] (1.2KB), in 0.0s (0.0s total), output rate 70KB/s
        // 07:32:43.487 INFO: [JOB 528] flushing: sstable created 024475
        // 07:32:43.488 INFO: [JOB 530] compacting(move) L3 [024469] (1.2KB) Score=6.48 + L4 [] (0B) Score=6.82; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:43.488 INFO: [JOB 527] sstable deleted 024462
        // 07:32:43.490 INFO: [JOB 530] compacted(move) L3 [024469] (1.2KB) Score=6.48 + L4 [] (0B) Score=6.82 -> L4 [024469] (1.2KB), in 0.0s (0.0s total), output rate 267MB/s
        // 07:32:46.840 INFO: [JOB 531] compacting(default) L0 [012763 013147 013535 014176 014585 014944 015240 015667 015540 016030 016031 016032 015745 016456 016457 016459 016460 016461 016705 016706 016707 016708 016709 017576 017577 017578 017579 017580 017738 017739 017740 017741 017742 017658 018220 018221 018222 018223 018224 018225 018226 018731 018732 018733 018734 018735 018736 018737 019024 019025 019026 019027 019028 019029 019030 019233 019239 019704 019702 019703 019705 019706 019707 019708 019709 019710 019711 019712 019821 019822 019823 019824 019825 019826 019827 019828 019829 019830 019831 020344 020345 020346 020347 020348 020349 020350 020351 020352 020353 020354 020949 020955 020956 020957 020958 020959 020960 021588 021589 021590 021591 021592 021593 021594 021595 021596 021597 021598 021599 021600 021601 021903 022094 022095 022096 022097 022644 022645 022646 022647 022648 022649 022650 022651 022652 022653 022654 022655 022656 022657 022658 022843 022844 022845 022846 022847 022848 022849 022850 022851 022852 022853 022854 022855 022856 022857 023463 023464 023465 023466 023467 023468 023469 023470 023471 023472 023473 023474 023475 023476 023477 024046 024237 024240 024241 024242 024243 024244 024245 024246 024249 024251 024058] (148KB) Score=622.46 + L3 [] (0B) Score=0.00; OverlappingRatio: Single 0.00, Multi 0.00
        // 07:32:46.840 INFO: [JOB 528] flushing: sstable created 024476
        // 07:32:46.840 INFO: [JOB 528] flushing: sstable created 024477
        // 07:32:46.840 INFO: [JOB 528] flushing: sstable created 024478
        // 07:32:46.842 INFO: [JOB 528] flushing: sstable created 024479
        // 07:32:50.352 INFO: [JOB 528] flushed 1 memtable (414B) to L0 [024471 024472 024474 024475 024476 024477 024478 024479] (7.0KB), in 6.6s (10.1s total), output rate 1.1KB/s
        // 07:32:50.352 INFO: [JOB 531] compacting: sstable created 024480
        // 07:32:50.352 INFO: [JOB 528] WAL deleted 024054
        
        To reduce:  go test ./internal/metamorphic -tags invariants -run 'TestMeta$' --run-dir /artifacts/meta/240702-071749.1613085148326/random-008 --try-to-reduce -v
        --- FAIL: TestMeta/execution/random-008 (890.07s)
Help

To reproduce, try: 

go test -tags 'invariants' -exec 'stress -p 1' -timeout 0 -test.v -run 'TestMeta$' ./internal/metamorphic -seed 1719904669161584232 -ops "uniform:5000-10000"

This test on roachdash | Improve this report!

@jbowens
Copy link
Collaborator

jbowens commented Jul 2, 2024

I've forgotten all the context, do we understand why these download ops take so long?

@RaduBerinde
Copy link
Member

No.. i still need to investigate in more detail

@cockroach-teamcity cockroach-teamcity mentioned this issue Jul 4, 2024
Closed
jbowens added a commit to jbowens/pebble that referenced this issue Jul 10, 2024
@jbowens
metamorphic: limit aggregate injected I/O latency
4381080 
Limit the amount of I/O latency injected into any individual run of the
metamorphic test to improve worst-case test runtimes.

Informs cockroachdb#3681.
Informs cockroachdb#3733.
@jbowens jbowens mentioned this issue Jul 10, 2024
Merged
jbowens added a commit to jbowens/pebble that referenced this issue Jul 10, 2024
@jbowens
metamorphic: limit aggregate injected I/O latency
1635b06 
Limit the amount of I/O latency injected into any individual run of the
metamorphic test to improve worst-case test runtimes.

Informs cockroachdb#3681.
Informs cockroachdb#3733.
jbowens added a commit that referenced this issue Jul 10, 2024
@jbowens
metamorphic: limit aggregate injected I/O latency
3b1077d 
Limit the amount of I/O latency injected into any individual run of the
metamorphic test to improve worst-case test runtimes.

Informs #3681.
Informs #3733.
@cockroach-teamcity cockroach-teamcity mentioned this issue Jul 12, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@RaduBerinde RaduBerinde

Labels
A-storage branch-master C-test-failure O-metamorphic O-robot T-storage
Projects
Storage
Status: In Progress (this milestone)
(Deprecated) Storage
  
Incoming
Milestone
No milestone
Development

No branches or pull requests
5 participants
@itsbilal @nicktrav @jbowens @RaduBerinde @cockroach-teamcity