Some messages from Telegram are doubled

[BenWiederhake]

Describe the bug
Sometimes, very rarely, matterbridge receives a particular message "again", even though it was not even modified. This seems to correlate with running for a long time (weeks), restarting, and receiving an emoji reaction a few hours later.

My wild guess is that emoji reactions are sometimes received by a bot in the form of the same message being sent multiple times.

To Reproduce
Steps to reproduce the behavior: Cannot be reproduced reliably, but I guess that the setup is the following:

• Run the bridge for several weeks, with a lot of traffic
• Restart matterbridge, continue having traffic for a day
• Restart matterbridge again, continue having traffic, in particular including Telegram reactions after a few hours
• After a few hours, a single message from before the restart might be repeated

Expected behavior
matterbridge should never bridge "phantom" messages that don't exist.

Screenshots/debug logs

time="2024-08-15T19:50:25+02:00" level=debug msg="== Receiving event: &tgbotapi.Message{MessageID:3210, MessageThreadID:0, From:(*tgbotapi.User)(0xc00077eae0), SenderChat:(*tgbotapi.Chat)(nil), Date:1723744225, Chat:(*tgbotapi.Chat)(0xc000a5e120), ForwardFrom:(*tgbotapi.User)(nil), ForwardFromChat:(*tgbotapi.Chat)(nil), ForwardFromMessageID:0, ForwardSignature:"", ForwardSenderName:"", ForwardDate:0, IsTopicMessage:false, IsAutomaticForward:false, ReplyToMessage:(*tgbotapi.Message)(nil), ViaBot:(*tgbotapi.User)(nil), EditDate:0, HasProtectedContent:false, MediaGroupID:"", AuthorSignature:"", Text:"<REDACTED>", Entities:[]tgbotapi.MessageEntity(nil), Animation:(*tgbotapi.Animation)(nil), PremiumAnimation:(*tgbotapi.Animation)(nil), Audio:(*tgbotapi.Audio)(nil), Document:(*tgbotapi.Document)(nil), Photo:[]tgbotapi.PhotoSize(nil), Sticker:(*tgbotapi.Sticker)(nil), Video:(*tgbotapi.Video)(nil), VideoNote:(*tgbotapi.VideoNote)(nil), Voice:(*tgbotapi.Voice)(nil), Caption:"", CaptionEntities:[]tgbotapi.MessageEntity(nil), HasMediaSpoiler:false, Contact:(*tgbotapi.Contact)(nil), Dice:(*tgbotapi.Dice)(nil), Game:(*tgbotapi.Game)(nil), Poll:(*tgbotapi.Poll)(nil), Venue:(*tgbotapi.Venue)(nil), Location:(*tgbotapi.Location)(nil), NewChatMembers:[]tgbotapi.User(nil), LeftChatMember:(*tgbotapi.User)(nil), NewChatTitle:"", NewChatPhoto:[]tgbotapi.PhotoSize(nil), DeleteChatPhoto:false, GroupChatCreated:false, SuperGroupChatCreated:false, ChannelChatCreated:false, MessageAutoDeleteTimerChanged:(*tgbotapi.MessageAutoDeleteTimerChanged)(nil), MigrateToChatID:0, MigrateFromChatID:0, PinnedMessage:(*tgbotapi.Message)(nil), Invoice:(*tgbotapi.Invoice)(nil), SuccessfulPayment:(*tgbotapi.SuccessfulPayment)(nil), UserShared:(*tgbotapi.UserShared)(nil), ChatShared:(*tgbotapi.ChatShared)(nil), ConnectedWebsite:"", WriteAccessAllowed:(*tgbotapi.WriteAccessAllowed)(nil), PassportData:(*tgbotapi.PassportData)(nil), ProximityAlertTriggered:(*tgbotapi.ProximityAlertTriggered)(nil), ForumTopicCreated:(*tgbotapi.ForumTopicCreated)(nil), ForumTopicEdited:(*tgbotapi.ForumTopicEdited)(nil), ForumTopicClosed:(*tgbotapi.ForumTopicClosed)(nil), ForumTopicReopened:(*tgbotapi.ForumTopicReopened)(nil), GeneralForumTopicHidden:(*tgbotapi.GeneralForumTopicHidden)(nil), GeneralForumTopicUnhidden:(*tgbotapi.GeneralForumTopicUnhidden)(nil), VideoChatScheduled:(*tgbotapi.VideoChatScheduled)(nil), VideoChatStarted:(*tgbotapi.VideoChatStarted)(nil), VideoChatEnded:(*tgbotapi.VideoChatEnded)(nil), VideoChatParticipantsInvited:(*tgbotapi.VideoChatParticipantsInvited)(nil), WebAppData:(*tgbotapi.WebAppData)(nil), ReplyMarkup:(*tgbotapi.InlineKeyboardMarkup)(nil)}" func=handleRecv file="/home/user/workspace/matterbridge/bridge/telegram/handlers.go:190" prefix=telegram
time="2024-08-15T19:50:25+02:00" level=debug msg="<= Sending message from Ben on telegram.mytelegram to gateway" func=handleRecv file="/home/user/workspace/matterbridge/bridge/telegram/handlers.go:259" prefix=telegram
time="2024-08-15T19:50:25+02:00" level=debug msg="<= Message is config.Message<REDACTED same message> func=handleRecv file="/home/user/workspace/matterbridge/bridge/telegram/handlers.go:260" prefix=telegram
time="2024-08-15T19:50:25+02:00" level=debug msg="=> Sending config.Message<REDACTED same message> from telegram.mytelegram (-1001234567890) to discord.mydiscord (nameredacted)" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:499" prefix=gateway
time="2024-08-15T19:50:25+02:00" level=debug msg="=> Receiving config.Message<REDACTED same message> func=Send file="/home/user/workspace/matterbridge/bridge/discord/discord.go:254" prefix=discord
time="2024-08-15T19:50:25+02:00" level=debug msg="Processing webhook sending for message &<REDACTED same message> func=handleEventWebhook file="/home/user/workspace/matterbridge/bridge/discord/webhook.go:169" prefix=discord
time="2024-08-15T19:50:25+02:00" level=debug msg="mID discord.mydiscord: 1234567890123456789" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:518" prefix=gateway
time="2024-08-15T19:50:25+02:00" level=debug msg="=> Send from telegram.mytelegram (-1001234567890) to discord.mydiscord (nameredacted) took 294.820002ms" func=func1 file="/home/user/workspace/matterbridge/gateway/gateway.go:508" prefix=gateway
time="2024-08-15T19:50:25+02:00" level=debug msg="=> Sending config.Message<REDACTED same message> from telegram.mytelegram (-1001234567890) to matrix.mymatrix (!ABCDEFGHIJKLMNOPQR:matrix.org)" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:499" prefix=gateway
time="2024-08-15T19:50:25+02:00" level=debug msg="=> Receiving config.Message<REDACTED same message>" func=Send file="/home/user/workspace/matterbridge/bridge/matrix/matrix.go:144" prefix=matrix
time="2024-08-15T19:50:25+02:00" level=debug msg="Channel !ABCDEFGHIJKLMNOPQR:matrix.org maps to channel id !ABCDEFGHIJKLMNOPQR:matrix.org" func=Send file="/home/user/workspace/matterbridge/bridge/matrix/matrix.go:147" prefix=matrix
time="2024-08-15T19:50:26+02:00" level=debug msg="mID matrix.mymatrix: $GxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxE" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:518" prefix=gateway
time="2024-08-15T19:50:26+02:00" level=debug msg="=> Send from telegram.mytelegram (-1001234567890) to matrix.mymatrix (!ABCDEFGHIJKLMNOPQR:matrix.org) took 285.778977ms" func=func1 file="/home/user/workspace/matterbridge/gateway/gateway.go:508" prefix=gateway
time="2024-08-15T19:50:26+02:00" level=debug msg="== Receiving event: &gomatrix.Event<REDACTED same message>" func=handleEvent file="/home/user/workspace/matterbridge/bridge/matrix/matrix.go:484" prefix=matrix

When the message was received again:

time="2024-08-20T17:40:42+02:00" level=debug msg="<= Message is config.Message{Text:"<REDACTED>", Channel:"-1001234567890", name:"Ben", ID:"123456789", Avatar:"https://example.com/mb_storage/abcd1234/123456789.png", Account:"telegram.mytelegram", Event:"", Protocol:"", Gateway:"", ParentID:"", Timestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), ID:"3210", Extra:map[string][]interface {}{}}" func=handleRecv file="/home//workspace/matterbridge/bridge/telegram/handlers.go:260" prefix=telegram
time="2024-08-20T17:40:42+02:00" level=debug msg="=> Sending config.Message<REDACTED same message> from telegram.mytelegram (-1001234567890) to discord.mydiscord (nameredacted)" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:499" prefix=gateway
time="2024-08-20T17:40:42+02:00" level=debug msg="=> Receiving config.Message<REDACTED same message> func=Send file="/home/user/workspace/matterbridge/bridge/discord/discord.go:254" prefix=discord
time="2024-08-20T17:40:42+02:00" level=debug msg="Processing webhook sending for message &config.Message<REDACTED same message> func=handleEventWebhook file="/home/user/workspace/matterbridge/bridge/discord/webhook.go:171" prefix=discord
time="2024-08-20T17:40:42+02:00" level=debug msg="mID discord.mydiscord: 1234567890123456789" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:518" prefix=gateway
time="2024-08-20T17:40:42+02:00" level=debug msg="=> Send from telegram.mytelegram (-1001234567890) to discord.mydiscord (nameredacted) took 301.318451ms" func=func1 file="/home/user/workspace/matterbridge/gateway/gateway.go:508" prefix=gateway
time="2024-08-20T17:40:42+02:00" level=debug msg="=> Sending config.Message<REDACTED same message> from telegram.mytelegram (-1001234567890) to matrix.mymatrix (!ABCDEFGHIJKLMNOPQR:matrix.org)" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:499" prefix=gateway
time="2024-08-20T17:40:42+02:00" level=debug msg="=> Receiving config.Message<REDACTED same message> func=Send file="/home/user/workspace/matterbridge/bridge/matrix/matrix.go:144" prefix=matrix
time="2024-08-20T17:40:42+02:00" level=debug msg="Channel !ABCDEFGHIJKLMNOPQR:matrix.org maps to channel id !ABCDEFGHIJKLMNOPQR:matrix.org" func=Send file="/home/user/workspace/matterbridge/bridge/matrix/matrix.go:147" prefix=matrix
time="2024-08-20T17:40:42+02:00" level=debug msg="mID matrix.mymatrix: $uxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx0" func=SendMessage file="/home/user/workspace/matterbridge/gateway/gateway.go:518" prefix=gateway
time="2024-08-20T17:40:42+02:00" level=debug msg="=> Send from telegram.mytelegram (-1001234567890) to matrix.mymatrix (!ABCDEFGHIJKLMNOPQR:matrix.org) took 495.509627ms" func=func1 file="/home/user/workspace/matterbridge/gateway/gateway.go:508" prefix=gateway
time="2024-08-20T17:40:43+02:00" level=debug msg="== Receiving event: &gomatrix.Event<REDACTED same message> func=handleEvent file="/home/user/workspace/matterbridge/bridge/matrix/matrix.go:484" prefix=matrix

Note: The "second received" message Telegram-ID is the same as the first time. So it may be a spurious notification or something, and a permanent storage which message have already been bridged would help detecting duplicates.

Note: In the second log, I can't find any == Receiving event: &tgbotapi.Message or <= Sending message from Ben on telegram.mytelegram to gateway log lines. Weird.

I know for certain that the most recent restart of the server and also matterbridge was 11:35 local time, and the message got repeated 17:40 (over 6 hours later). This coincides exactly with an emoji-reaction, which makes me suspicious:

Environment (please complete the following information):

• OS: Linux, but shouldn't matter
• Matterbridge version: 1.26.1-dev (Explicitly announce the sender of each file in Telegram, simplifying moderation #2165)
• If self compiled (yes!): commit e03fb75

Additional context
Please add your configuration file (be sure to exclude or anonymize private data (tokens/passwords))

[telegram.mytelegram]
Token="1234567890:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA"
RemoteNickFormat="{NICK}@‍{PROTOCOL}: "
MediaConvertWebPToPNG=true
MediaConvertTgs="png"
UseFirstName=true

[discord.mydiscord]
Token="AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA"
Server="RedactedServer"
RemoteNickFormat="{NICK}@‍{PROTOCOL}"
AutoWebhooks=true

[matrix.mymatrix]
Server="https://matrix.org"
Login="redactedbotname"
Password="AAAAAAAAAAAAAAAAAAAAAAAA"
RemoteNickFormat="{NICK}@‍{PROTOCOL}: "
NoHomeServerSuffix=true
HTMLDisable=true

[[gateway]]
name="redactedname"
enable=true
[[gateway.inout]]
account="telegram.mytelegram"
channel="-1001234567890"
[[gateway.inout]]
account="discord.mydiscord"
channel="redactedname"
[[gateway.inout]]
account="matrix.mymatrix"
channel="!AAAAAAAAAAAAAAAAAA:matrix.org"

[Mikaela]

Duplicate of #1816