确认后，一次又一次收到来自Google Pub/Sub订阅的消息[Heisenbug]

问题描述

我想注意到，我要描述的场景发生得很少，在大多数情况下，一切都按预期进行.

I would like to notice that the scenarion I will describe happen rare enough and in most cases everything works as expected.

我在发布/订阅方面有1个主题和1个订阅.

I have 1 topic and 1 subscription on Pub/Sub side.

我的Java应用程序侦听订阅，进行一些处理并发送回确认.由于Google Pub/Sub至少保证一次传递，因此我们根据objectGeneration标头和'objectId'标头在我们这一边进行邮件重复数据删除.

My java application listens for subscription, does some processing and sends acknowledge back. Because of fact that google Pub/Sub guarantees at least once delivery, we do message deduplication on our side based on objectGeneration header and 'objectId' header.

有时候，我们看到应用程序一次又一次地接受了确认的消息，这是意外行为.

Sometimes we see that message that was acknowldged is accepted by our application again and again and it is unexpected behaviour.

日志示例:

//first
2019-12-17 20:51:57.375 INFO 1 --- [sub-subscriber3] bucketNotificationFlow : Received new message from pub-sub: GenericMessage [payload={....}, headers={.....objectGeneration=1576615916875106, eventTime=2019-12-17T20:51:56.874940Z, objectId=Small_files_bunch/100_12_1.csv, ....
....
2019-12-17 20:51:57.698 INFO 1 --- [sub-subscriber3] .i.g.PubSubMessageAcknowledgementHandler : Acknowledged message - 1576615916875106
...
//duplicate 1
2019-12-17 20:51:59.663 INFO 1 --- [sub-subscriber4] bucketNotificationFlow : Received new message from pub-sub: GenericMessage [payload={...}, headers={ objectGeneration=1576615916875106, eventTime=2019-12-17T20:51:56.874940Z, objectId=Small_files_bunch/100_12_1.csv", ....
...
2019-12-17 20:51:59.704 INFO 1 --- [sub-subscriber4] c.b.m.i.DiscardedMessagesHandler : Duplicate message received GenericMessage [ headers={idempotent.keys=[objectGeneration.1576615916875106, objectId.Small_files_bunch/100_12_1.csv], ...
....
//duplicate 2
2019-12-17 22:52:02.239 INFO 1 --- [sub-subscriber1] bucketNotificationFlow : Received new message from pub-sub: GenericMessage [payload={...}, headers={objectGeneration=1576615916875106, eventTime=2019-12-17T20:51:56.874940Z, objectId=Small_files_bunch/100_12_1.csv, ...
...
2019-12-17 22:52:02.339 INFO 1 --- [sub-subscriber1] c.b.m.i.DiscardedMessagesHandler : Duplicate message received GenericMessage [ headers={idempotent.keys=[objectGeneration.1576615916875106, objectId.Small_files_bunch/100_12_1.csv], ...

// and so on each 2 hours

确认代码:

var generation = message.getHeaders().get("objectGeneration");
pubSubMessage = message.getHeaders().get(GcpPubSubHeaders.ORIGINAL_MESSAGE, BasicAcknowledgeablePubsubMessage.class)
pubSubMessage.ack().addCallback(
        v -> {
            removeFromIdempotentStore(targetMessage, false);
            log.info("Acknowledged message - {}", generation); //from logs we see that this line was invoked
        },
        e -> {
            removeFromIdempotentStore(targetMessage, false);
            log.error("Failed to acknowledge message - {}", generation, e);
        }
);

GCP订阅页面包含下图:

GCP subscription page contains following diagram:

StackDriver确认图:

StackDriver acknowledge diagram:

有什么想法吗，如何对其进行故障排除和修复?

Any ideas what is going on, how to troubleshoot it and fix it ?

推荐答案

尝试检查Stackdriver以查看您是否缺少确认截止日期.

Try checking Stackdriver to see if you are missing acknowledgement deadlines.

重复之间两个小时的等待时间非常有趣.您是否曾经尝试过扩大消息的截止日期? (有关此信息，请参见上面的链接.)

The two hour wait time between duplicates is very interesting. Have you tried expanding your message deadline before? (Info on this is at the above link.)

这篇关于确认后，一次又一次收到来自Google Pub/Sub订阅的消息[Heisenbug]的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持！