Warnings on graceful quit running v2.1.0-beta.20181015


(James Hartig) #1

We are running v2.1.0-beta.20181015 and are in the process of upgrading to v2.1.0-rc.1 but after calling cockroach quit from a remote node the node shutting down printed out a bunch of warnings and I wanted to see if these were expected or if I should file a bug. This instance has
--advertise-addr royal.node.gce-europe-west2.admiral:26257 so I’m not sure why the first warning talked about it reconnecting to itself?

Oct 23 16:21:04 royal cockroach[28709]: I181023 16:21:04.754108 32619628 storage/store.go:1224  [drain] waiting for 17 replicas to transfer their lease away
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.092017 63 vendor/google.golang.org/grpc/clientconn.go:1293  grpc: addrConn.createTransport failed to connect to {royal.node.gce-europe-west2.admiral:26257 0  <nil>}. Err :connection error: desc = "transport: authentication handshake failed: io: read/write on closed pipe". Reconnecting...
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.093523 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 17     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.095364 63 vendor/google.golang.org/grpc/clientconn.go:1429  grpc: addrConn.transportMonitor exits due to: context canceled
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.096268 28538264 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 17: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.097195 31827214 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 6: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.098127 26972394 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 10: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.098900 12941818 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 7: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.099625 1412893 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 2: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.100452 15598375 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 12: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.101220 13184273 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 5: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.101932 3390349 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 16: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.103223 28147949 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 8: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.105261 13911880 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 18: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.105501 508463 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 11: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.106370 28185404 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 3: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.107043 16925098 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 1: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.107835 22327723 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 9: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.108533 13565681 storage/raft_transport.go:583  [n13] while processing outgoing Raft queue to node 4: rpc error: code = Canceled desc = grpc: the client connection is closing:
Oct 23 16:21:05 royal cockroach[28709]: W181023 16:21:05.109163 69 gossip/gossip.go:1499  [n13] no incoming or outgoing connections
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.109939 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 16     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.111485 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 15     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113007 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 14     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113112 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 13     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113131 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 12     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113175 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 11     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113196 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 10     [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113212 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 9      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113225 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 8      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113664 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 7      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.113861 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 6      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.114053 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 5      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.114069 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 4      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.114211 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 3      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.114235 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 2      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-rangefeed-subscriber
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.114414 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 2      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.114433 32621349 util/stop/stopper.go:537  quiescing; tasks left:
Oct 23 16:21:05 royal cockroach[28709]: 1      [async] closedts-subscription
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.120966 32621349 storage/engine/rocksdb.go:707  closing rocksdb instance at "/opt/data/1/cockroachdb/cockroach-temp211471298"
Oct 23 16:21:05 royal cockroach[28709]: I181023 16:21:05.121667 32621349 storage/engine/rocksdb.go:707  closing rocksdb instance at "/opt/data/1/cockroachdb"
Oct 23 16:21:11 royal systemd[1]: cockroachdb.service holdoff time over, scheduling restart.
Oct 23 16:21:11 royal systemd[1]: Starting cockroachdb...

We have server.shutdown.drain_wait set to 10 seconds.


(Ben Darnell) #2

That logging is a little noisy, but I don’t see any problems there. We’re working on improving our logging in the next release cycle.


(James Hartig) #3

Good to know! Thanks for checking it out and looking forward to the next release then :wink: