关闭程序顺序不当导致无法关闭 kafka
1. 报错如下
1.1 日志如下
[2018-12-22 08:59:39,405] INFO Opening socket connection to server server5/192.168.211.5:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:39,407] INFO Socket error occurred: server5/192.168.211.5:2181: Connection refused (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:39,927] INFO Opening socket connection to server server6/192.168.211.6:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:39,927] INFO Socket error occurred: server6/192.168.211.6:2181: Connection refused (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:41,281] INFO Opening socket connection to server server4/192.168.211.4:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:41,281] INFO Socket connection established to server4/192.168.211.4:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:41,282] INFO Unable to read additional data from server sessionid 0x500000208e80005, likely server has closed socket, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:42,268] INFO Opening socket connection to server server5/192.168.211.5:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:42,269] INFO Socket connection established to server5/192.168.211.5:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:42,274] INFO Unable to read additional data from server sessionid 0x500000208e80005, likely server has closed socket, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:43,216] INFO Opening socket connection to server server6/192.168.211.6:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:43,216] INFO Socket error occurred: server6/192.168.211.6:2181: Connection refused (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:44,323] INFO Opening socket connection to server server4/192.168.211.4:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:44,323] INFO Socket connection established to server4/192.168.211.4:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:44,335] INFO Session establishment complete on server server4/192.168.211.4:2181, sessionid = 0x500000208e80005, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
···
1.2 原因
因为笔者尝试了一次先关闭zookeeper,然后关闭kafka,接着kafka就报无法连接的错误。如果此时再开启zookeeper,日志输出如下:
[2018-12-22 08:59:44,335] INFO [ZooKeeperClient] Connected. (kafka.zookeeper.ZooKeeperClient)
[2018-12-22 08:59:44,584] INFO [KafkaServer id=0] Controlled shutdown succeeded (kafka.server.KafkaServer)
[2018-12-22 08:59:44,590] INFO [/config/changes-event-process-thread]: Shutting down (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread)
[2018-12-22 08:59:44,597] INFO [/config/changes-event-process-thread]: Stopped (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread)
[2018-12-22 08:59:44,597] INFO [/config/changes-event-process-thread]: Shutdown completed (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread)
[2018-12-22 08:59:44,600] INFO [SocketServer brokerId=0] Stopping socket server request processors (kafka.network.SocketServer)
[2018-12-22 08:59:44,614] INFO [SocketServer brokerId=0] Stopped socket server request processors (kafka.network.SocketServer)
[2018-12-22 08:59:44,616] INFO [Kafka Request Handler on Broker 0], shutting down (kafka.server.KafkaRequestHandlerPool)
[2018-12-22 08:59:44,656] INFO [Kafka Request Handler on Broker 0], shut down completely (kafka.server.KafkaRequestHandlerPool)
[2018-12-22 08:59:44,669] INFO [KafkaApi-0] Shutdown complete. (kafka.server.KafkaApis)
[2018-12-22 08:59:44,671] INFO [ExpirationReaper-0-topic]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:44,840] INFO [ExpirationReaper-0-topic]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:44,840] INFO [ExpirationReaper-0-topic]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:44,858] INFO [TransactionCoordinator id=0] Shutting down. (kafka.coordinator.transaction.TransactionCoordinator)
[2018-12-22 08:59:44,864] INFO [ProducerId Manager 0]: Shutdown complete: last producerId assigned 0 (kafka.coordinator.transaction.ProducerIdManager)
[2018-12-22 08:59:44,867] INFO [Transaction State Manager 0]: Shutdown complete (kafka.coordinator.transaction.TransactionStateManager)
[2018-12-22 08:59:44,867] INFO [Transaction Marker Channel Manager 0]: Shutting down (kafka.coordinator.transaction.TransactionMarkerChannelManager)
[2018-12-22 08:59:44,867] INFO [Transaction Marker Channel Manager 0]: Stopped (kafka.coordinator.transaction.TransactionMarkerChannelManager)
[2018-12-22 08:59:44,867] INFO [Transaction Marker Channel Manager 0]: Shutdown completed (kafka.coordinator.transaction.TransactionMarkerChannelManager)
[2018-12-22 08:59:44,869] INFO [TransactionCoordinator id=0] Shutdown complete. (kafka.coordinator.transaction.TransactionCoordinator)
[2018-12-22 08:59:44,871] INFO [GroupCoordinator 0]: Shutting down. (kafka.coordinator.group.GroupCoordinator)
[2018-12-22 08:59:44,871] INFO [ExpirationReaper-0-Heartbeat]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,041] INFO [ExpirationReaper-0-Heartbeat]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,041] INFO [ExpirationReaper-0-Heartbeat]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,041] INFO [ExpirationReaper-0-Rebalance]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,328] INFO [ExpirationReaper-0-Rebalance]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,329] INFO [ExpirationReaper-0-Rebalance]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,339] INFO [GroupCoordinator 0]: Shutdown complete. (kafka.coordinator.group.GroupCoordinator)
[2018-12-22 08:59:45,673] INFO [ReplicaManager broker=0] Shutting down (kafka.server.ReplicaManager)
[2018-12-22 08:59:45,674] INFO [LogDirFailureHandler]: Shutting down (kafka.server.ReplicaManager$LogDirFailureHandler)
[2018-12-22 08:59:45,675] INFO [LogDirFailureHandler]: Stopped (kafka.server.ReplicaManager$LogDirFailureHandler)
[2018-12-22 08:59:45,676] INFO [LogDirFailureHandler]: Shutdown completed (kafka.server.ReplicaManager$LogDirFailureHandler)
[2018-12-22 08:59:45,677] INFO [ReplicaFetcherManager on broker 0] shutting down (kafka.server.ReplicaFetcherManager)
[2018-12-22 08:59:45,681] INFO [ReplicaFetcherManager on broker 0] shutdown completed (kafka.server.ReplicaFetcherManager)
[2018-12-22 08:59:45,682] INFO [ReplicaAlterLogDirsManager on broker 0] shutting down (kafka.server.ReplicaAlterLogDirsManager)
[2018-12-22 08:59:45,683] INFO [ReplicaAlterLogDirsManager on broker 0] shutdown completed (kafka.server.ReplicaAlterLogDirsManager)
[2018-12-22 08:59:45,683] INFO [ExpirationReaper-0-Fetch]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,874] INFO [ExpirationReaper-0-Fetch]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,874] INFO [ExpirationReaper-0-Fetch]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:45,874] INFO [ExpirationReaper-0-Produce]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:46,075] INFO [ExpirationReaper-0-Produce]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:46,075] INFO [ExpirationReaper-0-Produce]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:46,075] INFO [ExpirationReaper-0-DeleteRecords]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:46,277] INFO [ExpirationReaper-0-DeleteRecords]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:46,277] INFO [ExpirationReaper-0-DeleteRecords]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2018-12-22 08:59:46,279] INFO [ReplicaManager broker=0] Shut down completely (kafka.server.ReplicaManager)
[2018-12-22 08:59:46,312] INFO Shutting down. (kafka.log.LogManager)
[2018-12-22 08:59:46,430] INFO [ProducerStateManager partition=__consumer_offsets-30] Writing producer snapshot at offset 1151 (kafka.log.ProducerStateManager)
[2018-12-22 08:59:47,008] INFO [ProducerStateManager partition=__consumer_offsets-31] Writing producer snapshot at offset 3 (kafka.log.ProducerStateManager)
[2018-12-22 08:59:47,069] INFO [ProducerStateManager partition=dblab-0] Writing producer snapshot at offset 70 (kafka.log.ProducerStateManager)
[2018-12-22 08:59:47,321] INFO [ProducerStateManager partition=__consumer_offsets-20] Writing producer snapshot at offset 3 (kafka.log.ProducerStateManager)
[2018-12-22 08:59:47,439] INFO [ProducerStateManager partition=__consumer_offsets-5] Writing producer snapshot at offset 3 (kafka.log.ProducerStateManager)
[2018-12-22 08:59:48,072] INFO Shutdown complete. (kafka.log.LogManager)
[2018-12-22 08:59:48,100] INFO [ZooKeeperClient] Closing. (kafka.zookeeper.ZooKeeperClient)
[2018-12-22 08:59:48,108] INFO Session: 0x500000208e80005 closed (org.apache.zookeeper.ZooKeeper)
[2018-12-22 08:59:48,109] INFO EventThread shut down for session: 0x500000208e80005 (org.apache.zookeeper.ClientCnxn)
[2018-12-22 08:59:48,114] INFO [ZooKeeperClient] Closed. (kafka.zookeeper.ZooKeeperClient)
[2018-12-22 08:59:48,122] INFO [ThrottledChannelReaper-Fetch]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:48,691] INFO [ThrottledChannelReaper-Fetch]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:48,692] INFO [ThrottledChannelReaper-Fetch]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:48,692] INFO [ThrottledChannelReaper-Produce]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:49,693] INFO [ThrottledChannelReaper-Produce]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:49,693] INFO [ThrottledChannelReaper-Produce]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:49,693] INFO [ThrottledChannelReaper-Request]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:50,694] INFO [ThrottledChannelReaper-Request]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:50,694] INFO [ThrottledChannelReaper-Request]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2018-12-22 08:59:50,721] INFO [SocketServer brokerId=0] Shutting down socket server (kafka.network.SocketServer)
[2018-12-22 08:59:50,798] INFO [SocketServer brokerId=0] Shutdown completed (kafka.network.SocketServer)
[2018-12-22 08:59:50,881] INFO [KafkaServer id=0] shut down completed (kafka.server.KafkaServer)
可以看到kafka此时已经正确关闭了。