Skip to content

kv/kvserver: TestReplicaRangefeedNudgeSlowClosedTimestamp failed #55420

@cockroach-teamcity

Description

@cockroach-teamcity

(kv/kvserver).TestReplicaRangefeedNudgeSlowClosedTimestamp failed on master@e824da5a2b33168fa4ef93c83295c8205acfadb7:

I201011 06:01:33.867300 503933 gossip/client.go:129  [n2] closing client to n1 (127.0.0.1:36429): stopping outgoing client to n1 (127.0.0.1:36429); already have incoming
E201011 06:01:33.970599 503629 kv/kvserver/consistency_queue.go:178  [n2,consistencyChecker,s2,r1/2:/{Min-System/NodeL…}] computing own checksum: could not dial node ID 2: failed to connect to n2 at 127.0.0.1:40657: initial connection heartbeat failed: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: context deadline exceeded"
E201011 06:01:33.971916 503629 kv/kvserver/queue.go:1087  [n2,consistencyChecker,s2,r1/2:/{Min-System/NodeL…}] computing own checksum: could not dial node ID 2: failed to connect to n2 at 127.0.0.1:40657: initial connection heartbeat failed: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: context deadline exceeded"
I201011 06:01:33.980949 498039 kv/kvserver/node_liveness.go:1161  [n3,liveness-hb] retrying liveness update after kvserver.errRetryLiveness: result is ambiguous (context done during DistSender.Send: context deadline exceeded)
I201011 06:01:33.981017 497666 kv/kvserver/node_liveness.go:1161  [n2,liveness-hb] retrying liveness update after kvserver.errRetryLiveness: result is ambiguous (context done during DistSender.Send: context deadline exceeded)
I201011 06:01:34.000896 497812 gossip/gossip.go:1508  [n3] node has connected to cluster via gossip
W201011 06:01:34.011516 497666 kv/kvserver/node_liveness.go:787  [n2,liveness-hb] slow heartbeat took 4.651840858s; err=context deadline exceeded
W201011 06:01:34.026371 498039 kv/kvserver/node_liveness.go:787  [n3,liveness-hb] slow heartbeat took 4.659139688s; err=context deadline exceeded
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestReplicaRangefeedNudgeSlowClosedTimestamp367314799
W201011 06:01:34.028851 498039 kv/kvserver/node_liveness.go:689  [n3,liveness-hb] failed node liveness heartbeat: operation "node liveness heartbeat" timed out after 4.5s
(1) operation "node liveness heartbeat" timed out after 4.5s
Wraps: (2) context deadline exceeded
Error types: (1) *contextutil.TimeoutError (2) context.deadlineExceededError

An inability to maintain liveness will prevent a node from participating in a
cluster. If this problem persists, it may be a sign of resource starvation or
of network connectivity problems. For help troubleshooting, visit:

    https://www.cockroachlabs.com/docs/stable/cluster-setup-troubleshooting.html#node-liveness-issues

W201011 06:01:34.619691 496528 kv/kvserver/store_raft.go:492  [n1,s1,r7/1:/Table/1{1-2}] handle raft ready: 0.6s [applied=0, batches=0, state_assertions=0]
W201011 06:01:34.595074 496529 kv/kvserver/store_raft.go:492  [n1,s1,r6/1:/Table/{SystemCon…-11}] handle raft ready: 0.7s [applied=0, batches=0, state_assertions=0]
I201011 06:01:34.826169 496300 gossip/gossip.go:1508  [n1] node has connected to cluster via gossip
I201011 06:01:34.709144 497390 gossip/gossip.go:1508  [n2] node has connected to cluster via gossip
W201011 06:01:34.699310 497666 kv/kvserver/node_liveness.go:689  [n2,liveness-hb] failed node liveness heartbeat: operation "node liveness heartbeat" timed out after 4.5s
(1) operation "node liveness heartbeat" timed out after 4.5s
Wraps: (2) context deadline exceeded
Error types: (1) *contextutil.TimeoutError (2) context.deadlineExceededError

An inability to maintain liveness will prevent a node from participating in a
cluster. If this problem persists, it may be a sign of resource starvation or
of network connectivity problems. For help troubleshooting, visit:

    https://www.cockroachlabs.com/docs/stable/cluster-setup-troubleshooting.html#node-liveness-issues

W201011 06:01:34.855703 504435 gossip/client.go:118  [n3] failed to start gossip client to 127.0.0.1:40657: initial connection heartbeat failed: rpc error: code = Unavailable desc = connection error: desc = "transport: authentication handshake failed: context deadline exceeded"
W201011 06:01:34.961344 496476 kv/kvserver/store_raft.go:492  [n1,s1,r2/1:/System/NodeLiveness{-Max}] handle raft ready: 0.9s [applied=2, batches=2, state_assertions=0]
I201011 06:01:35.844318 497662 kv/kvserver/replica_rangefeed.go:610  [n2,s2,r6/2:/Table/{SystemCon…-11}] RangeFeed closed timestamp 1602396070.566420951,0 is behind by 25.265238248s
W201011 06:01:35.845365 503992 kv/kvserver/node_liveness.go:787  [n1,s1,r18/1:/Table/2{2-3}] slow heartbeat took 13.032487202s; err=<nil>
W201011 06:01:35.936564 503999 kv/kvserver/node_liveness.go:787  [n1,s1,r34/1:/Table/3{8-9}] slow heartbeat took 11.369921658s; err=<nil>
W201011 06:01:35.953262 504021 kv/kvserver/node_liveness.go:787  [n1,s1,r26/1:/NamespaceTable/{30-Max}] slow heartbeat took 10.487283786s; err=<nil>
W201011 06:01:35.865967 503936 kv/kvserver/node_liveness.go:787  [n1,s1,r35/1:/{Table/39-Max}] slow heartbeat took 12.139462738s; err=<nil>
W201011 06:01:35.973499 504062 kv/kvserver/node_liveness.go:787  [n1,s1,r6/1:/Table/{SystemCon…-11}] slow heartbeat took 8.948238459s; err=<nil>
W201011 06:01:35.990352 504024 kv/kvserver/node_liveness.go:787  [n1,s1,r31/1:/Table/3{5-6}] slow heartbeat took 8.910812481s; err=<nil>
--- FAIL: TestReplicaRangefeedNudgeSlowClosedTimestamp (445.52s)
    test_log_scope.go:154: test logs captured to: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestReplicaRangefeedNudgeSlowClosedTimestamp367314799
    test_log_scope.go:63: use -show-logs to present logs inline
    closed_timestamp_test.go:1156: pq: query execution canceled due to statement timeout
W201011 06:01:36.008017 503852 kv/kvserver/node_liveness.go:787  [n1,s1,r4/1:/System{/tsd-tse}] slow heartbeat took 8.429767536s; err=<nil>
W201011 06:01:36.123609 504178 kv/kvserver/node_liveness.go:787  [n1,s1,r3/1:/System/{NodeLive…-tsd}] slow heartbeat took 8.434037138s; err=<nil>

More

Parameters:

  • TAGS=
  • GOFLAGS=-race -parallel=2
make stressrace TESTS=TestReplicaRangefeedNudgeSlowClosedTimestamp PKG=./pkg/kv/kvserver TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
powered by pkg/cmd/internal/issues

Metadata

Metadata

Assignees

Labels

C-test-failureBroken test (automatically or manually discovered).O-robotOriginated from a bot.branch-masterFailures and bugs on the master branch.

Type

No type

Projects

No projects

Relationships

None yet

Development

No branches or pull requests

Issue actions