yufan022 edited a comment on issue #9227:
URL: https://github.com/apache/pulsar/issues/9227#issuecomment-767250312
Open debug log of `Broker` and `Debezium`.
```
// Debezium
02:22:49.000 [pulsar-client-io-7-1] DEBUG
org.apache.pulsar.client.impl.ClientCnx - [id: 0xca74dac6, L:/10.42.3.36:50100
-
R:pulsar-mini-broker-0.pulsar-mini-broker.pulsar.svc.cluster.local/10.42.3.36:6650]
Received a message from the server:
org.apache.pulsar.common.api.proto.PulsarApi$CommandMessage@a075ae2
02:22:49.000 [pulsar-client-io-7-1] DEBUG
org.apache.pulsar.client.impl.ConsumerImpl -
[public/3426/offset-topic][reader-86b2926c2c] Received message: 6/1999
02:22:49.000 [pulsar-client-io-7-1] DEBUG
org.apache.pulsar.client.impl.ConsumerImpl - [reader-86b2926c2c] [0d080]
processing message num - 0 in batch
02:22:49.000 [pulsar-client-io-7-1] DEBUG
org.apache.pulsar.client.impl.ConsumerImpl - [reader-86b2926c2c] [0d080]
enqueued messages in batch. queue size - 878, available queue size - 2147483647
...
02:23:17.730 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarDecoder - [localhost/127.0.0.1:6650]
Received cmd PING
02:23:17.730 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarHandler - [[id: 0x474729d9,
L:/127.0.0.1:38340 - R:localhost/127.0.0.1:6650]] Replying back to ping message
02:23:17.741 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarHandler - [[id: 0x474729d9,
L:/127.0.0.1:38340 - R:localhost/127.0.0.1:6650]] Sending ping message
02:23:17.744 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarDecoder - [localhost/127.0.0.1:6650]
Received cmd PONG
02:23:17.938 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarHandler - [[id: 0xd7d4d92a,
L:/10.42.3.36:50094 -
R:pulsar-mini-broker-0.pulsar-mini-broker.pulsar.svc.cluster.local/10.42.3.36:6650]]
Sending ping message
02:23:17.939 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarDecoder -
[pulsar-mini-broker-0.pulsar-mini-broker.pulsar.svc.cluster.local/10.42.3.36:6650]
Received cmd PONG
02:23:17.943 [pulsar-client-io-1-1] DEBUG
org.apache.pulsar.common.protocol.PulsarDecoder -
[pulsar-mini-broker-0.pulsar-mini-broker.pulsar.svc.cluster.local/10.42.3.36:6650]
Received cmd PING
...
02:23:48.318 [pulsar-client-io-7-1] DEBUG
org.apache.pulsar.common.protocol.PulsarHandler - [[id: 0xca74dac6,
L:/10.42.3.36:50100 -
R:pulsar-mini-broker-0.pulsar-mini-broker.pulsar.svc.cluster.local/10.42.3.36:6650]]
Replying back to ping message
02:23:48.442 [pulsar-timer-10-1] INFO
org.apache.pulsar.client.impl.ConsumerStatsRecorderImpl -
[public/3426/offset-topic] [reader-86b2926c2c] [0d080] Prefetched messages: 878
--- Consume throughput received: 18.70 msgs/s --- 0.03 Mbit/s --- Ack sent
rate: 0.00 ack/s --- Failed messages: 0 --- batch messages: 0 ---Failed acks: 0
// Broker
02:22:48.984 [pulsar-io-24-2] DEBUG
org.apache.pulsar.broker.service.PulsarCommandSenderImpl -
[persistent://public/3426/offset-topic-PersistentSubscription{topic=persistent://public/3426/offset-topic,
name=reader-86b2926c2c}] Sending message to consumerId 0, msg id 6-1996
02:22:48.984 [pulsar-io-24-2] DEBUG
org.apache.pulsar.broker.service.PulsarCommandSenderImpl -
[persistent://public/3426/offset-topic-PersistentSubscription{topic=persistent://public/3426/offset-topic,
name=reader-86b2926c2c}] Sending message to consumerId 0, msg id 6-1997
02:22:48.984 [pulsar-io-24-2] DEBUG
org.apache.pulsar.broker.service.PulsarCommandSenderImpl -
[persistent://public/3426/offset-topic-PersistentSubscription{topic=persistent://public/3426/offset-topic,
name=reader-86b2926c2c}] Sending message to consumerId 0, msg id 6-1998
02:22:48.984 [pulsar-io-24-2] DEBUG
org.apache.pulsar.broker.service.PulsarCommandSenderImpl -
[persistent://public/3426/offset-topic-PersistentSubscription{topic=persistent://public/3426/offset-topic,
name=reader-86b2926c2c}] Sending message to consumerId 0, msg id 6-1999
02:22:48.984 [broker-topic-workers-OrderedScheduler-4-0] DEBUG
org.apache.pulsar.broker.service.persistent.PersistentDispatcherSingleActiveConsumer
- [persistent://public/3426/offset-topic /
reader-86b2926c2c-Consumer{subscription=PersistentSubscription{topic=persistent://public/3426/offset-topic,
name=reader-86b2926c2c}, consumerId=0, consumerName=0d080,
address=/10.42.3.36:50100}] Consumer buffer is full, pause reading
02:22:50.014 [AsyncHttpClient-timer-57-1] DEBUG
org.asynchttpclient.netty.channel.DefaultChannelPool - Entry count for :
http://pulsar-mini-broker-0.pulsar-mini-broker.pulsar.svc.cluster.local:8080 : 1
02:22:50.689
[pulsar-ordered-OrderedExecutor-1-0-SendThread(pulsar-mini-zookeeper:2181)]
DEBUG org.apache.zookeeper.ClientCnxn - Reading reply
sessionid:0x104fca0f218003c, packet:: clientPath:/ serverPath:/ finished:false
header:: 319,3 replyHeader:: 319,4212,0 request:: '/,F response::
s{0,0,0,0,0,9,0,0,0,11,120}
```
When Debezium blocked, I found `...Consumer buffer is full, pause reading`
logs on Broker and `Flushing pending acks to...` on Debezium connector.
Then I have to restart `broker` to keep `Debezium` working.
https://github.com/apache/pulsar/blob/ed5d94ccfdf4eba77678454945a2c3719dce2268/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/persistent/PersistentDispatcherSingleActiveConsumer.java#L359
https://github.com/apache/pulsar/blob/ed5d94ccfdf4eba77678454945a2c3719dce2268/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/persistent/PersistentDispatcherSingleActiveConsumer.java#L457
@sijie @codelipenghui Could anyone help me work out this 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.
For queries about this service, please contact Infrastructure at:
[email protected]
