Skip to content

kvflowcontrol: observed raft log position less than per-stream lower bound  #106123

@irfansharif

Description

@irfansharif

Describe the problem

In #105955 we saw the following:

۩ cat logs/3.unredacted/cockroach.log | grep "observed raft log position less than per-stream lower bound" | head -n 10
E230701 07:05:49.168518 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4421  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=7/252461)
E230701 07:05:49.171144 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4434  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/23546)
E230701 07:05:49.171165 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4435  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/23546)
E230701 07:05:49.171178 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4436  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/23546)
E230701 07:05:49.171190 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4437  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/23546)
E230701 07:05:49.171201 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4438  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/23546)
E230701 07:05:49.171215 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4439  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/23546)
E230701 07:05:49.171363 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4440  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=7/20430)
E230701 07:05:49.171381 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4441  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=7/20430)
E230701 07:05:49.172008 265 kv/kvserver/kvflowcontrol/kvflowtokentracker/tracker.go:95 ⋮ [-] 4445  observed raft log position less than per-stream lower bound (log-position=0/0 <= log-position=6/33144)

Which is an indication of a kvflowcontrol integration bug:

if !(dt.lowerBound.Less(pos)) {
// We're trying to track a token deduction at a position less than the
// stream's lower-bound. Shout loudly but ultimately no-op. This
// regression indicates buggy usage since:
// - token deductions are done so with monotonically increasing log
// positions (see Handle.DeductTokensFor);
// - the monotonically increasing log positions for token deductions
// also extends to positions at which streams are connected,
// which typically happen when (a) members are added to the raft
// group, (b) previously crashed follower nodes restart, (c)
// replicas are unpaused, or (d) caught back up via snapshots (see
// Handle.ConnectStream).
// - token returns upto some log position don't precede deductions at
// lower log positions (see Handle.ReturnTokensUpto);
logFn := log.Errorf
if buildutil.CrdbTestBuild {
logFn = log.Fatalf
}
logFn(ctx, "observed raft log position less than per-stream lower bound (%s <= %s)",
pos, dt.lowerBound)
return false
}

Jira issue: CRDB-29414

Metadata

Metadata

Assignees

Labels

A-admission-controlC-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