zbye opened a new issue, #16140:
URL: https://github.com/apache/pulsar/issues/16140
**Describe the bug**
**One Broker shutdown with the following logs :**
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] INFO
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Un-fencing topic...
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[gmtp_cffex/SF_test/persistent/bar] Managed ledger is now ready to accept
writes again
2022-06-17T13:27:16,824+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://gmtp_cffex/SF_test/bar] Failed to persist msg in store: Error
while using ZooKeeper
2022-06-17T13:27:16,825+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.bookkeeper.meta.AbstractZkLedgerManager - Conditional update ledger
metadata failed: SESSIONEXPIRED
2022-06-17T13:27:16,825+0800 [main-SendThread(10.187.128.229:2181)] ERROR
org.apache.bookkeeper.client.MetadataUpdateLoop -
UpdateLoop(ledgerId=135600,loopId=4f19d4e3) Error writing metadata to store
org.apache.bookkeeper.client.BKException$ZKException: Error while using
ZooKeeper
at
org.apache.bookkeeper.meta.AbstractZkLedgerManager$4.processResult(AbstractZkLedgerManager.java:509)
[org.apache.bookkeeper-bookkeeper-server-4.14.4.jar:4.14.4]
at
org.apache.bookkeeper.zookeeper.ZooKeeperClient$22$1.processResult(ZooKeeperClient.java:1094)
[org.apache.bookkeeper-bookkeeper-server-4.14.4.jar:4.14.4]
at
org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:638)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at
org.apache.zookeeper.ClientCnxn$EventThread.queuePacket(ClientCnxn.java:541)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxn.finishPacket(ClientCnxn.java:781)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxn.conLossPacket(ClientCnxn.java:818)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxn.access$2600(ClientCnxn.java:106)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at
org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1403)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at
org.apache.zookeeper.ClientCnxn$SendThread.cleanAndNotifyState(ClientCnxn.java:1331)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1309)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /ledgers/00/0013/L5600
at
org.apache.zookeeper.KeeperException.create(KeeperException.java:134)
~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.KeeperException.create(KeeperException.java:54)
~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
... 10 more
2022-06-17T13:27:16,825+0800 [main-SendThread(10.187.128.229:2181)] WARN
org.apache.bookkeeper.client.LedgerHandle - Close failed: ZKException: Error
while using ZooKeeper
2022-06-17T13:27:16,988+0800 [ZKC-connect-executor-0-EventThread] INFO
org.apache.bookkeeper.discover.ZKRegistrationClient - Update BookieInfoCache
(writable bookie) 10.187.128.232:3181 -> BookieServiceInfo{properties={},
endpoints=[EndpointInfo{id=bookie, port=3181, host=10.187.128.232,
protocol=bookie-rpc, auth=[], extensions=[]}]}
2022-06-17T13:27:16,988+0800 [ZKC-connect-executor-0-EventThread] INFO
org.apache.bookkeeper.discover.ZKRegistrationClient - Update BookieInfoCache
(writable bookie) 10.187.128.231:3181 -> BookieServiceInfo{properties={},
endpoints=[EndpointInfo{id=bookie, port=3181, host=10.187.128.231,
protocol=bookie-rpc, auth=[], extensions=[]}]}
2022-06-17T13:27:16,989+0800 [ZKC-connect-executor-0-EventThread] INFO
org.apache.bookkeeper.discover.ZKRegistrationClient - Update BookieInfoCache
(writable bookie) 10.187.128.230:3181 -> BookieServiceInfo{properties={},
endpoints=[EndpointInfo{id=bookie, port=3181, host=10.187.128.230,
protocol=bookie-rpc, auth=[], extensions=[]}]}
2022-06-17T13:27:17,015+0800 [main-SendThread(10.187.128.227:2181)] INFO
org.apache.zookeeper.ClientCnxn - Opening socket connection to server
10.187.128.227/10.187.128.227:2181.
2022-06-17T13:27:17,015+0800 [main-SendThread(10.187.128.227:2181)] INFO
org.apache.zookeeper.ClientCnxn - SASL config status: Will not attempt to
authenticate using SASL (unknown error)
2022-06-17T13:27:17,015+0800 [main-SendThread(10.187.128.227:2181)] INFO
org.apache.zookeeper.ClientCnxn - Socket connection established, initiating
session, client: /10.187.128.226:49916, server:
10.187.128.227/10.187.128.227:2181
2022-06-17T13:27:17,020+0800 [main-SendThread(10.187.128.227:2181)] WARN
org.apache.zookeeper.ClientCnxn - Unable to reconnect to ZooKeeper service,
session 0x304454ce5fc006e has expired
2022-06-17T13:27:17,020+0800 [main-SendThread(10.187.128.227:2181)] WARN
org.apache.zookeeper.ClientCnxn - Session 0x304454ce5fc006e for sever
10.187.128.227/10.187.128.227:2181, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
org.apache.zookeeper.ClientCnxn$SessionExpiredException: Unable to reconnect
to ZooKeeper service, session 0x304454ce5fc006e has expired
at
org.apache.zookeeper.ClientCnxn$SendThread.onConnected(ClientCnxn.java:1434)
~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at
org.apache.zookeeper.ClientCnxnSocket.readConnectResult(ClientCnxnSocket.java:154)
~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at
org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:86)
~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1290)
[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
2022-06-17T13:27:17,331+0800 [pulsar-timer-52-1] INFO
org.apache.pulsar.client.impl.ConnectionHandler -
[public/__kafka/__consumer_offsets-partition-48] [pulsar-cluster-test-148-18]
Reconnecting after connection was closed
2022-06-17T13:27:17,591+0800 [BookKeeperClientWorker-OrderedExecutor-2-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[gmtp_cffex/SF_test/persistent/bar] Creating a new ledger
2022-06-17T13:27:17,592+0800 [BookKeeperClientWorker-OrderedExecutor-2-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[gmtp_cffex/SF_test/persistent/bar] Creating ledger, metadata: {component=[109,
97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114],
pulsar/managed-ledger=[103, 109, 116, 112, 95, 99, 102, 102, 101, 120, 47, 83,
70, 95, 116, 101, 115, 116, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110,
116, 47, 98, 97, 114], application=[112, 117, 108, 115, 97, 114]} - metadata
ops timeout : 60 seconds
2022-06-17T13:27:17,592+0800 [BookKeeperClientWorker-OrderedExecutor-2-0]
WARN org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl -
Failed to find 2 bookies : excludeBookies [<Bookie:10.187.128.232:3181>,
<Bookie:10.187.128.231:3181>, <Bookie:10.187.128.230:3181>], allBookies
[<Bookie:10.187.128.232:3181>, <Bookie:10.187.128.230:3181>,
<Bookie:10.187.128.231:3181>].
2022-06-17T13:27:17,592+0800 [BookKeeperClientWorker-OrderedExecutor-2-0]
WARN org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[10.187.128.232:3181, 10.187.128.231:3181] is not adhering to Placement Policy
2022-06-17T13:27:17,599+0800 [ZKC-connect-executor-0-EventThread] INFO
org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [10.187.128.232:3181,
10.187.128.231:3181] for ledger: 135693
2022-06-17T13:27:17,600+0800 [ZKC-connect-executor-0-EventThread] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[gmtp_cffex/SF_test/persistent/bar] Created new ledger 135693
2022-06-17T13:27:18,053+0800 [metadata-store-zk-session-watcher-7-1] WARN
org.apache.pulsar.metadata.impl.ZKSessionWatcher - ZooKeeper client is
disconnected. Waiting to reconnect, time remaining = 22.988 seconds
2022-06-17T13:27:19,189+0800 [pulsar-web-37-7] INFO
org.eclipse.jetty.server.RequestLog - 10.187.98.151 - - [17/Jun/2022:13:27:19
+0800] "GET /metrics?format=prometheus HTTP/1.1" 302 0 "-" "Prometheus/2.16.0" 0
2022-06-17T13:27:19,248+0800 [prometheus-stats-38-1] INFO
org.eclipse.jetty.server.RequestLog - 10.187.98.151 - - [17/Jun/2022:13:27:19
+0800] "GET /metrics/?format=prometheus HTTP/1.1" 200 625724
"http://10.187.128.226:8080/metrics?format=prometheus"; "Prometheus/2.16.0" 58
2022-06-17T13:27:19,622+0800 [pulsar-timer-52-1] INFO
org.apache.pulsar.client.impl.ConnectionHandler -
[public/__kafka/__consumer_offsets-partition-40] [pulsar-cluster-test-148-8]
Reconnecting after connection was closed
2022-06-17T13:27:20,054+0800 [metadata-store-zk-session-watcher-7-1] WARN
org.apache.pulsar.metadata.impl.ZKSessionWatcher - ZooKeeper client is
disconnected. Waiting to reconnect, time remaining = 20.987 seconds
2022-06-17T13:27:21,966+0800 [pulsar-timer-52-1] INFO
org.apache.pulsar.client.impl.ConnectionHandler -
[public/__kafka/__consumer_offsets-partition-35] [pulsar-cluster-test-148-9]
Reconnecting after connection was closed
2022-06-17T13:27:22,054+0800 [metadata-store-zk-session-watcher-7-1] WARN
org.apache.pulsar.metadata.impl.ZKSessionWatcher - ZooKeeper client is
disconnected. Waiting to reconnect, time remaining = 18.987 seconds
2022-06-17T13:27:23,011+0800 [pulsar-timer-52-1] INFO
org.apache.pulsar.client.impl.ConnectionHandler -
[public/__kafka/__consumer_offsets-partition-25] [reader-fc21d8c429]
Reconnecting after connection was closed
2022-06-17T13:27:24,054+0800 [metadata-store-zk-session-watcher-7-1] WARN
org.apache.pulsar.metadata.impl.ZKSessionWatcher - ZooKeeper client is
disconnected. Waiting to reconnect, time remaining = 16.987 seconds
2022-06-17T13:27:24,189+0800 [pulsar-web-37-19] INFO
org.eclipse.jetty.server.RequestLog - 10.187.98.151 - - [17/Jun/2022:13:27:24
+0800] "GET /metrics?format=prometheus HTTP/1.1" 302 0 "-" "Prometheus/2.16.0" 0
2022-06-17T13:27:24,257+0800 [prometheus-stats-38-1] INFO
org.eclipse.jetty.server.RequestLog - 10.187.98.151 - - [17/Jun/2022:13:27:24
+0800] "GET /metrics/?format=prometheus HTTP/1.1" 200 625723
"http://10.187.128.226:8080/metrics?format=prometheus"; "Prometheus/2.16.0" 68
2022-06-17T13:27:25,455+0800 [pulsar-timer-52-1] INFO
org.apache.pulsar.client.impl.ConnectionHandler -
[public/__kafka/__consumer_offsets-partition-15] [reader-cf54e565f4]
Reconnecting after connection was closed
2022-06-17T13:27:26,055+0800 [metadata-store-zk-session-watcher-7-1] WARN
org.apache.pulsar.metadata.impl.ZKSessionWatcher - ZooKeeper client is
disconnected. Waiting to reconnect, time remaining = 14.986 seconds
2022-06-17T13:27:28,055+0800 [metadata-store-zk-session-watcher-7-1] WARN
org.apache.pulsar.metadata.impl.ZKSessionWatcher - ZooKeeper client is
disconnected. Waiting to reconnect, time remaining = 12.986 seconds
2022-06-17T13:27:29,189+0800 [pulsar-web-37-7] INFO
org.eclipse.jetty.server.RequestLog - 10.187.98.151 - - [17/Jun/2022:13:27:29
+0800] "GET /metrics?format=prometheus HTTP/1.1" 302 0 "-" "Prometheus/2.16.0" 1
2022-06-17T13:27:29,239+0800 [pulsar-timer-52-1] INFO
org.apache.pulsar.client.impl.ConnectionHandler - [public/__kafka/__consume
**To Reproduce**
This happens occasionally.
**Desktop (please complete the following information):**
CentOS Linux release 7.4.1708
**Additional context**
Pulsar 2.9.2
KoP 2.9.2.20
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
