From 641c494cb7a5e4ca1fe7bc7206018e7bfec2c83f Mon Sep 17 00:00:00 2001 From: Tobias Grieger Date: Thu, 20 Jan 2022 22:38:51 +0100 Subject: [PATCH] kvserver: use EncodedError in SnapshotResponse We were previously using a "Message" string to indicate details about an error. We can do so much better now and actually encode the error. This wasn't possible when this field was first added, but it is now, so let's use it. As always, there's a migration concern, which means the old field stays around & is populated as well as interpreted for one release. We then use this new-found freedom to improve which errors were marked as "failed snapshot" errors. Previously, any error coming in on a `SnapshotResponse` were considered snapshot errors and were considered retriable. This was causing `TestLearnerSnapshotFailsRollback` to run for 90s, as `TestCluster`'s replication changes use a [SucceedsSoon] to retry snapshot errors - but that test actually injects an error that it wants to fail-fast. Now, since snapshot error marks propagate over the wire, we can do the marking on the *sender* of the SnapshotResponse, and we can only mark messages that correspond to an actual failure to apply the snapshot (as opposed to an injected error, or a hard error due to a malformed request). The test now takes around one second, for a rare 90x speed-up. As a drive-by, we're also removing `errMalformedSnapshot`, which became unused when we stopped sending the raft log in raft snaps a few releases back, and which had managed to hide from the `unused` lint. [SucceedsSoon]: https://github.com/cockroachdb/cockroach/blob/37175f77bf374d1bcb76bc39a65149788be06134/pkg/testutils/testcluster/testcluster.go#L628-L631 Fixes #74621. Release note: None --- pkg/kv/kvserver/kvserverpb/BUILD.bazel | 2 ++ pkg/kv/kvserver/kvserverpb/raft.proto | 11 ++++++ pkg/kv/kvserver/markers.go | 4 +++ pkg/kv/kvserver/raft_transport.go | 7 ++-- pkg/kv/kvserver/replica_command.go | 16 +-------- pkg/kv/kvserver/replica_learner_test.go | 8 ++--- pkg/kv/kvserver/store_snapshot.go | 47 +++++++++++++++++-------- 7 files changed, 60 insertions(+), 35 deletions(-) diff --git a/pkg/kv/kvserver/kvserverpb/BUILD.bazel b/pkg/kv/kvserver/kvserverpb/BUILD.bazel index 51fb08fa05ef..53ef21d6cef7 100644 --- a/pkg/kv/kvserver/kvserverpb/BUILD.bazel +++ b/pkg/kv/kvserver/kvserverpb/BUILD.bazel @@ -36,6 +36,7 @@ proto_library( "//pkg/roachpb:roachpb_proto", "//pkg/storage/enginepb:enginepb_proto", "//pkg/util/hlc:hlc_proto", + "@com_github_cockroachdb_errors//errorspb:errorspb_proto", "@com_github_gogo_protobuf//gogoproto:gogo_proto", "@com_google_protobuf//:timestamp_proto", "@io_etcd_go_etcd_raft_v3//raftpb:raftpb_proto", @@ -56,6 +57,7 @@ go_proto_library( "//pkg/storage/enginepb", "//pkg/util/hlc", "//pkg/util/uuid", # keep + "@com_github_cockroachdb_errors//errorspb", "@com_github_gogo_protobuf//gogoproto", "@io_etcd_go_etcd_raft_v3//raftpb", ], diff --git a/pkg/kv/kvserver/kvserverpb/raft.proto b/pkg/kv/kvserver/kvserverpb/raft.proto index 2fa84622e03f..ee8394f59434 100644 --- a/pkg/kv/kvserver/kvserverpb/raft.proto +++ b/pkg/kv/kvserver/kvserverpb/raft.proto @@ -12,6 +12,7 @@ syntax = "proto3"; package cockroach.kv.kvserver.kvserverpb; option go_package = "kvserverpb"; +import "errorspb/errors.proto"; import "roachpb/errors.proto"; import "roachpb/metadata.proto"; import "kv/kvserver/liveness/livenesspb/liveness.proto"; @@ -210,8 +211,18 @@ message SnapshotResponse { reserved 4; } Status status = 1; + // Message is a message explaining an ERROR return value. It is not set for any + // other status. + // + // DEPRECATED: this field can be removed in 23.1. As of 22.2, the encoded_error + // field is always used instead. (22.2 itself needs to populate both due to + // needing to be wire-compatible with 22.1). string message = 2; reserved 3; + // encoded_error encodes the error when the status is ERROR. + // + // MIGRATION: only guaranteed to be set when the message field is no longer there. + errorspb.EncodedError encoded_error = 4 [(gogoproto.nullable) = false]; } // ConfChangeContext is encoded in the raftpb.ConfChange.Context field. diff --git a/pkg/kv/kvserver/markers.go b/pkg/kv/kvserver/markers.go index 29b7269e4469..9bef525358a4 100644 --- a/pkg/kv/kvserver/markers.go +++ b/pkg/kv/kvserver/markers.go @@ -15,6 +15,10 @@ import ( "github.com/cockroachdb/errors" ) +// errMarkSnapshotError is used as an error mark for errors that get returned +// to the initiator of a snapshot. This generally classifies errors as transient, +// i.e. communicates an intention for the caller to retry. +// // NB: don't change the string here; this will cause cross-version issues // since this singleton is used as a marker. var errMarkSnapshotError = errors.New("snapshot failed") diff --git a/pkg/kv/kvserver/raft_transport.go b/pkg/kv/kvserver/raft_transport.go index d0a5ab57a79a..0aeab54f9e5b 100644 --- a/pkg/kv/kvserver/raft_transport.go +++ b/pkg/kv/kvserver/raft_transport.go @@ -424,9 +424,12 @@ func (t *RaftTransport) RaftSnapshot(stream MultiRaft_RaftSnapshotServer) error return err } if req.Header == nil { + err := errors.New("client error: no header in first snapshot request message") return stream.Send(&kvserverpb.SnapshotResponse{ - Status: kvserverpb.SnapshotResponse_ERROR, - Message: "client error: no header in first snapshot request message"}) + Status: kvserverpb.SnapshotResponse_ERROR, + Message: err.Error(), + EncodedError: errors.EncodeError(ctx, err), + }) } rmr := req.Header.RaftMessageRequest handler, ok := t.getHandler(rmr.ToReplica.StoreID) diff --git a/pkg/kv/kvserver/replica_command.go b/pkg/kv/kvserver/replica_command.go index 5fdeb2c41816..07c96ff52ecd 100644 --- a/pkg/kv/kvserver/replica_command.go +++ b/pkg/kv/kvserver/replica_command.go @@ -2582,7 +2582,7 @@ func (r *Replica) sendSnapshot( sent := func() { r.store.metrics.RangeSnapshotsGenerated.Inc(1) } - err = contextutil.RunWithTimeout( + return contextutil.RunWithTimeout( ctx, "send-snapshot", sendSnapshotTimeout, func(ctx context.Context) error { return r.store.cfg.Transport.SendSnapshot( ctx, @@ -2594,20 +2594,6 @@ func (r *Replica) sendSnapshot( r.store.metrics.RangeSnapshotSentBytes, ) }) - if err != nil { - if errors.Is(err, errMalformedSnapshot) { - tag := fmt.Sprintf("r%d_%s", r.RangeID, snap.SnapUUID.Short()) - if dir, err := r.store.checkpoint(ctx, tag); err != nil { - log.Warningf(ctx, "unable to create checkpoint %s: %+v", dir, err) - } else { - log.Warningf(ctx, "created checkpoint %s", dir) - } - - log.Fatal(ctx, "malformed snapshot generated") - } - return errors.Mark(err, errMarkSnapshotError) - } - return nil } // replicasCollocated is used in AdminMerge to ensure that the ranges are diff --git a/pkg/kv/kvserver/replica_learner_test.go b/pkg/kv/kvserver/replica_learner_test.go index 3edeb38dae50..29a352e2e702 100644 --- a/pkg/kv/kvserver/replica_learner_test.go +++ b/pkg/kv/kvserver/replica_learner_test.go @@ -316,11 +316,11 @@ func TestLearnerSnapshotFailsRollback(t *testing.T) { skip.UnderRace(t) runTest := func(t *testing.T, replicaType roachpb.ReplicaType) { - var rejectSnapshots int64 + var rejectSnapshotErr atomic.Value // error knobs, ltk := makeReplicationTestKnobs() ltk.storeKnobs.ReceiveSnapshot = func(h *kvserverpb.SnapshotRequest_Header) error { - if atomic.LoadInt64(&rejectSnapshots) > 0 { - return errors.New(`nope`) + if err := rejectSnapshotErr.Load().(error); err != nil { + return err } return nil } @@ -332,7 +332,7 @@ func TestLearnerSnapshotFailsRollback(t *testing.T) { defer tc.Stopper().Stop(ctx) scratchStartKey := tc.ScratchRange(t) - atomic.StoreInt64(&rejectSnapshots, 1) + rejectSnapshotErr.Store(errors.New("boom")) var err error switch replicaType { case roachpb.LEARNER: diff --git a/pkg/kv/kvserver/store_snapshot.go b/pkg/kv/kvserver/store_snapshot.go index 1d7fba36525e..b66d8c2751f9 100644 --- a/pkg/kv/kvserver/store_snapshot.go +++ b/pkg/kv/kvserver/store_snapshot.go @@ -330,10 +330,6 @@ func (kvSS *kvBatchSnapshotStrategy) Receive( } } -// errMalformedSnapshot indicates that the snapshot in question is malformed, -// for e.g. missing raft log entries. -var errMalformedSnapshot = errors.New("malformed snapshot generated") - // Send implements the snapshotStrategy interface. func (kvSS *kvBatchSnapshotStrategy) Send( ctx context.Context, @@ -563,7 +559,10 @@ func (s *Store) checkSnapshotOverlapLocked( // NB: this check seems redundant since placeholders are also represented in // replicasByKey (and thus returned in getOverlappingKeyRangeLocked). if exRng, ok := s.mu.replicaPlaceholders[desc.RangeID]; ok { - return errors.Errorf("%s: canAcceptSnapshotLocked: cannot add placeholder, have an existing placeholder %s %v", s, exRng, snapHeader.RaftMessageRequest.FromReplica) + return errors.Mark(errors.Errorf( + "%s: canAcceptSnapshotLocked: cannot add placeholder, have an existing placeholder %s %v", + s, exRng, snapHeader.RaftMessageRequest.FromReplica), + errMarkSnapshotError) } // TODO(benesch): consider discovering and GC'ing *all* overlapping ranges, @@ -608,7 +607,10 @@ func (s *Store) checkSnapshotOverlapLocked( msg += "; initiated GC:" s.replicaGCQueue.AddAsync(ctx, exReplica, gcPriority) } - return errors.Errorf("%s %v (incoming %v)", msg, exReplica, snapHeader.State.Desc.RSpan()) // exReplica can be nil + return errors.Mark( + errors.Errorf("%s %v (incoming %v)", msg, exReplica, snapHeader.State.Desc.RSpan()), // exReplica can be nil + errMarkSnapshotError, + ) } return nil } @@ -640,6 +642,8 @@ func (s *Store) receiveSnapshot( if fn := s.cfg.TestingKnobs.ReceiveSnapshot; fn != nil { if err := fn(header); err != nil { + // NB: we intentionally don't mark this error as errMarkSnapshotError so + // that we don't end up retrying injected errors in tests. return sendSnapshotError(stream, err) } } @@ -680,7 +684,7 @@ func (s *Store) receiveSnapshot( return nil }); pErr != nil { log.Infof(ctx, "cannot accept snapshot: %s", pErr) - return pErr.GoError() + return sendSnapshotError(stream, pErr.GoError()) } defer func() { @@ -736,16 +740,22 @@ func (s *Store) receiveSnapshot( // already received the entire snapshot here, so there's no point in // abandoning application half-way through if the caller goes away. applyCtx := s.AnnotateCtx(context.Background()) - if err := s.processRaftSnapshotRequest(applyCtx, header, inSnap); err != nil { - return sendSnapshotError(stream, errors.Wrap(err.GoError(), "failed to apply snapshot")) + if pErr := s.processRaftSnapshotRequest(applyCtx, header, inSnap); pErr != nil { + err := pErr.GoError() + // We mark this error as a snapshot error which will be interpreted by the + // sender as this being a retriable error, see isSnapshotError(). + err = errors.Mark(err, errMarkSnapshotError) + err = errors.Wrap(err, "failed to apply snapshot") + return sendSnapshotError(stream, err) } return stream.Send(&kvserverpb.SnapshotResponse{Status: kvserverpb.SnapshotResponse_APPLIED}) } func sendSnapshotError(stream incomingSnapshotStream, err error) error { return stream.Send(&kvserverpb.SnapshotResponse{ - Status: kvserverpb.SnapshotResponse_ERROR, - Message: err.Error(), + Status: kvserverpb.SnapshotResponse_ERROR, + Message: err.Error(), + EncodedError: errors.EncodeError(context.Background(), err), }) } @@ -1135,9 +1145,18 @@ func sendSnapshot( } switch resp.Status { case kvserverpb.SnapshotResponse_ERROR: - storePool.throttle(throttleFailed, resp.Message, to.StoreID) - return errors.Errorf("%s: remote couldn't accept %s with error: %s", - to, snap, resp.Message) + var err error + if resp.EncodedError.Error != nil { + // NB: errMarkSnapshotError must be set on the other end, if it is + // set. We're not going to add it here. + err = errors.DecodeError(ctx, resp.EncodedError) + } else { + // Deprecated path. + err = errors.Errorf("%s", resp.Message) + err = errors.Mark(err, errMarkSnapshotError) + } + storePool.throttle(throttleFailed, err.Error(), to.StoreID) + return errors.Wrapf(err, "%s: remote couldn't accept %s", to, snap) case kvserverpb.SnapshotResponse_ACCEPTED: // This is the response we're expecting. Continue with snapshot sending. default: