Skip to content

Commit

Permalink
[fix][java-client] Fix performance regression with message listener (#…
Browse files Browse the repository at this point in the history
…15162)

#13023 has introduced a performance regression.
For each message, we are switching from external thread pool -> internal thread poll -> external thread pool.

Previously we want to control the outstanding messages of a consumer using a listener, so after #11455,
the message will not move from the receiver queue to the external executor. And #13023 changed the listener trigger
in the internal thread pool to fix the ordering issue, so this is the root cause of the performance regression.

Here is the frame graph to show the thread frame of the internal thread and external thread.
[framegraph.html.txt](https://github.com/apache/pulsar/files/8483765/framegraph.html.txt)

And also fix the performance issue for multiple topic consumers and key-shared subscriptions which enabled message listeners. Before this change, the messages are processed serially. After this change, We can improve parallelism on the premise of ensuring order.

- Remove the isListenerHandlingMessage control
- Move the messages from the receiver queue to the queue of external executor but not increase permits
- Increase permits before call message listener

(cherry picked from commit 83cd791)
  • Loading branch information
codelipenghui committed Apr 20, 2022
1 parent 779605b commit c712441
Show file tree
Hide file tree
Showing 6 changed files with 46 additions and 27 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -116,6 +116,7 @@ static class RawConsumerImpl extends ConsumerImpl<byte[]> {
client.externalExecutorProvider(),
TopicName.getPartitionIndex(conf.getSingleTopic()),
false,
false,
consumerFuture,
MessageId.earliest,
0 /* startMessageRollbackDurationInSec */,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,6 @@ public abstract class ConsumerBase<T> extends HandlerState implements Consumer<T
protected volatile long incomingMessagesSize = 0;
protected volatile Timeout batchReceiveTimeout = null;
protected final Lock reentrantLock = new ReentrantLock();
private volatile boolean isListenerHandlingMessage = false;

protected ConsumerBase(PulsarClientImpl client, String topic, ConsumerConfigurationData<T> conf,
int receiverQueueSize, ExecutorProvider executorProvider,
Expand Down Expand Up @@ -913,33 +912,34 @@ protected void tryTriggerListener() {
}

private void triggerListener() {
// The messages are added into the receiver queue by the internal pinned executor,
// so need to use internal pinned executor to avoid race condition which message
// might be added into the receiver queue but not able to read here.
internalPinnedExecutor.execute(() -> {
try {
// Listener should only have one pending/running executable to process a message
// See https://github.com/apache/pulsar/issues/11008 for context.
if (!isListenerHandlingMessage) {
final Message<T> msg = internalReceive(0, TimeUnit.MILLISECONDS);
Message<T> msg;
do {
msg = internalReceive(0, TimeUnit.MILLISECONDS);
if (msg != null) {
isListenerHandlingMessage = true;
// Trigger the notification on the message listener in a separate thread to avoid blocking the
// internal pinned executor thread while the message processing happens
final Message<T> finalMsg = msg;
if (SubscriptionType.Key_Shared == conf.getSubscriptionType()) {
executorProvider.getExecutor(peekMessageKey(msg)).execute(() ->
callMessageListener(msg));
callMessageListener(finalMsg));
} else {
getExternalExecutor(msg).execute(() -> {
callMessageListener(msg);
callMessageListener(finalMsg);
});
}
} else {
if (log.isDebugEnabled()) {
log.debug("[{}] [{}] Message has been cleared from the queue", topic, subscription);
}
}
}
} while (msg != null);
} catch (PulsarClientException e) {
log.warn("[{}] [{}] Failed to dequeue the message for listener", topic, subscription, e);
return;
}

if (log.isDebugEnabled()) {
log.debug("[{}] [{}] Message has been cleared from the queue", topic, subscription);
}
});
}
Expand All @@ -950,13 +950,16 @@ protected void callMessageListener(Message<T> msg) {
log.debug("[{}][{}] Calling message listener for message {}", topic, subscription,
msg.getMessageId());
}
ConsumerImpl receivedConsumer = (msg instanceof TopicMessageImpl)
? ((TopicMessageImpl<T>) msg).receivedByconsumer : (ConsumerImpl) this;
// Increase the permits here since we will not increase permits while receive messages from consumer
// after enabled message listener.
receivedConsumer.increaseAvailablePermits((MessageImpl<?>) (msg instanceof TopicMessageImpl
? ((TopicMessageImpl<T>) msg).getMessage() : msg));
listener.received(ConsumerBase.this, msg);
} catch (Throwable t) {
log.error("[{}][{}] Message listener error in processing message: {}", topic, subscription,
msg.getMessageId(), t);
} finally {
isListenerHandlingMessage = false;
triggerListener();
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -128,6 +128,7 @@ public class ConsumerImpl<T> extends ConsumerBase<T> implements ConnectionHandle
private final long subscribeTimeout;
private final int partitionIndex;
private final boolean hasParentConsumer;
private final boolean parentConsumerHasListener;

private final int receiverQueueRefillThreshold;

Expand Down Expand Up @@ -202,8 +203,8 @@ static <T> ConsumerImpl<T> newConsumerImpl(PulsarClientImpl client,
Schema<T> schema,
ConsumerInterceptors<T> interceptors,
boolean createTopicIfDoesNotExist) {
return newConsumerImpl(client, topic, conf, executorProvider, partitionIndex, hasParentConsumer, subscribeFuture,
startMessageId, schema, interceptors, createTopicIfDoesNotExist, 0);
return newConsumerImpl(client, topic, conf, executorProvider, partitionIndex, hasParentConsumer, false,
subscribeFuture, startMessageId, schema, interceptors, createTopicIfDoesNotExist, 0);
}

static <T> ConsumerImpl<T> newConsumerImpl(PulsarClientImpl client,
Expand All @@ -212,6 +213,7 @@ static <T> ConsumerImpl<T> newConsumerImpl(PulsarClientImpl client,
ExecutorProvider executorProvider,
int partitionIndex,
boolean hasParentConsumer,
boolean parentConsumerHasListener,
CompletableFuture<Consumer<T>> subscribeFuture,
MessageId startMessageId,
Schema<T> schema,
Expand All @@ -225,14 +227,16 @@ static <T> ConsumerImpl<T> newConsumerImpl(PulsarClientImpl client,
createTopicIfDoesNotExist);
} else {
return new ConsumerImpl<>(client, topic, conf, executorProvider, partitionIndex, hasParentConsumer,
subscribeFuture, startMessageId, startMessageRollbackDurationInSec /* rollback time in sec to start msgId */,
parentConsumerHasListener,
subscribeFuture, startMessageId,
startMessageRollbackDurationInSec /* rollback time in sec to start msgId */,
schema, interceptors, createTopicIfDoesNotExist);
}
}

protected ConsumerImpl(PulsarClientImpl client, String topic, ConsumerConfigurationData<T> conf,
ExecutorProvider executorProvider, int partitionIndex, boolean hasParentConsumer,
CompletableFuture<Consumer<T>> subscribeFuture, MessageId startMessageId,
boolean parentConsumerHasListener, CompletableFuture<Consumer<T>> subscribeFuture, MessageId startMessageId,
long startMessageRollbackDurationInSec, Schema<T> schema, ConsumerInterceptors<T> interceptors,
boolean createTopicIfDoesNotExist) {
super(client, topic, conf, conf.getReceiverQueueSize(), executorProvider, subscribeFuture, schema, interceptors);
Expand All @@ -246,6 +250,7 @@ protected ConsumerImpl(PulsarClientImpl client, String topic, ConsumerConfigurat
this.partitionIndex = partitionIndex;
this.hasParentConsumer = hasParentConsumer;
this.receiverQueueRefillThreshold = conf.getReceiverQueueSize() / 2;
this.parentConsumerHasListener = parentConsumerHasListener;
this.priorityLevel = conf.getPriorityLevel();
this.readCompacted = conf.isReadCompacted();
this.subscriptionInitialPosition = conf.getSubscriptionInitialPosition();
Expand Down Expand Up @@ -1342,7 +1347,9 @@ protected synchronized void messageProcessed(Message<?> msg) {
if (msgCnx != currentCnx) {
// The processed message did belong to the old queue that was cleared after reconnection.
} else {
increaseAvailablePermits(currentCnx);
if (listener == null && !parentConsumerHasListener) {
increaseAvailablePermits(currentCnx);
}
stats.updateNumMsgsReceived(msg);

trackMessage(msg);
Expand Down Expand Up @@ -1373,6 +1380,14 @@ protected void trackMessage(MessageId messageId) {
}
}

void increaseAvailablePermits(MessageImpl<?> msg) {
ClientCnx currentCnx = cnx();
ClientCnx msgCnx = msg.getCnx();
if (msgCnx == currentCnx) {
increaseAvailablePermits(currentCnx);
}
}

void increaseAvailablePermits(ClientCnx currentCnx) {
increaseAvailablePermits(currentCnx, 1);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -975,7 +975,7 @@ private void doSubscribeTopicPartitions(Schema<T> schema,
CompletableFuture<Consumer<T>> subFuture = new CompletableFuture<>();
ConsumerImpl<T> newConsumer = ConsumerImpl.newConsumerImpl(client, partitionName,
configurationData, client.externalExecutorProvider(),
partitionIndex, true, subFuture,
partitionIndex, true, listener != null, subFuture,
startMessageId, schema, interceptors,
createIfDoesNotExist, startMessageRollbackDurationInSec);
synchronized (pauseMutex) {
Expand All @@ -1002,7 +1002,7 @@ private void doSubscribeTopicPartitions(Schema<T> schema,
} else {
ConsumerImpl<T> newConsumer = ConsumerImpl.newConsumerImpl(client, topicName, internalConfig,
client.externalExecutorProvider(), -1,
true, subFuture, startMessageId, schema, interceptors,
true, listener != null, subFuture, startMessageId, schema, interceptors,
createIfDoesNotExist, startMessageRollbackDurationInSec);

synchronized (pauseMutex) {
Expand Down Expand Up @@ -1298,7 +1298,7 @@ private CompletableFuture<Void> subscribeIncreasedTopicPartitions(String topicNa
ConsumerImpl<T> newConsumer = ConsumerImpl.newConsumerImpl(
client, partitionName, configurationData,
client.externalExecutorProvider(),
partitionIndex, true, subFuture, startMessageId, schema, interceptors,
partitionIndex, true, listener != null, subFuture, startMessageId, schema, interceptors,
true /* createTopicIfDoesNotExist */, startMessageRollbackDurationInSec);
synchronized (pauseMutex) {
if (paused) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -103,7 +103,7 @@ public void reachedEndOfTopic(Consumer<T> consumer) {

final int partitionIdx = TopicName.getPartitionIndex(readerConfiguration.getTopicName());
consumer = new ConsumerImpl<>(client, readerConfiguration.getTopicName(), consumerConfiguration,
executorProvider, partitionIdx, false, consumerFuture,
executorProvider, partitionIdx, false, false, consumerFuture,
readerConfiguration.getStartMessageId(), readerConfiguration.getStartMessageFromRollbackDurationInSec(),
schema, null, true /* createTopicIfDoesNotExist */);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -53,7 +53,7 @@ public ZeroQueueConsumerImpl(PulsarClientImpl client, String topic, ConsumerConf
CompletableFuture<Consumer<T>> subscribeFuture, MessageId startMessageId, Schema<T> schema,
ConsumerInterceptors<T> interceptors,
boolean createTopicIfDoesNotExist) {
super(client, topic, conf, executorProvider, partitionIndex, hasParentConsumer, subscribeFuture,
super(client, topic, conf, executorProvider, partitionIndex, hasParentConsumer, false, subscribeFuture,
startMessageId, 0 /* startMessageRollbackDurationInSec */, schema, interceptors,
createTopicIfDoesNotExist);
}
Expand Down

0 comments on commit c712441

Please sign in to comment.