You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2022/06/20 07:53:49 UTC
[GitHub] [pulsar] zbye opened a new issue, #16140: Broker often shutdown after using KoP
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: commits-unsubscribe@pulsar.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] github-actions[bot] commented on issue #16140: Broker often shutdown after using KoP
Posted by GitBox <gi...@apache.org>.
github-actions[bot] commented on issue #16140:
URL: https://github.com/apache/pulsar/issues/16140#issuecomment-1190958478
The issue had no activity for 30 days, mark with Stale label.
--
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: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] tisonkun commented on issue #16140: Broker often shutdown after using KoP
Posted by "tisonkun (via GitHub)" <gi...@apache.org>.
tisonkun commented on issue #16140:
URL: https://github.com/apache/pulsar/issues/16140#issuecomment-1519318017
I suggest you open an issue to https://github.com/streamnative/kop first and let the developers there to figure out whether it's a KoP issue or upstream Pulsar issue.
--
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: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] tisonkun closed issue #16140: Broker often shutdown after using KoP
Posted by "tisonkun (via GitHub)" <gi...@apache.org>.
tisonkun closed issue #16140: Broker often shutdown after using KoP
URL: https://github.com/apache/pulsar/issues/16140
--
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: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org