Skip to content

kvserver: lease expiration warnings are either wrong or overly eager #97209

@erikgrinaker

Description

@erikgrinaker

Over in #97141, we're seeing lots of messages like these about a minute apart, for a bunch of different ranges:

W230215 15:05:25.397825 438 kv/kvserver/replica_proposal.go:504 ⋮ [T1,n1,s1,r208/1:‹/Table/114/1/7{16/1/…-28/3/…}›,raft] 1186  lease repl=(n1,s1):1 seq=8 start=1676473525.388300956,0 exp=1676473531.388236519,0 pro=1676473525.388236519,0 expired before being followed by lease repl=(n1,s1):1 seq=9 start=1676473525.388300956,0 epo=1 pro=1676473525.389899605,0; foreground traffic may have been impacted
W230215 15:05:25.399483 389 kv/kvserver/replica_proposal.go:504 ⋮ [T1,n1,s1,r202/1:‹/Table/114/1/7{04/2/…-16/1/…}›,raft] 1187  lease repl=(n1,s1):1 seq=8 start=1676473525.392789979,0 exp=1676473531.392713495,0 pro=1676473525.392713495,0 expired before being followed by lease repl=(n1,s1):1 seq=9 start=1676473525.392789979,0 epo=1 pro=1676473525.395106219,0; foreground traffic may have been impacted
W230215 15:05:25.401462 393 kv/kvserver/replica_proposal.go:504 ⋮ [T1,n1,s1,r316/1:‹/Table/114/1/8{35/10…-47/9/…}›,raft] 1188  lease repl=(n1,s1):1 seq=8 start=1676473525.394871000,0 exp=1676473531.394811451,0 pro=1676473525.394811451,0 expired before being followed by lease repl=(n1,s1):1 seq=9 start=1676473525.394871000,0 epo=1 pro=1676473525.397471476,0; foreground traffic may have been impacted
W230215 15:05:25.402589 465 kv/kvserver/replica_proposal.go:504 ⋮ [T1,n1,s1,r295/1:‹/Table/114/1/{41/3/-…-53/7/-…}›,raft] 1189  lease repl=(n1,s1):1 seq=8 start=1676473525.397320365,0 exp=1676473531.397258820,0 pro=1676473525.397258820,0 expired before being followed by lease repl=(n1,s1):1 seq=9 start=1676473525.397320365,0 epo=1 pro=1676473525.398718792,0; foreground traffic may have been impacted
W230215 15:05:25.403898 394 kv/kvserver/replica_proposal.go:504 ⋮ [T1,n1,s1,r157/1:‹/Table/114/1/{28/8/-…-41/3/-…}›,raft] 1190  lease repl=(n1,s1):1 seq=8 start=1676473525.398777759,0 exp=1676473531.398716723,0 pro=1676473525.398716723,0 expired before being followed by lease repl=(n1,s1):1 seq=9 start=1676473525.398777759,0 epo=1 pro=1676473525.400299666,0; foreground traffic may have been impacted
W230215 15:05:25.405819 414 kv/kvserver/replica_proposal.go:504 ⋮ [T1,n1,s1,r311/1:‹/Table/114/1/4{74/4/…-86/3/…}›,raft] 1191  lease repl=(n1,s1):1 seq=12 start=1676473525.400304925,0 exp=1676473531.400169005,0 pro=1676473525.400169005,0 expired before being followed by lease repl=(n1,s1):1 seq=13 start=1676473525.400304925,0 epo=1 pro=1676473525.402156568,0; foreground traffic may have been impacted

Notice how the lease was in fact taken over by the same leaseholder. I think something's off with the condition for that log message. It was added back in #96257. We should get this fixed asap, since it was backported to 22.2 and 22.1.

Entire log: cockroach.log

Jira issue: CRDB-24572

Metadata

Metadata

Assignees

Labels

A-kv-replicationRelating to Raft, consensus, and coordination.C-bugCode not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions