PubSubInboundChannelAdapter stops to receive messages after 4th message

Question

I've created simplified example which reproduces my real problem.

My example accepts from google pub/sub, logs it and send ack back to the Pub/Sub

Config:

@Slf4j
@Configuration
public class MyConfig implements FlowSupport {

    private final AppProperties properties;

    public MyConfig(AppProperties properties) {
        this.properties = properties;
    }

    @Bean
    public JacksonFactory jacksonFactory() {
        return JacksonFactory.getDefaultInstance();
    }
    @Bean
    public MessageChannel bucketNotificationChannel() {
        return MessageChannels.direct("input-notification-channel").get();
    }

    @Bean
    public PubSubInboundChannelAdapter messageChannelAdapter(PubSubTemplate template) {
        var adapter = new PubSubInboundChannelAdapter(template, properties.getBucketTopicSubscription());
        adapter.setOutputChannel(bucketNotificationChannel());
        adapter.setErrorChannel(errorChannel());
        adapter.setAckMode(AckMode.MANUAL);
        adapter.setPayloadType(Notification.class);
        return adapter;
    }

    @Bean
    @Override
    public MessageChannel idempotentDiscardChannel() {
        return MessageChannels.direct("idempotent-discard-channel").get();
    }

    @Bean
    public MessageChannel errorChannel() {
        return MessageChannels.direct("global-error-channel").get();
    }

    @Bean
    @Override
    public ConcurrentMetadataStore idempotencyStore() {
        return new SimpleMetadataStore();
    }

    @Bean
    public IntegrationFlow bucketNotificationFlow(
            EmptyNotificationHandler handler,
            IntegrationFlow acknowledgementFlow
    ) {
        return flow -> flow.channel(bucketNotificationChannel())
                .handle(handler)
                .log(INFO, "Handler finished", m -> {
                    return "got" + m;
                }).gateway(acknowledgementFlow);
    }

    @Bean
    public IntegrationFlow acknowledgementFlow(PubSubAckHandler handler) {
        return flow -> flow.log(DEBUG, "acknowledgementFlow", m -> "Handling acknowledgement for message: " + m)
                .handle(handler);
    }
}

NotificationHandler:

@Component
@Slf4j
public class EmptyNotificationHandler implements GenericHandler<Notification> {
    private final ResourceLoader loader;

    public EmptyNotificationHandler(ResourceLoader loader) {
        this.loader = loader;
    }

    @Override
    public Resource handle(Notification payload, MessageHeaders headers) {
        try {
            return new Resource() {
                @Override
                public boolean exists() {
                    return false;
                }    
                ...
            };

        } catch (Exception e) {
            log.error("Error occurred:", e);
            return null;
        }
    }
}

AckHandler:

@Component
public class MyPubSubAckHandler implements MessageHandler {

    private final ConcurrentMetadataStore idempotencyStore;


    public MyPubSubAckHandler(ConcurrentMetadataStore idempotencyStore, MeterRegistry meterRegistry) {
        this.idempotencyStore = idempotencyStore;
    }

    @Override
    public void handleMessage(@NonNull Message<?> message) throws MessagingException {
        Message<?> targetMessage = MessageUtils.unwrap(message);
        var pubSubMessage = getOriginalMessage(targetMessage);
        if (pubSubMessage == null) {
            removeFromIdempotentStore(targetMessage);               
            return;
        }
        var generation = targetMessage.getHeaders().get(OBJECT_GENERATION_HEADER);
        if (message instanceof ErrorMessage || message.getPayload() instanceof Throwable) {
            pubSubMessage.nack().addCallback(
                    v -> {
                        removeFromIdempotentStore(targetMessage);
                        log.error("Error message was nacked - {}", generation);
                    },
                    e -> {
                        removeFromIdempotentStore(targetMessage);
                        log.error("Failed to nack message {}", generation, e);
                    }
            );
        } else {
            pubSubMessage.ack().addCallback(
                    v -> {
                        removeFromIdempotentStore(targetMessage);
                        log.info("Acknowledged message - {}", generation);
                    },
                    e -> {
                        removeFromIdempotentStore(targetMessage);
                        log.error("Failed to acknowledge message - {}", generation, e);
                    }
            );
        }
    }

    @SuppressWarnings({"RedundantSuppression", "unchecked"}) //IDEMPOTENCY_HEADER has Set<String> underneath
    private void removeFromIdempotentStore(Message<?> targetMessage) {
        Optional.ofNullable(targetMessage.getHeaders().get(IDEMPOTENCY_HEADER, Set.class)).stream()
                .flatMap(Collection::stream)
                .forEach(key -> idempotencyStore.remove(String.valueOf(key)));
    }
}

When I send first message everything is ok - I see message in the log and ack is sent to pubsub. Also I see that amount of unacked messages on the gcp subcriptions page is 0.

But after several successful messages my application just stops to receive messages. I've wasted a lot of hours to debug and I was able to find out following:

Several threads hangs on line: org.springframework.messaging.core.GenericMessagingTemplate.TemporaryReplyChannel#receive(long):314

this.replyLatch.await();

ThreadDump:

"gcp-pubsub-subscriber1@7980" prio=5 tid=0x1e nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:885)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1039)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1345)
      at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232)
      at org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel.receive(GenericMessagingTemplate.java:314)
      at org.springframework.messaging.core.GenericMessagingTemplate$TemporaryReplyChannel.receive(GenericMessagingTemplate.java:306)
      at org.springframework.messaging.core.GenericMessagingTemplate.doReceive(GenericMessagingTemplate.java:207)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSendAndReceive(GenericMessagingTemplate.java:240)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSendAndReceive(GenericMessagingTemplate.java:47)
      at org.springframework.messaging.core.AbstractMessagingTemplate.sendAndReceive(AbstractMessagingTemplate.java:46)
      at org.springframework.integration.core.MessagingTemplate.sendAndReceive(MessagingTemplate.java:97)
      at org.springframework.integration.gateway.MessagingGatewaySupport.doSendAndReceive(MessagingGatewaySupport.java:503)
      at org.springframework.integration.gateway.MessagingGatewaySupport.sendAndReceiveMessage(MessagingGatewaySupport.java:474)
      at org.springframework.integration.gateway.GatewayProxyFactoryBean.sendOrSendAndReceive(GatewayProxyFactoryBean.java:573)
      at org.springframework.integration.gateway.GatewayProxyFactoryBean.invokeGatewayMethod(GatewayProxyFactoryBean.java:508)
      at org.springframework.integration.gateway.GatewayProxyFactoryBean.doInvoke(GatewayProxyFactoryBean.java:478)
      at org.springframework.integration.gateway.GatewayProxyFactoryBean.invoke(GatewayProxyFactoryBean.java:468)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
      at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
      at com.sun.proxy.$Proxy110.exchange(Unknown Source:-1)
      at org.springframework.integration.gateway.GatewayMessageHandler.handleRequestMessage(GatewayMessageHandler.java:88)
      at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:127)
      at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:170)
      at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:115)
      at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:133)
      at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:106)
      at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:73)
      at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:453)
      at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:403)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:187)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:166)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:47)
      at org.springframework.messaging.core.AbstractMessageSendingTemplate.send(AbstractMessageSendingTemplate.java:109)
      at org.springframework.integration.handler.AbstractMessageProducingHandler.sendOutput(AbstractMessageProducingHandler.java:444)
      at org.springframework.integration.handler.AbstractMessageProducingHandler.doProduceOutput(AbstractMessageProducingHandler.java:318)
      at org.springframework.integration.handler.AbstractMessageProducingHandler.produceOutput(AbstractMessageProducingHandler.java:266)
      at org.springframework.integration.handler.AbstractMessageProducingHandler.sendOutputs(AbstractMessageProducingHandler.java:229)
      at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:133)
      at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:170)
      at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:115)
      at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:133)
      at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:106)
      at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:73)
      at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:453)
      at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:403)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:187)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:166)
      at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:47)
      at org.springframework.messaging.core.AbstractMessageSendingTemplate.send(AbstractMessageSendingTemplate.java:109)
      at org.springframework.integration.endpoint.MessageProducerSupport.sendMessage(MessageProducerSupport.java:198)
      at org.springframework.cloud.gcp.pubsub.integration.inbound.PubSubInboundChannelAdapter.consumeMessage(PubSubInboundChannelAdapter.java:148)
      at org.springframework.cloud.gcp.pubsub.integration.inbound.PubSubInboundChannelAdapter$$Lambda$859.600858818.accept(Unknown Source:-1)
      at org.springframework.cloud.gcp.pubsub.core.subscriber.PubSubSubscriberTemplate.lambda$subscribeAndConvert$1(PubSubSubscriberTemplate.java:152)
      at org.springframework.cloud.gcp.pubsub.core.subscriber.PubSubSubscriberTemplate$$Lambda$860.1495761010.receiveMessage(Unknown Source:-1)
      at com.google.cloud.pubsub.v1.MessageDispatcher$4.run(MessageDispatcher.java:379)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
      at java.util.concurrent.FutureTask.run(FutureTask.java:-1)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

I suppose it is a reason because inside com.google.cloud.pubsub.v1.MessageDispatcher#processOutstandingMessage:

the line:

  executor.execute(deliverMessageTask);

is executed but deliverMessageTask is not executed by threadExecutor.

From my view it looks like a bug in the library but it might be library misusing. Anyway I am looking for any solution/workaround to avoid this isssue.

Library versions:

I use:
spring-boot 2.2.0.RELEASE
springCloudVersion = "Greenwich.SR3"

com.google.cloud:google-cloud-pubsub:1.98.0

P.S.

I know that I can increase thread pool size like:

spring:
  cloud:
    gcp:     
      pubsub:
        enabled: true
        subscriber:
          executor-threads: 100

But I don't think it is a good idea.

score 2 · Accepted Answer · answered Oct 30 '19 at 13:21

2

You problem is here:

.gateway(acknowledgementFlow);

It means request-reply and we can't guess that your acknowledgementFlow is one-way flow. I see that by your MyPubSubAckHandler implementation which returns void for its handleMessage() implementation. This way a gateway waits for reply, but the real sub-flow will never return any result. Therefore awaiting for reply threads are stuck and eventually your application fail.

One of the solution is to make a GatewayEndpointSpec.replyTimeout() as 0. So, your void sub-flow won't block a main flow for potential reply.

Another way just don't use gateway(), but that sub-flow content directly in the main flow. It really doesn't look like you expect some reply so this should work for you:

  return flow -> flow.channel(bucketNotificationChannel())
            .handle(handler)
            .log(INFO, "Handler finished", m -> {
                return "got" + m;
            })
            .log(DEBUG, "acknowledgementFlow", m -> "Handling acknowledgement for message: " + m)
            .handle(pubSubAckHandler);

answered Oct 30 '19 at 13:21

Artem Bilan

113,505
11
91
118

Could you please clarify a bit how to set gateway timeout in my code ? – gstackoverflow Oct 30 '19 at 14:32
1

`.gateway(acknowledgementFlow, (gatewaySpec) -> gatewaySpec.replyTimeout(0))` – Artem Bilan Oct 30 '19 at 14:34
Actually in the project I develop is used following technique to connect flows: flow->flow.channel()...gateway(anotherFlow) and anotherFlow ends with acknowledgementFlow which doesn't respond anything. Is there way to add some fake step which will return something? – gstackoverflow Oct 30 '19 at 16:38
Well, you would nee a `publishSubscribeChannel()` for that because you can't simulate any reply after `void` return. It is just the end of the flow - we can't continue. With a `publishSubscribeChannel()` you can have a first subscriber with that `void` and a second one to return something. Not sure though that you need all of that complexity in your solution... I would really go away from `gateway()` at all. `WireTap` can be used instead, if you would like reuse existing flow... – Artem Bilan Oct 30 '19 at 16:42
went away to read about WireTap. Will appreciate if you show/link appropriate example – gstackoverflow Oct 30 '19 at 16:59
Looks like I understood what you mean. but now I don't understand how to pass header to child flow: **Consumer idempotentByHeader(String objectIdHeader) { return endpointSpec -> endpointSpec.advice(idempotentByHeaderInterceptor(objectIdHeader)).errorChannel(errorChannel()); }** – gstackoverflow Oct 30 '19 at 17:05
**WireTapSpec** doesn't have advice method – gstackoverflow Oct 30 '19 at 17:06
This sounds like a fully different story. Please, don't pollute one SO thread with many note related questions. – Artem Bilan Oct 30 '19 at 17:06

PubSubInboundChannelAdapter stops to receive messages after 4th message

Library versions:

1 Answers1

Linked