Skip to content

kv/kvserver: TestReadLoadMetricAccounting failed #159719

Closed
#159877
Closed
kv/kvserver: TestReadLoadMetricAccounting failed#159719
#159877
Labels
A-testingTesting tools and infrastructureC-bugCode not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.C-test-failureBroken test (automatically or manually discovered).O-robotOriginated from a bot.T-kvKV Teambranch-masterFailures and bugs on the master branch.branch-release-25.4Used to mark GA and release blockers and technical advisories for 25.4branch-release-26.1Used to mark GA and release blockers, technical advisories, and bugs for 26.1target-release-26.2.0v25.4.6v26.1.1v26.2.0-prerelease
@cockroach-teamcity

Description

@cockroach-teamcity
cockroach-teamcity
opened on Dec 17, 2025

kv/kvserver.TestReadLoadMetricAccounting failed with artifacts on master @ 72825229532522f6377e706e009c1090eb1f9b23:

=== RUN   TestReadLoadMetricAccounting
    test_log_scope.go:171: test logs captured to: /artifacts/tmp/_tmp/645d36459c8d7b7939924714a555a08a/logTestReadLoadMetricAccounting564952480
    test_log_scope.go:82: use -show-logs to present logs inline
    test_server_shim.go:668: DRPC is enabled (via override by TestingGlobalDRPCOption)
    replica_rankings_test.go:441: evaluated [logtags=: *kvpb.AddSSTableRequest
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.111903730,0 TimestampFromServerClock:<nil> Now:1765988944.111903730,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.112240907,0 TimestampFromServerClock:<nil> Now:1765988944.112240907,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.112430629,0 TimestampFromServerClock:<nil> Now:1765988944.112430629,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.112690747,0 TimestampFromServerClock:<nil> Now:1765988944.112690747,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.112914099,0 TimestampFromServerClock:<nil> Now:1765988944.112914099,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.113094298,0 TimestampFromServerClock:<nil> Now:1765988944.113094298,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.113288467,0 TimestampFromServerClock:<nil> Now:1765988944.113288467,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.113495601,0 TimestampFromServerClock:<nil> Now:1765988944.113495601,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.113687234,0 TimestampFromServerClock:<nil> Now:1765988944.113687234,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.114027155,0 TimestampFromServerClock:<nil> Now:1765988944.114027155,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.114296156,0 TimestampFromServerClock:<nil> Now:1765988944.114296156,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.114502831,0 TimestampFromServerClock:<nil> Now:1765988944.114502831,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.114726024,0 TimestampFromServerClock:<nil> Now:1765988944.114726024,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.115037081,0 TimestampFromServerClock:<nil> Now:1765988944.115037081,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.115270173,0 TimestampFromServerClock:<nil> Now:1765988944.115270173,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.115472092,0 TimestampFromServerClock:<nil> Now:1765988944.115472092,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.116546926,0 TimestampFromServerClock:<nil> Now:1765988944.116546926,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.117067138,0 TimestampFromServerClock:<nil> Now:1765988944.117067138,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.117435923,0 TimestampFromServerClock:<nil> Now:1765988944.117435923,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.117959005,0 TimestampFromServerClock:<nil> Now:1765988944.117959005,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.119327656,0 TimestampFromServerClock:<nil> Now:1765988944.119327656,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.122235484,0 TimestampFromServerClock:<nil> Now:1765988944.122235484,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.128790152,0 TimestampFromServerClock:<nil> Now:1765988944.128790152,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.134400195,0 TimestampFromServerClock:<nil> Now:1765988944.134400195,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.143588503,0 TimestampFromServerClock:<nil> Now:1765988944.143588503,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.161041719,0 TimestampFromServerClock:<nil> Now:1765988944.161041719,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.195096870,0 TimestampFromServerClock:<nil> Now:1765988944.195096870,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.RequestLeaseRequest on /Table/Max: header:<key:"\372" > lease:<start:<> replica:<node_id:1 store_id:1 replica_id:1 type:VOTER_FULL > proposed_ts:<wall_time:1765988944261918514 > sequence:1 acquisition_type:Request min_expiration:<wall_time:1765988950077331053 > term:6 > prev_lease:<start:<> expiration:<wall_time:1765988950077331053 > replica:<node_id:1 store_id:1 replica_id:1 type:VOTER_FULL > deprecated_start_stasis:<wall_time:1765988950077331053 > proposed_ts:<wall_time:1765988944077331053 > sequence:1 acquisition_type:Request min_expiration:<> >  {Timestamp:1765988944.262002629,0 TimestampFromServerClock:<nil> Now:0,0 Replica:(n0,s0):? RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:CONSISTENT RoutingPolicy:LEASEHOLDER WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:0 ClientRangeInfo:{DescriptorGeneration:0 LeaseSequence:0 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.LeaseInfoRequest on /Table/Max: header:<key:"\372" >  {Timestamp:1765988944.262738726,0 TimestampFromServerClock:<nil> Now:1765988944.262738726,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:INCONSISTENT RoutingPolicy:NEAREST WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    testcluster.go:1243: lease is now of type: LeaseLeader
    replica_rankings_test.go:536: test #1
    replica_rankings_test.go:444: evaluated [logtags=]: *kvpb.GetRequest on �000000000: header:<key:"\372000000000" > expect_exclusion_since:<>  {Timestamp:1765988944.263133468,0 TimestampFromServerClock:1765988944.263133468,0 Now:1765988944.263106429,0 Replica:(n1,s1):1 RangeID:81 UserPriority:normal Txn:<nil> ReadConsistency:CONSISTENT RoutingPolicy:LEASEHOLDER WaitPolicy:Block LockTimeout:0s MaxSpanRequestKeys:0 TargetBytes:0 WholeRowsOfSize:0 AllowEmpty:false DistinctSpans:false AsyncConsensus:false CanForwardReadTimestamp:false GatewayNodeID:1 ClientRangeInfo:{DescriptorGeneration:1 LeaseSequence:1 ClosedTimestampPolicy:LAG_BY_CLUSTER_SETTING ExplicitlyRequested:false} BoundedStaleness:<nil> TraceInfo:<nil> IndexFetchSpec:<nil> ReturnElasticCPUResumeSpans:false ProfileLabels:[] AmbiguousReplayProtection:false ConnectionClass:default ProxyRangeInfo:<nil> WriteOptions:<nil> DeadlockTimeout:0s HasBufferedAllPrecedingWrites:false IsReverse:false}
    replica_rankings_test.go:209: 
        	Error Trace:	pkg/kv/kvserver/replica_rankings_test.go:209
        	            				pkg/kv/kvserver/replica_rankings_test.go:564
        	Error:      	Max difference between 0 and 85 allowed is 4, but difference was -85
        	Test:       	TestReadLoadMetricAccounting
    panic.go:615: -- test log scope end --
test logs left over in: /artifacts/tmp/_tmp/645d36459c8d7b7939924714a555a08a/logTestReadLoadMetricAccounting564952480
--- FAIL: TestReadLoadMetricAccounting (0.71s)
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-58004

Metadata

Metadata

Assignees

No one assigned

    Labels

    A-testingTesting tools and infrastructureC-bugCode not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.C-test-failureBroken test (automatically or manually discovered).O-robotOriginated from a bot.T-kvKV Teambranch-masterFailures and bugs on the master branch.branch-release-25.4Used to mark GA and release blockers and technical advisories for 25.4branch-release-26.1Used to mark GA and release blockers, technical advisories, and bugs for 26.1target-release-26.2.0v25.4.6v26.1.1v26.2.0-prerelease

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions