cockroachdb / cockroachdb/cockroach

storage/fs: TestBasaltMetrics failed

Open
#175,307 5 comments 0 reactions 0 assignees View on GitHub
A-storage branch-master C-test-failure O-robot P-1 T-storage
Dominant language
Go
Stars
32.5k
Forks
4.1k
PR merge metrics
PR metrics pending

Description

storage/fs.TestBasaltMetrics [failed](https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_Ci_TestsAwsLinuxArm64_UnitTests/21514273?buildTab=log) with [artifacts](https://teamcity.cockroachdb.com/buildConfiguration/Cockroach_Ci_TestsAwsLinuxArm64_UnitTests/21514273?buildTab=artifacts#/) on master @ [586bc08b6da5c647e5ec2b3f6a2e581acc69a876](https://github.com/cockroachdb/cockroach/commits/586bc08b6da5c647e5ec2b3f6a2e581acc69a876):

```
I260912 16:35:29.352302 2746 (gostd) log.go:56 [-] 455 INFO rpc component=rpc method=Mkdir tenant=test-tenant dir=00000000-0000-0000-0000-000000000000 name=cluster-1 dur=21.166208ms code=OK
I260912 16:35:29.352532 2690 (gostd) logger.go:37 [-] 456 INFO basaltfs: opened dir=0344c65b-dcf9-4789-b4a7-9a7bd0224fe8 zone=test-zone-1
I260912 16:35:29.359062 2818 (gostd) log.go:56 [-] 457 INFO rpc component=rpc method=Mkdir tenant=test-tenant dir=0344c65b-dcf9-4789-b4a7-9a7bd0224fe8 name=store-1 dur=6.176865ms code=OK
I260912 16:35:29.359273 2690 (gostd) logger.go:37 [-] 458 INFO basaltfs: opened dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 zone=test-zone-1
I260912 16:35:29.368876 2792 (gostd) log.go:56 [-] 459 INFO rpc component=rpc method=Lock tenant=test-tenant object=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 dur=9.385985ms code=OK
I260912 16:35:29.369350 2690 (gostd) logger.go:37 [-] 460 INFO basaltfs: locked dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2
I260912 16:35:29.376760 2747 (gostd) log.go:56 [-] 461 INFO rpc component=rpc method=List tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 dur=7.033763ms code=OK
I260912 16:35:29.383665 2793 (gostd) log.go:46 [-] 462 INFO rpc component=rpc method=StatByPath tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 name=STORAGE_MIN_VERSION dur=6.51846ms code=NotFound err="rpc error: code = NotFound desc = entry \"STORAGE_MIN_VERSION\" not found"
I260912 16:35:29.388116 2819 (gostd) log.go:56 [-] 463 INFO rpc component=rpc method=List tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 dur=3.925669ms code=OK
I260912 16:35:29.396757 2748 (gostd) log.go:56 [-] 464 INFO rpc component=rpc method=SetSetting tenant=test-tenant key=tenant_usage.interval value=10ms restore_default=false dur=8.296412ms code=OK
I260912 16:35:29.439996 2811 (gostd) log.go:56 [-] 465 INFO rpc component=rpc method=Create tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 name=metrics-test-file dur=37.879047ms code=OK
I260912 16:35:29.483015 2750 (gostd) seal_direct.go:721 [-] 466 INFO CopyFrom to materialize direct upload replica component=seal object=1e15df17-7a58-4008-a14c-99a98c98881d disk=1 size=29 dur=1.604704ms
I260912 16:35:29.483463 2751 (gostd) seal_direct.go:721 [-] 467 INFO CopyFrom to materialize direct upload replica component=seal object=1e15df17-7a58-4008-a14c-99a98c98881d disk=2 size=29 dur=2.036478ms
I260912 16:35:29.506964 90 (gostd) log.go:56 [-] 468 INFO rpc component=rpc method=Seal tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 name=metrics-test-file size=29 dur=55.714281ms code=OK
I260912 16:35:29.621592 2861 (gostd) log.go:56 [-] 469 INFO rpc component=rpc method=Mkdir tenant=test-tenant dir=0344c65b-dcf9-4789-b4a7-9a7bd0224fe8 name=store-2 dur=11.42856ms code=OK
I260912 16:35:29.621807 2690 (gostd) logger.go:37 [-] 470 INFO basaltfs: opened dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b zone=test-zone-1
I260912 16:35:29.633864 1681 (gostd) log.go:56 [-] 471 INFO rpc component=rpc method=Lock tenant=test-tenant object=2e72171f-7aa9-4862-9e1a-e82c43e39a8b dur=11.810921ms code=OK
I260912 16:35:29.634031 2690 (gostd) logger.go:37 [-] 472 INFO basaltfs: locked dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b
I260912 16:35:29.644506 2781 (gostd) log.go:56 [-] 473 INFO rpc component=rpc method=List tenant=test-tenant dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b dur=10.298725ms code=OK
I260912 16:35:29.655667 2862 (gostd) log.go:46 [-] 474 INFO rpc component=rpc method=StatByPath tenant=test-tenant dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b name=STORAGE_MIN_VERSION dur=9.270982ms code=NotFound err="rpc error: code = NotFound desc = entry \"STORAGE_MIN_VERSION\" not found"
I260912 16:35:29.659504 2863 (gostd) log.go:56 [-] 475 INFO rpc component=rpc method=List tenant=test-tenant dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b dur=3.472888ms code=OK
I260912 16:35:29.687487 2882 (gostd) log.go:56 [-] 476 INFO rpc component=rpc method=Create tenant=test-tenant dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b name=metrics-test-file-2 dur=24.180671ms code=OK
I260912 16:35:29.709044 2782 (gostd) seal_direct.go:721 [-] 477 INFO CopyFrom to materialize direct upload replica component=seal object=f214815b-dd49-449a-82df-7ad876aa2f0b disk=1 size=29 dur=1.089261ms
I260912 16:35:29.709113 2783 (gostd) seal_direct.go:721 [-] 478 INFO CopyFrom to materialize direct upload replica component=seal object=f214815b-dd49-449a-82df-7ad876aa2f0b disk=2 size=29 dur=1.244195ms
I260912 16:35:29.743333 2901 (gostd) log.go:56 [-] 479 INFO rpc component=rpc method=Seal tenant=test-tenant dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b name=metrics-test-file-2 size=29 dur=54.837744ms code=OK
I260912 16:35:29.749367 2690 (gostd) logger.go:37 [-] 480 INFO basaltfs: unlocked dir=2e72171f-7aa9-4862-9e1a-e82c43e39a8b
I260912 16:35:29.749431 2690 (gostd) logger.go:37 [-] 481 INFO basaltfs: closed
I260912 16:35:29.766841 2478 (gostd) log.go:56 [-] 482 INFO rpc component=rpc method=Create tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 name=metrics-test-file-archived dur=14.605865ms code=OK
I260912 16:35:29.787761 2884 (gostd) seal_direct.go:721 [-] 483 INFO CopyFrom to materialize direct upload replica component=seal object=c88e8db5-5019-4e1c-acf2-ed767b4f21bf disk=2 size=29 dur=1.736977ms
I260912 16:35:29.788542 2885 (gostd) seal_direct.go:721 [-] 484 INFO CopyFrom to materialize direct upload replica component=seal object=c88e8db5-5019-4e1c-acf2-ed767b4f21bf disk=1 size=29 dur=2.570751ms
I260912 16:35:29.798959 2822 (gostd) log.go:56 [-] 485 INFO rpc component=rpc method=Seal tenant=test-tenant dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2 name=metrics-test-file-archived size=29 dur=26.78504ms code=OK
I260912 16:35:29.804537 2690 (gostd) logger.go:37 [-] 486 INFO basaltfs: unlocked dir=eaeda4cc-a88c-4211-a4df-92cd5dc99ff2
I260912 16:35:29.804607 2690 (gostd) logger.go:37 [-] 487 INFO basaltfs: closed
I260912 16:35:29.804623 2690 (gostd) logger.go:37 [-] 488 INFO basaltfs: closed
basalt_test.go:1659:
Error Trace: pkg/storage/fs/basalt_test.go:1659
Error: Not equal:
expected: fs.archiveMetrics{staleUnsealedEntries:0, uploads:1, uploadRetries:0, uploadResigns:0, uploadFailures:0, bytesUploaded:0, finishPut:1, finishPartUpload:0, seal:1, putResponseWait:1, completeMultipartUpload:0, adoptHead:1, materialization:1}
actual : fs.archiveMetrics{staleUnsealedEntries:0, uploads:1, uploadRetries:0, uploadResigns:0, uploadFailures:0, bytesUploaded:0, finishPut:1, finishPartUpload:0, seal:1, putResponseWait:0, completeMultipartUpload:0, adoptHead:1, materialization:1}

Diff:
--- Expected
+++ Actual
@@ -10,3 +10,3 @@
seal: (int64) 1,
- putResponseWait: (int64) 1,
+ putResponseWait: (int64) 0,
completeMultipartUpload: (int64) 0,
Test: TestBasaltMetrics
--- FAIL: TestBasaltMetrics (7.70s)
```
Help

See also: [How To Investigate a Go Test Failure \(internal\)](https://cockroachlabs.atlassian.net/l/c/HgfXfJgM)

/cc @cockroachlabs/storage

[Improve this report!](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/bazci/githubpost/issues)

Jira issue: CRDB-68336

Contributor guide

Open the contributing guide

Research direction

Start with pkg/storage/fs/basalt_test.go at TestBasaltMetrics and reproduce the failure using the reported test. Trace why putResponseWait is 0 instead of the expected 1, using the log sequence and archiveMetrics assertion as the guide. Done means the metric behavior is correct and TestBasaltMetrics passes reliably.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
databases
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
72/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.