From 2ea582b5c340d68ebd3e1f2b9fc2affc0eae54b4 Mon Sep 17 00:00:00 2001 From: Nathan VanBenschoten Date: Tue, 31 May 2022 16:02:00 +0000 Subject: [PATCH] kv: add debug information to track down #77663 I've given #77663 a few looks and have yet to understand how it is possible to hit that assertion. To continue making progress, this commit adds additional debug information to the assertion so that we'll be able to understand this better if it happens again. --- .../concurrency/concurrency_manager.go | 23 ++++++++++++++++--- 1 file changed, 20 insertions(+), 3 deletions(-) diff --git a/pkg/kv/kvserver/concurrency/concurrency_manager.go b/pkg/kv/kvserver/concurrency/concurrency_manager.go index deec67b4a3af..6682a3f16648 100644 --- a/pkg/kv/kvserver/concurrency/concurrency_manager.go +++ b/pkg/kv/kvserver/concurrency/concurrency_manager.go @@ -12,6 +12,8 @@ package concurrency import ( "context" + "fmt" + "runtime/debug" "sync" "github.com/cockroachdb/cockroach/pkg/kv" @@ -29,6 +31,7 @@ import ( "github.com/cockroachdb/cockroach/pkg/util/stop" "github.com/cockroachdb/cockroach/pkg/util/uuid" "github.com/cockroachdb/errors" + "github.com/cockroachdb/redact" ) // MaxLockWaitQueueLength sets the maximum length of a lock wait-queue that a @@ -181,33 +184,42 @@ func (m *managerImpl) SequenceReq( ctx context.Context, prev *Guard, req Request, evalKind RequestEvalKind, ) (*Guard, Response, *Error) { var g *Guard + var branch int if prev == nil { switch evalKind { case PessimisticEval: + branch = 1 log.Event(ctx, "sequencing request") case OptimisticEval: + branch = 2 log.Event(ctx, "optimistically sequencing request") case PessimisticAfterFailedOptimisticEval: panic("retry should have non-nil guard") + default: + panic("unexpected evalKind") } g = newGuard(req) } else { g = prev switch evalKind { case PessimisticEval: + branch = 3 g.AssertNoLatches() log.Event(ctx, "re-sequencing request") case OptimisticEval: panic("optimistic eval cannot happen when re-sequencing") case PessimisticAfterFailedOptimisticEval: + branch = 4 if !shouldIgnoreLatches(g.Req) { g.AssertLatches() } log.Event(ctx, "re-sequencing request after optimistic sequencing failed") + default: + panic("unexpected evalKind") } } g.EvalKind = evalKind - resp, err := m.sequenceReqWithGuard(ctx, g) + resp, err := m.sequenceReqWithGuard(ctx, g, branch) if resp != nil || err != nil { // Ensure that we release the guard if we return a response or an error. m.FinishReq(g) @@ -216,7 +228,9 @@ func (m *managerImpl) SequenceReq( return g, nil, nil } -func (m *managerImpl) sequenceReqWithGuard(ctx context.Context, g *Guard) (Response, *Error) { +func (m *managerImpl) sequenceReqWithGuard( + ctx context.Context, g *Guard, branch int, +) (Response, *Error) { // Some requests don't need to acquire latches at all. if shouldIgnoreLatches(g.Req) { log.Event(ctx, "not acquiring latches") @@ -268,7 +282,10 @@ func (m *managerImpl) sequenceReqWithGuard(ctx context.Context, g *Guard) (Respo panic(errors.AssertionFailedf("second or later iteration cannot be holding latches")) } if g.EvalKind != PessimisticAfterFailedOptimisticEval { - panic("must not be holding latches") + panic(redact.Safe(fmt.Sprintf("must not be holding latches\n"+ + "this is tracked in github.com/cockroachdb/cockroach/issues/77663; please comment if seen\n"+ + "eval_kind=%d, holding_latches=%t, branch=%d, first_iteration=%t, stack=\n%s", + g.EvalKind, g.HoldingLatches(), branch, firstIteration, string(debug.Stack())))) } log.Event(ctx, "optimistic failed, so waiting for latches") g.lg, err = m.lm.WaitUntilAcquired(ctx, g.lg)