cockroachdb / cockroach

CockroachDB — the cloud native, distributed SQL database designed for high availability, effortless scale, and control over data placement.
https://www.cockroachlabs.com
Other
29.86k stars 3.77k forks source link

the server is terminating due to a fatal error #105164

Open wencan opened 1 year ago

wencan commented 1 year ago

OS: Fedora Linux 38 (Workstation Edition) x86_64 Kernel: 6.3.7-200.fc38.x86_64 Cockroach Version: v23.1.3.linux-amd64

supervisor conf:

[program:cockroach_node1]
command=/data/cockroach/current/cockroach start --certs-dir=certs --store=/data/cockroach/cockroach-data/node1 --listen-addr=localhost:26257 --sql-addr=localhost:36257 --http-addr=localhost:38081 --join=localhost:26257,localhost:26258,localhost:26259 --unencrypted-localhost-http
directory=/data/cockroach
autostart=true

[program:cockroach_node2]
command=/data/cockroach/current/cockroach start --certs-dir=certs --store=/data/cockroach/cockroach-data/node2 --listen-addr=localhost:26258 --sql-addr=localhost:36258 --http-addr=localhost:38082 --join=localhost:26257,localhost:26258,localhost:26259 --unencrypted-localhost-http
directory=/data/cockroach
autostart=true

command=/data/cockroach/current/cockroach start --certs-dir=certs --store=/data/cockroach/cockroach-data/node3 --listen-addr=localhost:26259 --sql-addr=localhost:36259 --http-addr=localhost:38083 --join=localhost:26257,localhost:26258,localhost:26259 --unencrypted-localhost-http
directory=/data/cockroach
autostart=true

log:

I230620 04:00:00.625520 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r31/1:‹/{Table/29-NamespaceTab…}›,raft] 1567  slow non-blocking raft commit: commit-wait 766.62258ms sem 379ns
I230620 04:00:01.600379 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r57/1:‹/Table/5{6-7}›,raft] 1568  slow non-blocking raft commit: commit-wait 511.349809ms sem 241ns
I230620 04:00:06.000239 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 1569  slow non-blocking raft commit: commit-wait 1.026425686s sem 326ns
W230620 04:00:06.217018 655 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n1,liveness-hb] 1570  slow heartbeat took 1.243741185s; err=<nil>
I230620 04:00:09.623788 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r94/1:‹/System{/tsd/cr.n…-tse}›,raft] 1571  slow non-blocking raft commit: commit-wait 1.985339693s sem 396ns
I230620 04:00:09.623971 535 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r4/1:‹/System/tsd{-/cr.nod…}›,raft] 1572  raft ready handling: 1.55s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.55s, other=0.00s], wrote 138 KiB sync(non-blocking) [append-ent=138 KiB (1), ]; node might be overloaded
I230620 04:00:09.623986 557 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r95/1:‹/System/tsd/cr.node.{re…-sq…}›,raft] 1573  raft ready handling: 1.42s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.42s, other=0.00s], wrote 136 B sync(non-blocking) [append-ent=76 B (1), ]; node might be overloaded
I230620 04:00:09.624047 542 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r94/1:‹/System{/tsd/cr.n…-tse}›,raft] 1574  raft ready handling: 1.42s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.42s, other=0.00s], wrote 140 B sync(non-blocking) [append-ent=79 B (1), ]; node might be overloaded
I230620 04:00:09.624144 498 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 1575  raft ready handling: 1.20s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.20s, other=0.00s], wrote 51 B sync(non-blocking) []; node might be overloaded
I230620 04:00:09.624202 473 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r37/1:‹/Table/3{5-6}›,raft] 1576  raft ready handling: 1.06s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.06s, other=0.00s], wrote 507 B sync(non-blocking) [append-ent=398 B (2), ]; node might be overloaded
I230620 04:00:09.624296 511 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 1577  raft ready handling: 1.39s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.39s, other=0.00s], wrote 187 B sync(non-blocking) [append-ent=124 B (1), ]; node might be overloaded
I230620 04:00:09.624400 560 kv/kvserver/store_raft.go:656 ⋮ [T1,n1,s1,r53/1:‹/Table/5{2-3}›,raft] 1578  raft ready handling: 1.39s [append=0.00s, apply=0.00s, commit-batch=1.39s, other=0.00s], wrote 50 B [apply=357 B (1)] pebble stats: [commit-wait 71ns sem 571ns]; node might be overloaded
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579  
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +__level_____count____size___score______in__ingest(sz_cnt)____move(sz_cnt)___write(sz_cnt)____read___r-amp___w-amp__val-bl
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +    WAL         1    49 M       -   3.2 G       -       -       -       -   3.2 G       -       -       -     1.0
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      0         0     0 B    0.00   3.2 G     0 B       0     0 B       0   222 M     158     0 B       0     0.1     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      1         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      2         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      3         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      4         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      5        14    36 M    0.71   222 M     0 B       0   215 K       1   1.7 G     534   1.7 G       1     8.0    17 K
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +      6        52   330 M       -   212 M     0 B       0    15 K       1   433 M      69   463 M       1     2.0   940 K
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +  total        66   366 M       -   3.2 G     0 B       0   230 K       2   5.6 G     761   2.2 G       2     1.7   958 K
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +  flush        61                             0 B       0       0  (ingest = tables-ingested, move = ingested-as-flushable)
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +compact       183     0 B     0 B       0                          (size == estimated-debt, score = in-progress-bytes, in = num-in-progress)
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +  ctype       181       0       0       2       0       0       0  (default, delete, elision, move, read, rewrite, multi-level)
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 + memtbl         1    64 M
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +zmemtbl         0     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +   ztbl         0     0 B
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 + bcache     3.5 K    49 M   88.2%  (score == hit-rate)
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 + tcache        57    40 K  100.0%  (score == hit-rate)
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 +  snaps         0       -       0  (score == earliest seq num)
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 + titers         0
I230620 04:00:09.974366 643 kv/kvserver/store.go:3299 ⋮ [T1,n1] 1579 + filter         -       -   98.5%  (score == utility)
I230620 04:00:12.599096 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r4/1:‹/System/tsd{-/cr.nod…}›,raft] 1580  slow non-blocking raft commit: commit-wait 2.756649604s wal-q 1.551084007s sem 363ns
I230620 04:00:12.599136 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r95/1:‹/System/tsd/cr.node.{re…-sq…}›,raft] 1581  slow non-blocking raft commit: commit-wait 174ns sem 1.134µs
I230620 04:00:12.599146 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r94/1:‹/System{/tsd/cr.n…-tse}›,raft] 1582  slow non-blocking raft commit: commit-wait 188ns sem 345ns
I230620 04:00:12.599214 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r1/1:‹/{Min-System/NodeL…}›,raft] 1583  slow non-blocking raft commit: commit-wait 130ns sem 444ns
I230620 04:00:12.599246 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r37/1:‹/Table/3{5-6}›,raft] 1584  slow non-blocking raft commit: commit-wait 106ns sem 383ns
I230620 04:00:12.599261 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 1585  slow non-blocking raft commit: commit-wait 151.326µs sem 240ns
W230620 04:00:12.653886 655 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n1,liveness-hb] 1586  slow heartbeat took 4.680613173s; err=<nil>
W230620 04:00:12.987598 346979 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n1,s1,r66/1:‹/Table/110{-/1/8754…}›] 1587  slow heartbeat took 3.282238401s; err=<nil>
W230620 04:00:18.313636 655 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n1,liveness-hb] 1588  slow heartbeat took 1.339651294s; err=<nil>
W230620 04:00:25.973696 655 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n1,liveness-hb] 1589  slow heartbeat took 3.000252694s; err=disk write failed while updating node liveness: interrupted during singleflight ‹engine sync:0›: context deadline exceeded
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590  failed node liveness heartbeat: operation ‹"node liveness heartbeat"› timed out after 3s (given timeout 3s): disk write failed while updating node liveness: interrupted during singleflight ‹engine sync:0›: context deadline exceeded
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590 +
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590 +An inability to maintain liveness will prevent a node from participating in a
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590 +cluster. If this problem persists, it may be a sign of resource starvation or
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590 +of network connectivity problems. For help troubleshooting, visit:
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590 +
W230620 04:00:25.973745 655 kv/kvserver/liveness/liveness.go:810 ⋮ [T1,n1,liveness-hb] 1590 +    https://www.cockroachlabs.com/docs/stable/cluster-setup-troubleshooting.html#node-liveness-issues
W230620 04:00:26.827176 833 server/node.go:1075 ⋮ [T1,n1,summaries] 1591  health alerts detected: {Alerts:[{StoreID:0 Category:‹METRICS› Description:‹liveness.heartbeatfailures› Value:1}]}
I230620 04:00:27.040338 568 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n1,s1,r2/1:‹/System/NodeLiveness{-Max}›,raft] 1592  slow non-blocking raft commit: commit-wait 4.149644868s sem 167ns
I230620 04:00:35.774789 570 kv/kvserver/store_gossip.go:134 ⋮ [T1,n1,s1,r1/1:‹/{Min-System/NodeL…}›] 1593  could not gossip first range descriptor: [NotLeaseHolderError] ‹lease acquisition canceled because context canceled›; r1: replica (n1,s1):1 not lease holder; lease holder unknown
W230620 04:00:41.858325 748 kv/kvserver/store_raft.go:316 ⋮ [-] 1594  raft receive queue for r44 is full
W230620 04:00:41.984680 575 13@kv/kvserver/store_rebalancer.go:323 ⋮ [T1,n1,s1,store-rebalancer,obj=‹cpu›] 1595  StorePool missing descriptor for local store with ID 1, store list ‹  candidate: avg-ranges=66.00 avg-leases=25.00 avg-disk-usage=1.4 GiB avg-queries-per-second=12.86 avg-store-cpu-per-second=10ms›
W230620 04:00:41.984680 575 13@kv/kvserver/store_rebalancer.go:323 ⋮ [T1,n1,s1,store-rebalancer,obj=‹cpu›] 1595 +‹  2: ranges=66 leases=25 disk-usage=1.4 GiB queries-per-second=11.27 store-cpu-per-second=9ms io-overload=0.00›
W230620 04:00:41.984680 575 13@kv/kvserver/store_rebalancer.go:323 ⋮ [T1,n1,s1,store-rebalancer,obj=‹cpu›] 1595 +‹  3: ranges=66 leases=25 disk-usage=1.4 GiB queries-per-second=14.46 store-cpu-per-second=11ms io-overload=0.00›
W230620 04:00:42.231078 575 13@kv/kvserver/store_rebalancer.go:431 ⋮ [T1,n1,s1,store-rebalancer,obj=‹cpu›] 1596  no rebalance context given, bailing out of rebalancing store, will try again later
W230620 04:00:42.858581 748 kv/kvserver/store_raft.go:316 ⋮ [-] 1597  raft receive queue for r44 is full
W230620 04:00:44.858976 748 kv/kvserver/store_raft.go:316 ⋮ [-] 1598  raft receive queue for r44 is full
W230620 04:00:46.858709 748 kv/kvserver/store_raft.go:316 ⋮ [-] 1599  raft receive queue for r44 is full
W230620 04:00:47.593111 1722 kv/kvserver/closedts/sidetransport/receiver.go:139 ⋮ [n1] 1600  closed timestamps side-transport connection dropped from node: 3
W230620 04:00:47.593157 1898 kv/kvserver/closedts/sidetransport/receiver.go:139 ⋮ [n1] 1601  closed timestamps side-transport connection dropped from node: 2
W230620 04:00:47.593152 641 kv/kvserver/raft_transport.go:605 ⋮ [T1,n1] 1602  while processing outgoing Raft queue to node 3: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.593157 60 kv/kvserver/raft_transport.go:605 ⋮ [T1,n1] 1603  while processing outgoing Raft queue to node 2: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.593182 493 kv/kvserver/raft_transport.go:605 ⋮ [T1,n1] 1604  while processing outgoing Raft queue to node 3: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.593201 55 2@gossip/gossip.go:1406 ⋮ [T1,n1] 1605  no incoming or outgoing connections
W230620 04:00:47.593231 347874 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1606  ‹[core]›‹[Server #1] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"›
W230620 04:00:47.593235 347861 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1607  ‹[core]›‹[Server #1] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"›
W230620 04:00:47.593240 724 kv/kvserver/raft_transport.go:605 ⋮ [T1,n1] 1608  while processing outgoing Raft queue to node 2: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609  ‹[core]›‹[Channel #9 SubChannel #11] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹  "Addr": "localhost:26258",›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹  "ServerName": "localhost:26258",›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹  "Attributes": null,›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹  "BalancerAttributes": null,›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹  "Type": 0,›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹  "Metadata": null›
W230620 04:00:47.593382 347895 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1609 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:47.593447 350 2@rpc/context.go:2399 ⋮ [T1,n1,rnode=?,raddr=‹localhost:26258›,class=system,rpc] 1610  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.593478 350 rpc/context.go:2313 ⋮ [T1,n1,rnode=?,raddr=‹localhost:26258›,class=system,rpc] 1611  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.593477 347894 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n1] 1612  circuitbreaker: ‹gossip 127.0.0.1:26257->localhost:26258› tripped: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.593530 347894 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n1] 1613  circuitbreaker: ‹gossip 127.0.0.1:26257->localhost:26258› event: ‹BreakerTripped›
W230620 04:00:47.593540 347894 gossip/client.go:118 ⋮ [T1,n1] 1614  failed to start gossip client to ‹localhost:26258›: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
E230620 04:00:47.593798 342480 util/log/logcrash/crash_reporting.go:373 ⋮ [T1,n1] 1615  Queued as error ‹86a1698254d94f4ca9cfb6aa93fff494›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616  ‹[core]›‹[Channel #41 SubChannel #42] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹  "Addr": "localhost:26259",›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹  "ServerName": "localhost:26259",›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹  "Attributes": null,›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹  "BalancerAttributes": null,›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹  "Type": 0,›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹  "Metadata": null›
W230620 04:00:47.725793 346430 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1616 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:47.725890 725 2@rpc/context.go:2399 ⋮ [T1,n1,rnode=2,raddr=‹localhost:26259›,class=default,rpc] 1617  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.725944 725 rpc/context.go:2313 ⋮ [T1,n1,rnode=2,raddr=‹localhost:26259›,class=default,rpc] 1618  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.761236 1616 kv/kvserver/closedts/sidetransport/sender.go:825 ⋮ [T1,n1,ctstream=2] 1619  failed to send closed timestamp message 57056 to n2: send msg error: ‹EOF›
W230620 04:00:47.761236 1617 kv/kvserver/closedts/sidetransport/sender.go:825 ⋮ [T1,n1,ctstream=3] 1620  failed to send closed timestamp message 57056 to n3: send msg error: ‹EOF›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621  ‹[core]›‹[Channel #27 SubChannel #29] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹  "Addr": "localhost:26258",›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹  "ServerName": "localhost:26258",›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹  "Attributes": null,›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹  "BalancerAttributes": null,›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹  "Type": 0,›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹  "Metadata": null›
W230620 04:00:47.927606 347897 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1621 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622  ‹[core]›‹[Channel #34 SubChannel #35] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹  "Addr": "localhost:26259",›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹  "ServerName": "localhost:26259",›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹  "Attributes": null,›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹  "BalancerAttributes": null,›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹  "Type": 0,›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹  "Metadata": null›
W230620 04:00:47.927606 346494 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1622 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623  ‹[core]›‹[Channel #26 SubChannel #28] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹  "Addr": "localhost:26259",›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹  "ServerName": "localhost:26259",›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹  "Attributes": null,›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹  "BalancerAttributes": null,›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹  "Type": 0,›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹  "Metadata": null›
W230620 04:00:47.927606 347987 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1623 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:47.927679 661 2@rpc/context.go:2399 ⋮ [T1,n1,rnode=?,raddr=‹localhost:26259›,class=system,rpc] 1625  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
E230620 04:00:47.927679 582 2@rpc/context.go:2399 ⋮ [T1,n1,rnode=3,raddr=‹localhost:26258›,class=system,rpc] 1624  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
E230620 04:00:47.927680 62 2@rpc/context.go:2399 ⋮ [T1,n1,rnode=2,raddr=‹localhost:26259›,class=system,rpc] 1626  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.927705 661 rpc/context.go:2313 ⋮ [T1,n1,rnode=?,raddr=‹localhost:26259›,class=system,rpc] 1627  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.927706 582 rpc/context.go:2313 ⋮ [T1,n1,rnode=3,raddr=‹localhost:26258›,class=system,rpc] 1628  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.927707 62 rpc/context.go:2313 ⋮ [T1,n1,rnode=2,raddr=‹localhost:26259›,class=system,rpc] 1629  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
E230620 04:00:48.027941 347961 2@rpc/context.go:2399 ⋮ [T1,n1,rnode=2,raddr=‹localhost:26259›,class=system,rpc] 1630  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.027969 347961 rpc/context.go:2313 ⋮ [T1,n1,rnode=2,raddr=‹localhost:26259›,class=system,rpc] 1631  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.028016 346589 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n1] 1632  circuitbreaker: ‹rpc 127.0.0.1:26257 [n2]› tripped: failed to connect to n2 at ‹localhost:26259›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.028054 346589 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n1] 1633  circuitbreaker: ‹rpc 127.0.0.1:26257 [n2]› event: ‹BreakerTripped›
W230620 04:00:48.028061 346589 2@rpc/nodedialer/nodedialer.go:196 ⋮ [T1,n1] 1634  unable to connect to n2: failed to connect to n2 at ‹localhost:26259›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.029362 346591 rpc/context.go:2313 ⋮ [T1,n1,rnode=3,raddr=‹localhost:26258›,class=system,rpc] 1635  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.029405 346590 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n1] 1636  circuitbreaker: ‹rpc 127.0.0.1:26257 [n3]› tripped: failed to connect to n3 at ‹localhost:26258›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.029436 346590 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n1] 1637  circuitbreaker: ‹rpc 127.0.0.1:26257 [n3]› event: ‹BreakerTripped›
W230620 04:00:48.029443 346590 2@rpc/nodedialer/nodedialer.go:196 ⋮ [T1,n1] 1638  unable to connect to n3: failed to connect to n3 at ‹localhost:26258›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 2/Unknown]
I230620 04:00:48.100776 342480 1@storage/pebble.go:1268 ⋮ [T1,n1] 1639  the server is terminating due to a fatal error (see the DEV channel for details)
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640  file write stall detected: disk slowness detected: syncdata on file 005315.log (0 bytes) has been ongoing for 20.4s
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !goroutine 342480 [running]:
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !runtime/debug.Stack()
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  GOROOT/src/runtime/debug/stack.go:24 +0x65
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/cockroach/pkg/util/log.(*loggerT).outputLogEntry(0xc00130d460, {{{0xc007d80bd0, 0x24}, {0x5d8c9db, 0x1}, {0x5d8c9db, 0x1}, {0x5d8c9db, 0x1}}, 0x176a421048227da4, ...})
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/cockroach/pkg/util/log/clog.go:261 +0xb8
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/cockroach/pkg/util/log.logfDepthInternal({0x72a32f0, 0xc000da2cf0}, 0x2, 0x4, 0x0, 0x0?, {0x5d563a6, 0x1d}, {0xc00180ddc8, 0x1, ...})
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/cockroach/pkg/util/log/channels.go:106 +0x645
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/cockroach/pkg/util/log.logfDepth(...)
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/cockroach/pkg/util/log/channels.go:39
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/cockroach/pkg/util/log.Fatalf(...)
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/cockroach/bazel-out/k8-opt/bin/pkg/util/log/log_channels_generated.go:848
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/cockroach/pkg/storage.(*Pebble).makeMetricEtcEventListener.func4({{0xc0096c6ed0, 0x2f}, 0x3, 0x0, 0x4bd7c719b})
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/cockroach/pkg/storage/pebble.go:1268 +0x215
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/pebble.TeeEventListener.func4({{0xc0096c6ed0, 0x2f}, 0x3, 0x0, 0x4bd7c719b})
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/pebble/external/com_github_cockroachdb_pebble/event.go:672 +0x4d
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/cockroach/pkg/storage.wrapFilesystemMiddleware.func1({{0xc0096c6ed0, 0x2f}, 0x3, 0x0, 0x4bd7c719b})
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/cockroach/pkg/storage/pebble.go:668 +0x97
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/pebble/vfs.(*diskHealthCheckingFS).ReuseForWrite.func2(0x3e?, 0xa6f8b542846?, 0xb5572c0?)
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/pebble/vfs/external/com_github_cockroachdb_pebble/vfs/disk_health.go:754 +0x6b
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !github.com/cockroachdb/pebble/vfs.(*diskHealthCheckingFile).startTicker.func1()
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/pebble/vfs/external/com_github_cockroachdb_pebble/vfs/disk_health.go:187 +0x1cf
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !created by github.com/cockroachdb/pebble/vfs.(*diskHealthCheckingFile).startTicker
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !  github.com/cockroachdb/pebble/vfs/external/com_github_cockroachdb_pebble/vfs/disk_health.go:167 +0x5d
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !For more context, check log files in: /data/cockroach/cockroach-data/node1/logs
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !****************************************************************************
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !This node experienced a fatal error (printed above), and as a result the
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !process is terminating.
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !Fatal errors can occur due to faulty hardware (disks, memory, clocks) or a
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !problem in CockroachDB. With your help, the support team at Cockroach Labs
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !will try to determine the root cause, recommend next steps, and we can
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !improve CockroachDB based on your report.
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !Please submit a crash report by following the instructions here:
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !    https://github.com/cockroachdb/cockroach/issues/new/choose
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !If you would rather not post publicly, please contact us directly at:
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !    support@cockroachlabs.com
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !
F230620 04:00:48.100801 342480 storage/pebble.go:1268 ⋮ [T1,n1] 1640 !The Cockroach Labs team appreciates your feedback.

code:

package main

import (
    "context"
    "log"
    "math/rand"
    "time"

    "github.com/jmoiron/sqlx"
    _ "github.com/lib/pq"
    "github.com/samber/lo"
)

type Person struct {
    ID int64 `db:"_id"`

    RealName string `db:"real_name"`

    NickName string `db:"nick_name"`

    Sex string `db:"sex"`

    Birthday time.Time `db:"birthday"`

    Height int32 `db:"height"`

    Weight int32 `db:"weight"`

    City string `db:"city"`

    Deleted bool `db:"deleted"`

    CreateTime time.Time `db:"create_time"`

    UpdateTime time.Time `db:"update_time"`
}

func main() {
    dsn := "postgresql://test@localhost:36256/test?sslmode=verify-full&sslrootcert=/data/cockroach/certs/node.crt&sslcert=/data/cockroach/certs/client.test.crt&sslkey=/data/cockroach/certs/client.test.key"
    db, err := sqlx.Open("postgres", dsn)
    if err != nil {
        log.Fatalln(err)
        return
    }
    defer db.Close()

    ctx := context.Background()

    err = db.PingContext(ctx)
    if err != nil {
        log.Println(err)
        return
    }

    var now string
    err = db.GetContext(ctx, &now, "SELECT now() AT TIME ZONE 'Asia/Shanghai';")
    if err != nil {
        log.Fatalln(err)
        return
    }
    log.Println(now)

    err = insert(ctx, db, 5000000)
    if err != nil {
        log.Println(err)
        return
    }

    err = query_by_city(ctx, db, 100)
    if err != nil {
        log.Println(err)
        return
    }

    log.Println("finished.")
}

func insert(ctx context.Context, db *sqlx.DB, number int) error {
    log.Println("start inserting. number:", number)

    var total int64

    for l := 0; l < number/500; l++ {
        persons := make([]*Person, 0, 500)
        for idx := 0; idx < 500; idx++ {
            person := &Person{
                RealName: lo.Sample(firstNames) + lo.Sample(lastNames),
                NickName: lo.Sample(firstNames) + lo.Sample(lastNames),
                Sex:      lo.Sample([]string{"male", "female"}),
                Birthday: time.Date(
                    rand.Intn(100)+1920,
                    time.Month(rand.Intn(12)+1),
                    rand.Intn(30),
                    0,
                    0,
                    0,
                    0,
                    time.Local,
                ),
                Height: int32(rand.Intn(20) + 160),
                Weight: int32(rand.Intn(30) + 50),
                City:   lo.Sample(cityList),
            }
            persons = append(persons, person)
        }
        log.Println("preared.")
        _, err := db.NamedExecContext(ctx, `INSERT INTO person
    (real_name, nick_name, sex, birthday, height, weight, city)
    VALUES(:real_name, :nick_name, :sex, :birthday, :height, :weight, :city)`, persons)
        if err != nil {
            return err
        }

        total += int64(len(persons))
        log.Println("inserted:", total)
    }

    log.Println("complete insertion.")

    return nil
}

func query_by_city(ctx context.Context, db *sqlx.DB, number int) error {
    log.Println("start quering. condition: city. number:", number)

    for idx := 0; idx < number; idx++ {
        city := lo.Sample(cityList)
        var rows []*Person
        err := db.SelectContext(
            ctx,
            &rows,
            `SELECT _id, real_name, nick_name, sex, birthday, height, weight, city, deleted, create_time, update_time
        FROM person
        WHERE city = $1`,
            city,
        )
        if err != nil {
            return err
        }
    }

    log.Println("complete querion.")
    return nil
}

Jira issue: CRDB-28904

blathers-crl[bot] commented 1 year ago

Hello, I am Blathers. I am here to help you get the issue triaged.

It looks like you have not filled out the issue in the format of any of our templates. To best assist you, we advise you to use one of these templates.

I have CC'd a few people who may be able to assist you:

If we have not gotten back to your issue within a few business days, you can try the following:

:owl: Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.

blathers-crl[bot] commented 1 year ago

cc @cockroachdb/replication

knz commented 1 year ago

@wencan The log data you have shared is also insufficient to get a clear picture of what happened. We would want to see log data for all 3 nodes, not just 1.

Also it looks like you do not have enough hardware to run 3 cockroachdb nodes on 1 server. Try either:

Regards

erikgrinaker commented 1 year ago

file write stall detected: disk slowness detected: syncdata on file 005315.log (0 bytes) has been ongoing for 20.4s

The disk wasn't able to write for 20 seconds. Most likely the disk is faulty, or underprovisioned. There's some more information on troubleshooting disk stalls in our documentation:

https://www.cockroachlabs.com/docs/v23.1/cluster-setup-troubleshooting#disk-stalls

wencan commented 1 year ago

@knz node2 log:

I230620 04:00:04.823699 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r19/2:‹/Table/1{7-8}›,raft] 1426  slow non-blocking raft commit: commit-wait 727.251963ms sem 432ns
I230620 04:00:06.090210 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r2/3:‹/System/NodeLiveness{-Max}›,raft] 1427  slow non-blocking raft commit: commit-wait 1.116325468s sem 310ns
W230620 04:00:06.431999 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1428  slow heartbeat took 1.599848284s; err=<nil>
I230620 04:00:07.924962 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r3/3:‹/System/{NodeLive…-tsd}›,raft] 1429  slow non-blocking raft commit: commit-wait 853.204887ms sem 771ns
I230620 04:00:08.237964 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r95/3:‹/System/tsd/cr.node.{re…-sq…}›,raft] 1430  slow non-blocking raft commit: commit-wait 35.496572ms wal-q 490.603957ms sem 834ns
W230620 04:00:08.968138 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1431  slow heartbeat took 1.135839099s; err=<nil>
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432  
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +__level_____count____size___score______in__ingest(sz_cnt)____move(sz_cnt)___write(sz_cnt)____read___r-amp___w-amp__val-bl
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +    WAL         1    49 M       -   3.2 G       -       -       -       -   3.2 G       -       -       -     1.0
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      0         0     0 B    0.00   3.2 G     0 B       0     0 B       0   222 M     152     0 B       0     0.1     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      1         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      2         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      3         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      4         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      5        20    59 M    0.93   222 M     0 B       0     0 B       0   1.5 G     486   1.6 G       1     7.1   529 K
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +      6        47   310 M       -   193 M     0 B       0     0 B       0   391 M      61   417 M       1     2.0   561 K
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +  total        67   370 M       -   3.2 G     0 B       0     0 B       0   5.4 G     699   2.0 G       2     1.7   1.1 M
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +  flush        61                             0 B       0       0  (ingest = tables-ingested, move = ingested-as-flushable)
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +compact       168     0 B     0 B       0                          (size == estimated-debt, score = in-progress-bytes, in = num-in-progress)
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +  ctype       168       0       0       0       0       0       0  (default, delete, elision, move, read, rewrite, multi-level)
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 + memtbl         1    64 M
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +zmemtbl         0     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +   ztbl         0     0 B
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 + bcache     4.2 K    65 M   91.1%  (score == hit-rate)
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 + tcache        55    39 K  100.0%  (score == hit-rate)
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 +  snaps         1       - 91160211  (score == earliest seq num)
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 + titers         4
I230620 04:00:09.832431 536 kv/kvserver/store.go:3299 ⋮ [T1,n3] 1432 + filter         -       -   93.8%  (score == utility)
W230620 04:00:12.465552 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1433  slow heartbeat took 1.633919851s; err=<nil>
W230620 04:00:14.926327 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1434  slow heartbeat took 1.094209811s; err=<nil>
I230620 04:00:19.742883 1441 jobs/job_scheduler.go:172 ⋮ [T1,n3] 1435  Starting job for schedule 874048588737052673 (‹"sql-stats-compaction"›); scheduled to run at 2023-06-20 04:00:00 +0000 UTC; next run scheduled for 2023-06-20 05:00:00 +0000 UTC
W230620 04:00:21.070966 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1436  slow heartbeat took 1.239371623s; err=<nil>
I230620 04:00:21.070956 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r2/3:‹/System/NodeLiveness{-Max}›,raft] 1437  slow non-blocking raft commit: commit-wait 621.947645ms sem 359ns
W230620 04:00:24.012498 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1438  slow heartbeat took 1.180787837s; err=<nil>
I230620 04:00:25.925358 1245 jobs/adopt.go:112 ⋮ [T1,n3] 1439  claimed 1 jobs
W230620 04:00:26.953799 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1440  slow heartbeat took 1.121801626s; err=<nil>
I230620 04:00:27.235191 367793 jobs/adopt.go:261 ⋮ [T1,n3] 1441  job 875440438453567491: resuming execution
I230620 04:00:27.885464 367831 jobs/registry.go:1583 ⋮ [T1,n3] 1442  AUTO SQL STATS COMPACTION job 875440438453567491: stepping through state running
I230620 04:00:29.610996 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r54/2:‹/Table/5{3-4}›,raft] 1443  slow non-blocking raft commit: commit-wait 730.236778ms sem 207ns
I230620 04:00:29.829954 410 kv/kvserver/store_raft.go:656 ⋮ [T1,n3,s3,r41/2:‹/Table/{39-40}›,raft] 1444  raft ready handling: 1.03s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.03s, other=0.00s], wrote 252 B sync(non-blocking) [append-ent=188 B (1), ]; node might be overloaded
I230620 04:00:29.829946 388 kv/kvserver/store_raft.go:656 ⋮ [T1,n3,s3,r45/2:‹/Table/4{3-4}›,raft] 1445  raft ready handling: 1.15s [append=0.00s, apply=0.00s, commit-batch-non-blocking-sync=1.15s, other=0.00s], wrote 553 B sync(non-blocking) [append-ent=489 B (1), ]; node might be overloaded
I230620 04:00:29.830113 399 kv/kvserver/store_raft.go:656 ⋮ [T1,n3,s3,r4/3:‹/System/tsd{-/cr.nod…}›,raft] 1446  raft ready handling: 1.15s [append=0.00s, apply=1.15s, commit-batch=0.00s, other=0.00s], wrote 51 B [apply=138 KiB (1)] pebble stats: [commit-wait 35.28µs sem 193ns]; node might be overloaded
I230620 04:00:30.026954 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r17/2:‹/Table/1{5-6}›,raft] 1447  slow non-blocking raft commit: commit-wait 197.28538ms sem 473ns
I230620 04:00:30.027011 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r45/2:‹/Table/4{3-4}›,raft] 1448  slow non-blocking raft commit: commit-wait 297.131µs sem 171ns
I230620 04:00:30.027033 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r41/2:‹/Table/{39-40}›,raft] 1449  slow non-blocking raft commit: commit-wait 307.956µs sem 467ns
W230620 04:00:31.599367 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1450  slow heartbeat took 2.766955859s; err=<nil>
I230620 04:00:32.174636 367831 sql/compact_sql_stats.go:42 ⋮ [T1,n3,job=‹AUTO SQL STATS COMPACTION id=875440438453567491›] 1451  starting sql stats compaction job
I230620 04:00:38.595654 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r41/2:‹/Table/{39-40}›,raft] 1452  slow non-blocking raft commit: commit-wait 991.779623ms sem 704ns
I230620 04:00:39.626748 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r2/3:‹/System/NodeLiveness{-Max}›,raft] 1453  slow non-blocking raft commit: commit-wait 600.337188ms sem 306ns
W230620 04:00:39.927202 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1454  slow heartbeat took 2.094751446s; err=<nil>
W230620 04:00:41.923704 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 1455  slow heartbeat took 1.091956288s; err=<nil>
I230620 04:00:43.961808 431 kv/kvserver/replica_rangefeed.go:711 ⋮ [T1,n3,s3,r51/2:‹/Table/5{0-1}›] 1456  RangeFeed closed timestamp 1687233628.915284065,0 is behind by 15.046522415s
I230620 04:00:46.017984 367831 sql/compact_sql_stats.go:101 ⋮ [T1,n3,job=‹AUTO SQL STATS COMPACTION id=875440438453567491›] 1457  sql stats compaction job terminated with status = succeeded
I230620 04:00:46.463874 367831 jobs/registry.go:1583 ⋮ [T1,n3] 1458  AUTO SQL STATS COMPACTION job 875440438453567491: stepping through state succeeded
W230620 04:00:47.036300 840 server/node.go:1075 ⋮ [T1,n3,summaries] 1459  health alerts detected: {Alerts:[{StoreID:3 Category:‹METRICS› Description:‹ranges.underreplicated› Value:34}]}
W230620 04:00:47.593149 680 kv/kvserver/raft_transport.go:605 ⋮ [T1,n3] 1460  while processing outgoing Raft queue to node 1: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.593183 925 kv/kvserver/closedts/sidetransport/receiver.go:139 ⋮ [n3] 1461  closed timestamps side-transport connection dropped from node: 1
W230620 04:00:47.593246 363447 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1462  ‹[core]›‹[Server #1] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"›
W230620 04:00:47.593256 555 kv/kvserver/raft_transport.go:605 ⋮ [T1,n3] 1463  while processing outgoing Raft queue to node 1: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464  ‹[core]›‹[Channel #33 SubChannel #34] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹  "Addr": "localhost:26257",›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹  "ServerName": "localhost:26257",›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹  "Attributes": null,›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹  "BalancerAttributes": null,›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹  "Type": 0,›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹  "Metadata": null›
W230620 04:00:47.724144 368368 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1464 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
W230620 04:00:47.724213 368336 kv/kvserver/raft_transport.go:600 ⋮ [T1,n3] 1465  creating batch client for node 1 failed: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.724213 368336 kv/kvserver/raft_transport.go:600 ⋮ [T1,n3] 1465 +(1) grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.724213 368336 kv/kvserver/raft_transport.go:600 ⋮ [T1,n3] 1465 +Error types: (1) *status.Error
E230620 04:00:47.724266 592 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1466  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.724301 592 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1467  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.764953 1602 kv/kvserver/closedts/sidetransport/sender.go:825 ⋮ [T1,n3,ctstream=1] 1468  failed to send closed timestamp message 57058 to n1: send msg error: ‹EOF›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469  ‹[core]›‹[Channel #17 SubChannel #19] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹  "Addr": "localhost:26257",›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹  "ServerName": "localhost:26257",›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹  "Attributes": null,›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹  "BalancerAttributes": null,›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹  "Type": 0,›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹  "Metadata": null›
W230620 04:00:47.858443 368516 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1469 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:47.858537 482 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1470  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.858523 368547 kv/kvserver/raft_transport.go:600 ⋮ [T1,n3] 1471  creating batch client for node 1 failed: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.858523 368547 kv/kvserver/raft_transport.go:600 ⋮ [T1,n3] 1471 +(1) grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.858523 368547 kv/kvserver/raft_transport.go:600 ⋮ [T1,n3] 1471 +Error types: (1) *status.Error
I230620 04:00:47.858564 482 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1472  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473  ‹[core]›‹[Channel #8 SubChannel #9] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹  "Addr": "localhost:26257",›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹  "ServerName": "localhost:26257",›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹  "Attributes": null,›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹  "BalancerAttributes": null,›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹  "Type": 0,›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹  "Metadata": null›
W230620 04:00:47.928139 368433 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1473 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:47.928193 137 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=?,raddr=‹localhost:26257›,class=system,rpc] 1474  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.928213 137 rpc/context.go:2313 ⋮ [T1,n3,rnode=?,raddr=‹localhost:26257›,class=system,rpc] 1475  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476  ‹[core]›‹[Channel #46 SubChannel #47] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹  "Attributes": null,›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹  "BalancerAttributes": null,›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹  "Type": 0,›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹  "Metadata": null›
W230620 04:00:48.029177 368540 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1476 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:48.029223 368537 rpc/context.go:2672 ⋮ [T1,n3,rnode=?,raddr=‹localhost:26257›,class=system,rpc] 1477  blocking dialback connection failed to ‹localhost:26257›, n1, ‹dial tcp [::1]:26257: connect: connection refused›
I230620 04:00:48.029279 368537 rpc/heartbeat.go:174 ⋮ [-] 1478  failing ping request from node n1
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479  ‹[core]›‹[Channel #48 SubChannel #49] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹  "Attributes": null,›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹  "BalancerAttributes": null,›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹  "Type": 0,›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹  "Metadata": null›
W230620 04:00:48.150114 368568 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1479 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:48.150205 368566 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1480  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.150243 368566 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1481  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.150274 368551 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n3] 1482  circuitbreaker: ‹rpc 127.0.0.1:26258 [n1]› tripped: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.150306 368551 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n3] 1483  circuitbreaker: ‹rpc 127.0.0.1:26258 [n1]› event: ‹BreakerTripped›
W230620 04:00:48.150316 368551 2@rpc/nodedialer/nodedialer.go:196 ⋮ [T1,n3] 1484  unable to connect to n1: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485  ‹[core]›‹[Channel #50 SubChannel #51] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹  "Attributes": null,›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹  "BalancerAttributes": null,›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹  "Type": 0,›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹  "Metadata": null›
W230620 04:00:48.359095 368598 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1485 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:48.359144 368596 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1486  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.359209 368580 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n3] 1487  circuitbreaker: ‹rpc 127.0.0.1:26258 [n1]› tripped: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.359245 368580 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n3] 1488  circuitbreaker: ‹rpc 127.0.0.1:26258 [n1]› event: ‹BreakerTripped›
W230620 04:00:48.359251 368580 2@rpc/nodedialer/nodedialer.go:196 ⋮ [T1,n3] 1489  unable to connect to n1: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490  ‹[core]›‹[Channel #52 SubChannel #53] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹  "Attributes": null,›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹  "BalancerAttributes": null,›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹  "Type": 0,›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹  "Metadata": null›
W230620 04:00:48.766463 368611 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1490 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:48.766548 368481 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1491  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492  ‹[core]›‹[Channel #54 SubChannel #55] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹  "Attributes": null,›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹  "BalancerAttributes": null,›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹  "Type": 0,›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹  "Metadata": null›
W230620 04:00:48.901425 368523 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1492 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:48.901477 368521 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1493  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494  ‹[core]›‹[Channel #56 SubChannel #57] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹  "Addr": "localhost:26257",›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹  "ServerName": "localhost:26257",›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹  "Attributes": null,›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹  "BalancerAttributes": null,›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹  "Type": 0,›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹  "Metadata": null›
W230620 04:00:49.768001 368508 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1494 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:49.768206 368617 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1495  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:49.768265 368617 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1496  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497  ‹[core]›‹[Channel #58 SubChannel #59] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹  "Addr": "localhost:26257",›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹  "ServerName": "localhost:26257",›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹  "Attributes": null,›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹  "BalancerAttributes": null,›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹  "Type": 0,›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹  "Metadata": null›
W230620 04:00:50.587272 368463 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1497 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:50.587320 368461 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1498  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499  ‹[core]›‹[Channel #60 SubChannel #61] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹  "Addr": "localhost:26257",›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹  "ServerName": "localhost:26257",›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹  "Attributes": null,›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹  "BalancerAttributes": null,›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹  "Type": 0,›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹  "Metadata": null›
W230620 04:00:50.768998 368647 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1499 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:50.769115 368645 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1500  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:50.769145 368645 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1501  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502  ‹[core]›‹[Channel #62 SubChannel #63] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹  "Addr": "localhost:26257",›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹  "ServerName": "localhost:26257",›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹  "Attributes": null,›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹  "BalancerAttributes": null,›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹  "Type": 0,›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹  "Metadata": null›
W230620 04:00:51.769601 368653 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1502 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:51.769688 368651 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1503  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:51.769711 368651 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1504  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505  ‹[core]›‹[Channel #64 SubChannel #65] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹  "Addr": "localhost:26257",›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹  "ServerName": "localhost:26257",›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹  "Attributes": null,›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹  "BalancerAttributes": null,›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹  "Type": 0,›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹  "Metadata": null›
W230620 04:00:53.359528 368728 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1505 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:53.359615 368726 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1506  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:53.359639 368726 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1507  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508  ‹[core]›‹[Channel #66 SubChannel #67] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹  "Addr": "localhost:26257",›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹  "ServerName": "localhost:26257",›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹  "Attributes": null,›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹  "BalancerAttributes": null,›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹  "Type": 0,›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹  "Metadata": null›
W230620 04:00:54.771854 368678 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1508 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:54.771939 368676 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1509  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:54.771969 368676 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1510  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511  ‹[core]›‹[Channel #68 SubChannel #69] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹  "Addr": "localhost:26257",›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹  "ServerName": "localhost:26257",›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹  "Attributes": null,›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹  "BalancerAttributes": null,›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹  "Type": 0,›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹  "Metadata": null›
W230620 04:00:56.358725 368837 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1511 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:56.358816 368835 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1512  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:56.358843 368835 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1513  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514  ‹[core]›‹[Channel #70 SubChannel #71] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹  "Addr": "localhost:26257",›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹  "ServerName": "localhost:26257",›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹  "Attributes": null,›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹  "BalancerAttributes": null,›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹  "Type": 0,›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹  "Metadata": null›
W230620 04:00:56.837085 368870 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1514 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:56.837163 368868 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1515  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:57.036409 840 server/node.go:1075 ⋮ [T1,n3,summaries] 1516  health alerts detected: {Alerts:[{StoreID:3 Category:‹METRICS› Description:‹ranges.underreplicated› Value:33}]}
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517  ‹[core]›‹[Channel #72 SubChannel #73] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹  "Addr": "localhost:26257",›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹  "ServerName": "localhost:26257",›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹  "Attributes": null,›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹  "BalancerAttributes": null,›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹  "Type": 0,›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹  "Metadata": null›
W230620 04:00:57.773625 368848 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1517 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:57.773715 368846 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1518  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:57.773741 368846 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1519  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:57.773770 1602 kv/kvserver/closedts/sidetransport/sender.go:795 ⋮ [T1,n3,ctstream=1] 1520  side-transport failed to connect to n1: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521  ‹[core]›‹[Channel #74 SubChannel #75] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹  "Addr": "localhost:26257",›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹  "ServerName": "localhost:26257",›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹  "Attributes": null,›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹  "BalancerAttributes": null,›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹  "Type": 0,›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹  "Metadata": null›
W230620 04:00:58.774362 368905 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1521 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:58.774444 368903 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1522  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:58.774469 368903 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1523  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:58.794048 425 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n3,s3,r95/3:‹/System/tsd/cr.node.{re…-sq…}›,raft] 1524  slow non-blocking raft commit: commit-wait 713.901245ms sem 1.016µs
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525  ‹[core]›‹[Channel #76 SubChannel #77] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹  "Addr": "localhost:26257",›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹  "ServerName": "localhost:26257",›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹  "Attributes": null,›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹  "BalancerAttributes": null,›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹  "Type": 0,›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹  "Metadata": null›
W230620 04:00:59.774906 368961 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1525 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:59.774985 368959 2@rpc/context.go:2399 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1526  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:59.775012 368959 rpc/context.go:2313 ⋮ [T1,n3,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1527  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 05:04:00.107417 548 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n3,liveness-hb] 6738  slow heartbeat took 1.275036029s; err=<nil>

node3 log:

W230620 04:00:02.713497 436 13@kv/kvserver/store_rebalancer.go:323 ⋮ [T1,n2,s2,store-rebalancer,obj=‹cpu›] 1709  StorePool missing descriptor for local store with ID 2, store list ‹  candidate: avg-ranges=66.00 avg-leases=20.00 avg-disk-usage=1.4 GiB avg-queries-per-second=17.46 avg-store-cpu-per-second=23ms›
W230620 04:00:02.713497 436 13@kv/kvserver/store_rebalancer.go:323 ⋮ [T1,n2,s2,store-rebalancer,obj=‹cpu›] 1709 +‹  3: ranges=66 leases=30 disk-usage=1.4 GiB queries-per-second=26.22 store-cpu-per-second=16ms io-overload=0.00›
W230620 04:00:02.713497 436 13@kv/kvserver/store_rebalancer.go:323 ⋮ [T1,n2,s2,store-rebalancer,obj=‹cpu›] 1709 +‹  1: ranges=66 leases=10 disk-usage=1.4 GiB queries-per-second=8.69 store-cpu-per-second=31ms io-overload=0.00›
W230620 04:00:02.713556 436 13@kv/kvserver/store_rebalancer.go:431 ⋮ [T1,n2,s2,store-rebalancer,obj=‹cpu›] 1710  no rebalance context given, bailing out of rebalancing store, will try again later
I230620 04:00:05.083670 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r2/2:‹/System/NodeLiveness{-Max}›,raft] 1711  slow non-blocking raft commit: commit-wait 695.719677ms sem 226ns
W230620 04:00:05.392569 365167 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,s2,r33/2:‹/{NamespaceTab…-Table/32}›] 1712  slow heartbeat took 1.393023916s; err=<nil>
W230620 04:00:06.346113 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1713  slow heartbeat took 1.620555293s; err=<nil>
I230620 04:00:08.427890 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r4/2:‹/System/tsd{-/cr.nod…}›,raft] 1714  slow non-blocking raft commit: commit-wait 418.336973ms wal-q 196.275109ms sem 235ns
W230620 04:00:08.965918 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1715  slow heartbeat took 1.239831759s; err=<nil>
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716  
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +__level_____count____size___score______in__ingest(sz_cnt)____move(sz_cnt)___write(sz_cnt)____read___r-amp___w-amp__val-bl
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +    WAL         1    50 M       -   3.2 G       -       -       -       -   3.2 G       -       -       -     1.0
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      0         0     0 B    0.00   3.2 G     0 B       0     0 B       0   221 M     152     0 B       0     0.1     0 B
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      1         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      2         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      3         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      4         0     0 B    0.00     0 B     0 B       0     0 B       0     0 B       0     0 B       0     0.0     0 B
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      5        15    48 M    0.88   222 M     0 B       0     0 B       0   1.6 G     509   1.6 G       1     7.2   381 K
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +      6        48   320 M       -   199 M     0 B       0     0 B       0   363 M      55   389 M       1     1.8   1.0 M
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +  total        63   368 M       -   3.2 G     0 B       0     0 B       0   5.4 G     716   2.0 G       2     1.7   1.4 M
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +  flush        61                             0 B       0       0  (ingest = tables-ingested, move = ingested-as-flushable)
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +compact       166     0 B     0 B       0                          (size == estimated-debt, score = in-progress-bytes, in = num-in-progress)
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +  ctype       166       0       0       0       0       0       0  (default, delete, elision, move, read, rewrite, multi-level)
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 + memtbl         1    64 M
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +zmemtbl         0     0 B
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +   ztbl        11    47 M
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 + bcache     4.1 K    64 M   88.5%  (score == hit-rate)
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 + tcache        62    44 K   99.9%  (score == hit-rate)
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 +  snaps         1       - 91269288  (score == earliest seq num)
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 + titers        13
I230620 04:00:09.706571 482 kv/kvserver/store.go:3299 ⋮ [T1,n2] 1716 + filter         -       -   88.1%  (score == utility)
W230620 04:00:14.751353 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1717  slow heartbeat took 1.025150086s; err=<nil>
I230620 04:00:19.124332 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r54/3:‹/Table/5{3-4}›,raft] 1718  slow non-blocking raft commit: commit-wait 1.02247897s sem 143ns
I230620 04:00:19.810650 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r2/2:‹/System/NodeLiveness{-Max}›,raft] 1719  slow non-blocking raft commit: commit-wait 608.264909ms sem 228ns
W230620 04:00:19.893943 365691 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,s2,r35/3:‹/Table/3{3-4}›] 1720  slow heartbeat took 1.334508435s; err=<nil>
I230620 04:00:22.416061 1441 sql/sqlstats/persistedsqlstats/flush.go:70 ⋮ [T1,n2] 1721  flushing 32 stmt/txn fingerprints (215040 bytes) after 809ns
W230620 04:00:22.568751 365827 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,s2,r44/3:‹/Table/4{2-3}›] 1722  slow heartbeat took 1.007317771s; err=<nil>
I230620 04:00:23.802143 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r2/2:‹/System/NodeLiveness{-Max}›,raft] 1723  slow non-blocking raft commit: commit-wait 922.250352ms sem 675ns
W230620 04:00:23.827145 365840 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,s2,r25/3:‹/Table/2{3-4}›] 1724  slow heartbeat took 1.105980309s; err=<nil>
W230620 04:00:24.002311 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1725  slow heartbeat took 1.27625556s; err=<nil>
I230620 04:00:24.527131 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r25/3:‹/Table/2{3-4}›,raft] 1726  slow non-blocking raft commit: commit-wait 699.792049ms sem 155ns
I230620 04:00:25.368987 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r45/3:‹/Table/4{3-4}›,raft] 1727  slow non-blocking raft commit: commit-wait 672.559981ms sem 291ns
W230620 04:00:25.735797 365863 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,s2,r47/2:‹/Table/4{5-6}›] 1728  slow heartbeat took 1.208223926s; err=<nil>
I230620 04:00:27.370182 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r2/2:‹/System/NodeLiveness{-Max}›,raft] 1729  slow non-blocking raft commit: commit-wait 708.242627ms sem 203ns
W230620 04:00:27.422901 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1730  slow heartbeat took 1.697018778s; err=<nil>
I230620 04:00:28.462937 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r44/3:‹/Table/4{2-3}›,raft] 1731  slow non-blocking raft commit: commit-wait 544.793162ms sem 228ns
I230620 04:00:29.610883 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r1/2:‹/{Min-System/NodeL…}›,raft] 1732  slow non-blocking raft commit: commit-wait 875.651487ms sem 400ns
W230620 04:00:30.591561 365918 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,s2,r15/2:‹/Table/1{3-4}›] 1733  slow heartbeat took 2.026126155s; err=<nil>
W230620 04:00:30.740974 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1734  slow heartbeat took 2.014667258s; err=<nil>
I230620 04:00:31.267519 363 kv/kvserver/store_raft.go:656 ⋮ [T1,n2,s2,r2/2:‹/System/NodeLiveness{-Max}›,raft] 1735  raft ready handling: 0.68s [append=0.00s, apply=0.68s, commit-batch=0.00s, other=0.00s], wrote 51 B [apply=124 B (1)] pebble stats: [commit-wait 36ns sem 241ns]; node might be overloaded
I230620 04:00:31.341558 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r54/3:‹/Table/5{3-4}›,raft] 1736  slow non-blocking raft commit: commit-wait 600.520176ms sem 388ns
I230620 04:00:34.358643 366175 kv/kvserver/liveness/liveness.go:1245 ⋮ [T1,n2,s2,r29/2:‹/Table/2{7-8}›] 1737  incremented n1 liveness epoch to 20
W230620 04:00:38.850373 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 1738  slow heartbeat took 1.124080765s; err=<nil>
I230620 04:00:42.523863 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r1/2:‹/{Min-System/NodeL…}›,raft] 1739  slow non-blocking raft commit: commit-wait 576.489743ms sem 457ns
I230620 04:00:43.955944 435 kv/kvserver/replica_rangefeed.go:711 ⋮ [T1,n2,s2,r51/3:‹/Table/5{0-1}›] 1740  RangeFeed closed timestamp 1687233628.915284065,0 is behind by 15.040656619s
I230620 04:00:46.045900 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r36/3:‹/Table/3{4-5}›,raft] 1741  slow non-blocking raft commit: commit-wait 854.05694ms sem 517ns
W230620 04:00:46.830365 199 server/node.go:1075 ⋮ [T1,n2,summaries] 1742  health alerts detected: {Alerts:[{StoreID:2 Category:‹METRICS› Description:‹ranges.underreplicated› Value:32}]}
W230620 04:00:47.593288 1704 kv/kvserver/closedts/sidetransport/receiver.go:139 ⋮ [n2] 1743  closed timestamps side-transport connection dropped from node: 1
W230620 04:00:47.593347 361898 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1744  ‹[core]›‹[Server #1] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing"›
W230620 04:00:47.593327 627 kv/kvserver/raft_transport.go:605 ⋮ [T1,n2] 1745  while processing outgoing Raft queue to node 1: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.593341 336 kv/kvserver/raft_transport.go:605 ⋮ [T1,n2] 1746  while processing outgoing Raft queue to node 1: recv msg error: grpc: ‹error reading from server: EOF› [code 14/Unavailable]:
W230620 04:00:47.636643 1786 kv/kvserver/closedts/sidetransport/sender.go:825 ⋮ [T1,n2,ctstream=1] 1747  failed to send closed timestamp message 57046 to n1: send msg error: ‹EOF›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748  ‹[core]›‹[Channel #30 SubChannel #32] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹  "Addr": "localhost:26257",›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹  "ServerName": "localhost:26257",›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹  "Attributes": null,›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹  "BalancerAttributes": null,›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹  "Type": 0,›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹  "Metadata": null›
W230620 04:00:47.730234 366696 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1748 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:47.730319 624 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1749  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.730300 366695 kv/kvserver/raft_transport.go:600 ⋮ [T1,n2] 1750  creating batch client for node 1 failed: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.730300 366695 kv/kvserver/raft_transport.go:600 ⋮ [T1,n2] 1750 +(1) grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.730300 366695 kv/kvserver/raft_transport.go:600 ⋮ [T1,n2] 1750 +Error types: (1) *status.Error
I230620 04:00:47.730350 624 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1751  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752  ‹[core]›‹[Channel #13 SubChannel #14] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹  "Addr": "localhost:26257",›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹  "ServerName": "localhost:26257",›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹  "Attributes": null,›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹  "BalancerAttributes": null,›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹  "Type": 0,›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹  "Metadata": null›
W230620 04:00:47.858561 366654 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1752 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
W230620 04:00:47.858594 366544 kv/kvserver/raft_transport.go:600 ⋮ [T1,n2] 1753  creating batch client for node 1 failed: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.858594 366544 kv/kvserver/raft_transport.go:600 ⋮ [T1,n2] 1753 +(1) grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:47.858594 366544 kv/kvserver/raft_transport.go:600 ⋮ [T1,n2] 1753 +Error types: (1) *status.Error
E230620 04:00:47.858625 498 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1754  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:47.858646 498 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1755  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756  ‹[core]›‹[Channel #43 SubChannel #44] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹  "Attributes": null,›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹  "BalancerAttributes": null,›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹  "Type": 0,›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹  "Metadata": null›
W230620 04:00:48.027757 366717 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1756 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:48.027804 366714 rpc/context.go:2672 ⋮ [T1,n2,rnode=?,raddr=‹localhost:26257›,class=system,rpc] 1757  blocking dialback connection failed to ‹localhost:26257›, n1, ‹dial tcp [::1]:26257: connect: connection refused›
I230620 04:00:48.027846 366714 rpc/heartbeat.go:174 ⋮ [-] 1758  failing ping request from node n1
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759  ‹[core]›‹[Channel #45 SubChannel #46] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹  "Attributes": null,›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹  "BalancerAttributes": null,›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹  "Type": 0,›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹  "Metadata": null›
W230620 04:00:48.141482 366741 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1759 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:48.141566 366739 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1760  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.141592 366739 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1761  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.141621 366689 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n2] 1762  circuitbreaker: ‹rpc 127.0.0.1:26259 [n1]› tripped: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.141654 366689 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n2] 1763  circuitbreaker: ‹rpc 127.0.0.1:26259 [n1]› event: ‹BreakerTripped›
W230620 04:00:48.141664 366689 2@rpc/nodedialer/nodedialer.go:196 ⋮ [T1,n2] 1764  unable to connect to n1: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765  ‹[core]›‹[Channel #8 SubChannel #9] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹  "Attributes": null,›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹  "BalancerAttributes": null,›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹  "Type": 0,›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹  "Metadata": null›
W230620 04:00:48.259695 366614 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1765 +‹}. Err: connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"›
E230620 04:00:48.259766 313 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=?,raddr=‹localhost:26257›,class=system,rpc] 1766  closing connection after: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
I230620 04:00:48.259791 313 rpc/context.go:2313 ⋮ [T1,n2,rnode=?,raddr=‹localhost:26257›,class=system,rpc] 1767  connection heartbeat loop ended with err: grpc: ‹connection error: desc = "transport: error while dialing: connection interrupted (did the remote node shut down or are there networking issues?)"› [code 14/Unavailable]
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768  ‹[core]›‹[Channel #47 SubChannel #48] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹  "Addr": "localhost:26257",›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹  "ServerName": "localhost:26257",›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹  "Attributes": null,›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹  "BalancerAttributes": null,›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹  "Type": 0,›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹  "Metadata": null›
W230620 04:00:48.359238 366619 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1768 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:48.359284 366617 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1769  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.359334 366616 1@circuitbreaker/circuitbreaker.go:322 ⋮ [T1,n2] 1770  circuitbreaker: ‹rpc 127.0.0.1:26259 [n1]› tripped: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:48.359361 366616 1@circuitbreaker/circuitbreaker.go:447 ⋮ [T1,n2] 1771  circuitbreaker: ‹rpc 127.0.0.1:26259 [n1]› event: ‹BreakerTripped›
W230620 04:00:48.359367 366616 2@rpc/nodedialer/nodedialer.go:196 ⋮ [T1,n2] 1772  unable to connect to n1: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773  ‹[core]›‹[Channel #49 SubChannel #50] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹  "Addr": "localhost:26257",›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹  "ServerName": "localhost:26257",›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹  "Attributes": null,›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹  "BalancerAttributes": null,›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹  "Type": 0,›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹  "Metadata": null›
W230620 04:00:49.179296 366819 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1773 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:49.179399 366561 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1774  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:49.179423 366561 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1775  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776  ‹[core]›‹[Channel #51 SubChannel #52] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹  "Addr": "localhost:26257",›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹  "ServerName": "localhost:26257",›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹  "Attributes": null,›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹  "BalancerAttributes": null,›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹  "Type": 0,›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹  "Metadata": null›
W230620 04:00:49.638590 366672 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1776 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:49.638650 366670 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1777  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778  ‹[core]›‹[Channel #53 SubChannel #54] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹  "Addr": "localhost:26257",›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹  "ServerName": "localhost:26257",›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹  "Attributes": null,›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹  "BalancerAttributes": null,›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹  "Type": 0,›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹  "Metadata": null›
W230620 04:00:49.723561 366830 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1778 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:49.723632 366828 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1779  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780  ‹[core]›‹[Channel #55 SubChannel #56] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹  "Addr": "localhost:26257",›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹  "ServerName": "localhost:26257",›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹  "Attributes": null,›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹  "BalancerAttributes": null,›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹  "Type": 0,›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹  "Metadata": null›
W230620 04:00:50.639399 366751 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1780 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:50.639498 366749 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1781  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:50.639527 366749 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1782  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783  ‹[core]›‹[Channel #57 SubChannel #58] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹  "Addr": "localhost:26257",›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹  "ServerName": "localhost:26257",›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹  "Attributes": null,›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹  "BalancerAttributes": null,›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹  "Type": 0,›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹  "Metadata": null›
W230620 04:00:51.641004 366793 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1783 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:51.641100 366791 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1784  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:51.641125 366791 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1785  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786  ‹[core]›‹[Channel #59 SubChannel #60] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹  "Addr": "localhost:26257",›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹  "ServerName": "localhost:26257",›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹  "Attributes": null,›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹  "BalancerAttributes": null,›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹  "Type": 0,›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹  "Metadata": null›
W230620 04:00:53.580614 366896 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1786 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:53.580697 366894 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1787  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:53.580722 366894 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1788  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789  ‹[core]›‹[Channel #61 SubChannel #62] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹  "Addr": "localhost:26257",›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹  "ServerName": "localhost:26257",›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹  "Attributes": null,›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹  "BalancerAttributes": null,›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹  "Type": 0,›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹  "Metadata": null›
W230620 04:00:53.642149 366801 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1789 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:53.642211 366799 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1790  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791  ‹[core]›‹[Channel #63 SubChannel #64] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹  "Addr": "localhost:26257",›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹  "ServerName": "localhost:26257",›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹  "Attributes": null,›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹  "BalancerAttributes": null,›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹  "Type": 0,›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹  "Metadata": null›
W230620 04:00:54.859346 366997 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1791 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:54.859444 366995 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1792  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:54.859469 366995 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1793  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794  ‹[core]›‹[Channel #65 SubChannel #66] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹  "Addr": "localhost:26257",›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹  "ServerName": "localhost:26257",›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹  "Attributes": null,›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹  "BalancerAttributes": null,›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹  "Type": 0,›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹  "Metadata": null›
W230620 04:00:56.358727 366934 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1794 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:56.358816 366932 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1795  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:56.358841 366932 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1796  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
W230620 04:00:56.830445 199 server/node.go:1075 ⋮ [T1,n2,summaries] 1797  health alerts detected: {Alerts:[{StoreID:2 Category:‹METRICS› Description:‹ranges.underreplicated› Value:34}]}
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798  ‹[core]›‹[Channel #67 SubChannel #68] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹  "Addr": "localhost:26257",›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹  "ServerName": "localhost:26257",›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹  "Attributes": null,›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹  "BalancerAttributes": null,›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹  "Type": 0,›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹  "Metadata": null›
W230620 04:00:57.644409 367093 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1798 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:57.644496 367091 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1799  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:57.644519 367091 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1800  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:57.644549 1786 kv/kvserver/closedts/sidetransport/sender.go:795 ⋮ [T1,n2,ctstream=1] 1801  side-transport failed to connect to n1: failed to connect to n1 at ‹localhost:26257›: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:58.483395 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r3/2:‹/System/{NodeLive…-tsd}›,raft] 1802  slow non-blocking raft commit: commit-wait 521.596602ms sem 454ns
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803  ‹[core]›‹[Channel #69 SubChannel #70] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹  "Addr": "localhost:26257",›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹  "ServerName": "localhost:26257",›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹  "Attributes": null,›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹  "BalancerAttributes": null,›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹  "Type": 0,›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹  "Metadata": null›
W230620 04:00:58.583123 367112 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1803 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
I230620 04:00:58.583168 367110 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=default,rpc] 1804  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:58.991105 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r4/2:‹/System/tsd{-/cr.nod…}›,raft] 1805  slow non-blocking raft commit: commit-wait 333.559645ms wal-q 400.287312ms sem 676ns
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806  ‹[core]›‹[Channel #71 SubChannel #72] grpc: addrConn.createTransport failed to connect to {›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹  "Addr": "localhost:26257",›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹  "ServerName": "localhost:26257",›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹  "Attributes": null,›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹  "BalancerAttributes": null,›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹  "Type": 0,›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹  "Metadata": null›
W230620 04:00:59.359088 367159 google.golang.org/grpc/grpclog/component.go:41 ⋮ [-] 1806 +‹}. Err: connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"›
E230620 04:00:59.359180 367157 2@rpc/context.go:2399 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1807  unable to connect (is the peer up and reachable?): initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:59.359204 367157 rpc/context.go:2313 ⋮ [T1,n2,rnode=1,raddr=‹localhost:26257›,class=system,rpc] 1808  connection heartbeat loop ended with err: initial connection heartbeat failed: grpc: ‹connection error: desc = "transport: error while dialing: dial tcp [::1]:26257: connect: connection refused"› [code 14/Unavailable]
I230620 04:00:59.644847 429 kv/kvserver/replica_raft.go:1531 ⋮ [T1,n2,s2,r95/2:‹/System/tsd/cr.node.{re…-sq…}›,raft] 1809  slow non-blocking raft commit: commit-wait 653.584581ms sem 540ns
W230620 04:04:00.042230 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 2019  slow heartbeat took 1.315931668s; err=<nil>
W230620 05:04:00.238372 457 kv/kvserver/liveness/liveness.go:908 ⋮ [T1,n2,liveness-hb] 5515  slow heartbeat took 1.421175236s; err=<nil>