kv/kvclient/kvcoord: TestRangeFeedMetricsManagement failed

[cockroach-teamcity]

kv/kvclient/kvcoord.TestRangeFeedMetricsManagement failed on master @ ccdd2647944cbbda82017879398e376cb9478363:

=== RUN   TestRangeFeedMetricsManagement
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestRangeFeedMetricsManagement275544180
    test_log_scope.go:82: use -show-logs to present logs inline
    test_server_shim.go:141: cluster virtualization disabled in global scope due to issue: #156327 (expected label: C-bug)
    test_server_shim.go:594: DRPC is enabled (override by TestingGlobalDRPCOption)
    dist_sender_rangefeed_test.go:561: condition failed to evaluate within 3m45s: from dist_sender_rangefeed_test.go:563: waiting for frontier advance: [/Table/104/1{-/300}@0,0] [/Table/104/1/{300-500}@1762517824.519028645,0] [/Table/104/1/{500-900}@1762517833.239785603,0] [/Table/104/{1/900-2}@0,0]
    panic.go:615: -- test log scope end --
test logs left over in: outputs.zip/logTestRangeFeedMetricsManagement275544180
--- FAIL: TestRangeFeedMetricsManagement (229.77s)

Parameters:

• attempt=1
• race=true
• run=2
• shard=13

Help

See also: How To Investigate a Go Test Failure (internal)

/cc @cockroachdb/kv-triage

This test on roachdash | Improve this report!

Jira issue: CRDB-56298

[pav-kv]

Dup of #156853 but note that the condition failed to evaluate within 3m45s now vs 45s before. The timeout bump in #156950 apparently hasn't helped.

CC @sumeerbhola @stevendanna

[cockroach-teamcity]

kv/kvclient/kvcoord.TestRangeFeedMetricsManagement failed on master @ ddeef368172658dddb47811fe0fcdcaf5abbe8ee:

=== RUN   TestRangeFeedMetricsManagement
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestRangeFeedMetricsManagement4018387917
    test_log_scope.go:82: use -show-logs to present logs inline
    test_server_shim.go:141: cluster virtualization disabled in global scope due to issue: #156327 (expected label: C-bug)
    test_server_shim.go:594: DRPC is enabled (override by TestingGlobalDRPCOption)
    dist_sender_rangefeed_test.go:561: condition failed to evaluate within 3m45s: from dist_sender_rangefeed_test.go:563: waiting for frontier advance: [/Table/104/1{-/300}@0,0] [/Table/104/1/{300-500}@1762607301.120037254,0] [/Table/104/1/{500-900}@1762607309.644035540,0] [/Table/104/{1/900-2}@0,0]
    panic.go:615: -- test log scope end --
test logs left over in: outputs.zip/logTestRangeFeedMetricsManagement4018387917
--- FAIL: TestRangeFeedMetricsManagement (230.44s)

Parameters:

• attempt=1
• race=true
• run=2
• shard=13

Help

See also: How To Investigate a Go Test Failure (internal)

This test on roachdash | Improve this report!

[cockroach-teamcity]

kv/kvclient/kvcoord.TestRangeFeedMetricsManagement failed on master @ ae0b3d742f343186aa770c4ba8c3bf748bbc78f9:

=== RUN   TestRangeFeedMetricsManagement
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestRangeFeedMetricsManagement3602567629
    test_log_scope.go:82: use -show-logs to present logs inline
    test_server_shim.go:141: cluster virtualization disabled in global scope due to issue: #156327 (expected label: C-bug)
    dist_sender_rangefeed_test.go:561: condition failed to evaluate within 3m45s: from dist_sender_rangefeed_test.go:563: waiting for frontier advance: [/Table/104/1{-/300}@0,0] [/Table/104/1/{300-500}@1762772645.419282918,0] [/Table/104/1/{500-800}@1762772654.114110276,0] [/Table/104/{1/800-2}@0,0]
    panic.go:615: -- test log scope end --
test logs left over in: outputs.zip/logTestRangeFeedMetricsManagement3602567629
--- FAIL: TestRangeFeedMetricsManagement (230.28s)

Parameters:

• attempt=1
• race=true
• run=2
• shard=13

Help

See also: How To Investigate a Go Test Failure (internal)

This test on roachdash | Improve this report!

[stevendanna]

3m45s is a very long time. I'll try to stress this locally a bit. It feels unreasonable that even with reopening the iterator on every key this test takes that long.

[cockroach-teamcity]

kv/kvclient/kvcoord.TestRangeFeedMetricsManagement failed on master @ b07e9c2cc91be05a90b1c0f0665da0da4cde2e7a:

=== RUN   TestRangeFeedMetricsManagement
    test_log_scope.go:171: test logs captured to: outputs.zip/logTestRangeFeedMetricsManagement1173786090
    test_log_scope.go:82: use -show-logs to present logs inline
    test_server_shim.go:141: cluster virtualization disabled in global scope due to issue: #156327 (expected label: C-bug)
    dist_sender_rangefeed_test.go:561: condition failed to evaluate within 3m45s: from dist_sender_rangefeed_test.go:563: waiting for frontier advance: [/Table/104/1{-/300}@0,0] [/Table/104/1/{300-400}@1762945177.781488509,0] [/Table/104/1/{400-500}@1762945178.019284992,0] [/Table/104/{1/500-2}@1762945188.560921559,0]
    panic.go:615: -- test log scope end --
test logs left over in: outputs.zip/logTestRangeFeedMetricsManagement1173786090
--- FAIL: TestRangeFeedMetricsManagement (232.12s)

Parameters:

• attempt=1
• race=true
• run=2
• shard=13

Help

See also: How To Investigate a Go Test Failure (internal)

This test on roachdash | Improve this report!

[sumeerbhola]

If this failure and the other race timeouts are due to reopening every time, we could simply reduce the frequency using the iterator pointer. We have some code akin to the following in Pebble:

if RaceEnabled {
  var ptr uintptr
  ptr = ...
  // Fibonacci hash https://probablydance.com/2018/06/16/fibonacci-hashing-the-optimization-that-the-world-forgot-or-a-better-alternative-to-integer-modulo/
  simpleHash := (11400714819323198485 * uint64(ptr)) >> 63
  if simpleHash == 0 {
    // do slow thing
  }
}

[stevendanna]

@sumeerbhola Yeah, I'll do something like that. I just am hoping to be able to reproduce one locally so that I can make sure it is just the stream being slow and not something that has resulted in us being completely stuck.

That fibonacci hash is neat, thanks for sharing.