Slack to Mattermost: panic: runtime error: invalid memory address or nil pointer dereference

celine-m-s commented 1 year ago

Describe the bug Matterbridge crashes for an unknown reason. Well, in fact, it must crash for a reason but I didn't find it! :)

To Reproduce Unable to reproduce.

Screenshots/debug logs

time="2023-01-19T14:38:34Z" level=error msg="getting post slack 1674136831.135359 failed: : Sorry, we could not find the page., There doesn't appear to be an api call for the url='/api/v4/posts/slack 1674136831.135359'.  Typo? are you missing a team_id or user_id as part of the url?" prefix=mattermost
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x60 pc=0xf99905]

goroutine 64 [running]:
github.com/42wim/matterbridge/bridge/mattermost.(*Bmattermost).Send(0xc0000fd2d0, {{0xc000917428, 0x11}, {0xc000238cc0, 0xc}, {0xc0009cf290, 0xf}, {0xc0003cf780, 0xb}, {0xc00051f0e0, ...}, ...})
    /go/src/github.com/42wim/matterbridge/bridge/mattermost/mattermost.go:191 +0x4e5
github.com/42wim/matterbridge/gateway.(*Gateway).SendMessage(0xc0004087e0, 0xc000d7e8f0, 0xc0000b4a00, 0xc00090b800, {0xc0009177e8, 0x17})
    /go/src/github.com/42wim/matterbridge/gateway/gateway.go:511 +0x998
github.com/42wim/matterbridge/gateway.(*Gateway).handleMessage(0xc0004087e0, 0xc000d7e8f0, 0xc0000b4a00)
    /go/src/github.com/42wim/matterbridge/gateway/handlers.go:226 +0x37c
github.com/42wim/matterbridge/gateway.(*Router).handleReceive(0xc00026a500)
    /go/src/github.com/42wim/matterbridge/gateway/router.go:154 +0x535
created by github.com/42wim/matterbridge/gateway.(*Router).Start
    /go/src/github.com/42wim/matterbridge/gateway/router.go:102 +0x64e

Environment (please complete the following information):

OS: Exherbo Linux
Matterbridge version: 1.25.2 20f841c5

Additional context

# Accounts
[mattermost.xx]
    PreserveThreading=true
    UseUserName=true
    PrefixMessagesWithNick=true
    RemoteNickFormat="**{NICK}** : "

[slack.xx]
    PreserveThreading=true
    UseFullName=true
    RemoteNickFormat="{NICK}"

[[gateway]]
    name="gateway-c1"
    enable=true

[[gateway.inout]]
    account="mattermost.xx"
    channel="startup"

[[gateway.inout]]
    account="slack.xx"
    channel="c1"

Thanks again for this amazing project! It helps us every day!

42wim commented 1 year ago

what output does matterbridge --version give, because the 1.25.2 can not fail on the place that your log shows.

celine-m-s commented 1 year ago

Hello! Thanks for answering! Here is the output:

$ matterbridge --version
version: 1.25.2 20f841c5

It's downloaded using this script: https://github.com/betagouv/itou-matterbridge/blob/main/dl_matterbridge.sh

celine-m-s commented 1 year ago

Update: it seems it comes from picture uploads failing from Slack to Mattermost.

Sending images from Slack to Mattermost fails most of the time, causing the app to crash. However, CPU, memory and disks are fully free. I use a Heroku-like SaaS platform to host Matterbridge with a dedicated instance.

I enabled debug mode. Here is the output:

$ grep -C 20 --color=auto 'panic' /tmp/matterbridge.log 
time="2023-02-01T17:48:27Z" level=debug msg="map[string]interface {}{"parent_id":"7n1uo6su4fgdpnpw8uoqtwomee", "user_id":"qrrm5tzixtbkfdadka8e3bxhtc"} "typing"" func=handleMatterClient6 file="bridge/mattermost/handlers.go:198" prefix=mattermost
time="2023-02-01T17:48:27Z" level=debug msg="ignoring nil message.Post: &matterclient.Message{Raw:(*model.WebSocketEvent)(0xc0030000c0), Post:(*model.Post)(nil), Team:"betagouv", Channel:"", Username:"", Text:"", Type:"", UserID:""}" func=skipMessage6 file="bridge/mattermost/helpers.go:338" prefix=mattermost
time="2023-02-01T17:48:27Z" level=debug msg="Skipped message: &matterclient.Message{Raw:(*model.WebSocketEvent)(0xc0030000c0), Post:(*model.Post)(nil), Team:"betagouv", Channel:"", Username:"", Text:"", Type:"", UserID:""}" func=handleMatterClient6 file="bridge/mattermost/handlers.go:201" prefix=mattermost
time="2023-02-01T17:48:46Z" level=debug msg="map[string]interface {}{"channel_display_name":"etalab-veille-jobs-data-scientist", "channel_name":"etalab-veille-jobs-data-scientist", "channel_type":"O", "post":"{\"id\":\"6uscdw64ep8f38woe6rm1izjmy\",\"create_at\":1675273726875,\"update_at\":1675273726875,\"edit_at\":0,\"delete_at\":0,\"is_pinned\":false,\"user_id\":\"zwrmqfxk5jd8frj9xjhd18r4fc\",\"channel_id\":\"p4jfi4x7j784xcbqhqy9ncm6ah\",\"root_id\":\"\",\"original_id\":\"\",\"message\":\"Export RSS des offres - Seulement les offres à la une : Non / Mots clés / Référence de l'offre : Data scientist\\n2023-1117771 - Consultant.e interne en open data (temps partiel 60%) H/F\\nhttps://place-emploi-public.gouv.fr/offre-emploi/2023-1117771/?tracking=1\\u0026idOrigine=502\\n\",\"type\":\"custom_git_pr\",\"props\":{\"from_bot\":\"true\"},\"hashtags\":\"\",\"pending_post_id\":\"\",\"reply_count\":0,\"last_reply_at\":0,\"participants\":null,\"metadata\":{\"embeds\":[{\"type\":\"opengraph\",\"url\":\"https://place-emploi-public.gouv.fr/offre-emploi/2023-1117771/?tracking=1\\u0026idOrigine=502\",\"data\":{\"type\":\"\",\"url\":\"https://place-emploi-public.gouv.fr/offre-emploi/2023-1117771/?tracking=1\\u0026idOrigine=502\",\"title\":\"Consultant.e interne en open data (temps partiel 60%) h/f | Place de l'emploi public\",\"description\":\"Ce site propose des offres d'emplois publiées par les employeurs des Fonctions Publiques d'Etat, Territoriale et Hospitalière.\",\"determiner\":\"\",\"site_name\":\"Place de l'emploi public\",\"locale\":\"\",\"locales_alternate\":null,\"images\":[{\"url\":\"\",\"secure_url\":\"\",\"type\":\"\",\"width\":800,\"height\":500}],\"audios\":null,\"videos\":null}}]}}", "sender_name":"@rssfeedbot", "set_online":true, "team_id":"fowuhet9sbg9brkh6gfakz91qc"} "posted"" func=handleMatterClient6 file="bridge/mattermost/handlers.go:198" prefix=mattermost
time="2023-02-01T17:48:46Z" level=debug msg="== Receiving event &matterclient.Message{Raw:(*model.WebSocketEvent)(0xc003001170), Post:(*model.Post)(0xc00475ab00), Team:"betagouv", Channel:"etalab-veille-jobs-data-scientist", Username:"rssfeedbot", Text:"Export RSS des offres - Seulement les offres à la une : Non / Mots clés / Référence de l'offre : Data scientist\n2023-1117771 - Consultant.e interne en open data (temps partiel 60%) H/F\nhttps://place-emploi-public.gouv.fr/offre-emploi/2023-1117771/?tracking=1&idOrigine=502\n", Type:"custom_git_pr", UserID:"zwrmqfxk5jd8frj9xjhd18r4fc"}" func=handleMatterClient6 file="bridge/mattermost/handlers.go:215" prefix=mattermost
time="2023-02-01T17:48:46Z" level=debug msg="<= Sending message from rssfeedbot on mattermost.betagouv to gateway" func=handleMatter file="bridge/mattermost/handlers.go:122" prefix=mattermost
time="2023-02-01T17:48:46Z" level=debug msg="<= Message is &config.Message{Text:"Export RSS des offres - Seulement les offres à la une : Non / Mots clés / Référence de l'offre : Data scientist\n2023-1117771 - Consultant.e interne en open data (temps partiel 60%) H/F\nhttps://place-emploi-public.gouv.fr/offre-emploi/2023-1117771/?tracking=1&idOrigine=502\n", Channel:"etalab-veille-jobs-data-scientist", Username:"rssfeedbot", UserID:"zwrmqfxk5jd8frj9xjhd18r4fc", Avatar:"", Account:"mattermost.betagouv", Event:"", Protocol:"", Gateway:"", ParentID:"", Timestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), ID:"6uscdw64ep8f38woe6rm1izjmy", Extra:map[string][]interface {}{}}" func=handleMatter file="bridge/mattermost/handlers.go:123" prefix=mattermost
time="2023-02-01T17:49:45Z" level=debug msg="map[string]interface {}{"channel_display_name":"signaux-faibles", "channel_name":"signaux-faibles", "channel_type":"P", "post":"{\"id\":\"xwt635zdwp8n5c1atxjhimfa1o\",\"create_at\":1675273785054,\"update_at\":1675273785054,\"edit_at\":0,\"delete_at\":0,\"is_pinned\":false,\"user_id\":\"d1ofhdkmubrr8qcmfr9kwkrnbo\",\"channel_id\":\"ni7jjg6fdbrymcaym37e6hkk9y\",\"root_id\":\"muuwi9q7j3b3bx6zafdaynj76r\",\"original_id\":\"\",\"message\":\"oui, c'est lolifiant… Je pense qu'on se met un standard qui est pragmatique et au service des entreprises pour notre part, c'est sans doute une ligne à tenir avec une boussole assez évidente…\",\"type\":\"\",\"props\":{},\"hashtags\":\"\",\"pending_post_id\":\"\",\"reply_count\":16,\"last_reply_at\":0,\"participants\":null,\"metadata\":{}}", "sender_name":"@christophe.ninucci", "set_online":true, "team_id":"fowuhet9sbg9brkh6gfakz91qc"} "posted"" func=handleMatterClient6 file="bridge/mattermost/handlers.go:198" prefix=mattermost
time="2023-02-01T17:49:45Z" level=debug msg="== Receiving event &matterclient.Message{Raw:(*model.WebSocketEvent)(0xc0038ba030), Post:(*model.Post)(0xc00475a000), Team:"betagouv", Channel:"signaux-faibles", Username:"christophe.ninucci", Text:"oui, c'est lolifiant… Je pense qu'on se met un standard qui est pragmatique et au service des entreprises pour notre part, c'est sans doute une ligne à tenir avec une boussole assez évidente…", Type:"", UserID:"d1ofhdkmubrr8qcmfr9kwkrnbo"}" func=handleMatterClient6 file="bridge/mattermost/handlers.go:215" prefix=mattermost
time="2023-02-01T17:49:45Z" level=debug msg="<= Sending message from christophe.ninucci on mattermost.betagouv to gateway" func=handleMatter file="bridge/mattermost/handlers.go:122" prefix=mattermost
time="2023-02-01T17:49:45Z" level=debug msg="<= Message is &config.Message{Text:"oui, c'est lolifiant… Je pense qu'on se met un standard qui est pragmatique et au service des entreprises pour notre part, c'est sans doute une ligne à tenir avec une boussole assez évidente…", Channel:"signaux-faibles", Username:"christophe.ninucci", UserID:"d1ofhdkmubrr8qcmfr9kwkrnbo", Avatar:"", Account:"mattermost.betagouv", Event:"", Protocol:"", Gateway:"", ParentID:"muuwi9q7j3b3bx6zafdaynj76r", Timestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), ID:"xwt635zdwp8n5c1atxjhimfa1o", Extra:map[string][]interface {}{}}" func=handleMatter file="bridge/mattermost/handlers.go:123" prefix=mattermost
time="2023-02-01T17:52:26Z" level=debug msg="== Receiving event &slack.MessageEvent{Msg:slack.Msg{ClientMsgID:"", Type:"message", Channel:"C01AQKD7MAN", User:"", Text:"", Timestamp:"1675273266.332239", ThreadTimestamp:"", IsStarred:false, PinnedTo:[]string(nil), Attachments:[]slack.Attachment(nil), Edited:(*slack.Edited)(nil), LastRead:"", Subscribed:false, UnreadCount:0, SubType:"message_replied", Hidden:true, DeletedTimestamp:"", EventTimestamp:"1675273946.035200", BotID:"", Username:"", Icons:(*slack.Icon)(nil), BotProfile:(*slack.BotProfile)(nil), Inviter:"", Topic:"", Purpose:"", Name:"", OldName:"", Members:[]string(nil), ReplyCount:0, Replies:[]slack.Reply(nil), ParentUserId:"", LatestReply:"", Files:[]slack.File(nil), Upload:false, Comment:(*slack.Comment)(nil), ItemType:"", ReplyTo:0, Team:"", Reactions:[]slack.ItemReaction(nil), ResponseType:"", ReplaceOriginal:false, DeleteOriginal:false, Blocks:slack.Blocks{BlockSet:[]slack.Block(nil)}}, SubMessage:(*slack.Msg)(0xc000248000), PreviousMessage:(*slack.Msg)(nil)}" func=handleSlackClient file="bridge/slack/handlers.go:53" prefix=slack
time="2023-02-01T17:52:26Z" level=debug msg="Skipped message: &slack.MessageEvent{Msg:slack.Msg{ClientMsgID:"", Type:"message", Channel:"C01AQKD7MAN", User:"", Text:"", Timestamp:"1675273266.332239", ThreadTimestamp:"", IsStarred:false, PinnedTo:[]string(nil), Attachments:[]slack.Attachment(nil), Edited:(*slack.Edited)(nil), LastRead:"", Subscribed:false, UnreadCount:0, SubType:"message_replied", Hidden:true, DeletedTimestamp:"", EventTimestamp:"1675273946.035200", BotID:"", Username:"", Icons:(*slack.Icon)(nil), BotProfile:(*slack.BotProfile)(nil), Inviter:"", Topic:"", Purpose:"", Name:"", OldName:"", Members:[]string(nil), ReplyCount:0, Replies:[]slack.Reply(nil), ParentUserId:"", LatestReply:"", Files:[]slack.File(nil), Upload:false, Comment:(*slack.Comment)(nil), ItemType:"", ReplyTo:0, Team:"", Reactions:[]slack.ItemReaction(nil), ResponseType:"", ReplaceOriginal:false, DeleteOriginal:false, Blocks:slack.Blocks{BlockSet:[]slack.Block(nil)}}, SubMessage:(*slack.Msg)(0xc000248000), PreviousMessage:(*slack.Msg)(nil)}" func=handleSlackClient file="bridge/slack/handlers.go:71" prefix=slack
time="2023-02-01T17:52:26Z" level=debug msg="== Receiving event &slack.MessageEvent{Msg:slack.Msg{ClientMsgID:"f24af8fa-29a7-4ea5-965c-9368e9b90258", Type:"message", Channel:"C01AQKD7MAN", User:"UQ6BZ0F2S", Text:"BRAVO de faire de ce service un service reconnu et incontournable dans le monde de l'emploi aujourd'hui.", Timestamp:"1675273946.495669", ThreadTimestamp:"1675273266.332239", IsStarred:false, PinnedTo:[]string(nil), Attachments:[]slack.Attachment(nil), Edited:(*slack.Edited)(nil), LastRead:"", Subscribed:false, UnreadCount:0, SubType:"", Hidden:false, DeletedTimestamp:"", EventTimestamp:"1675273946.495669", BotID:"", Username:"", Icons:(*slack.Icon)(nil), BotProfile:(*slack.BotProfile)(nil), Inviter:"", Topic:"", Purpose:"", Name:"", OldName:"", Members:[]string(nil), ReplyCount:0, Replies:[]slack.Reply(nil), ParentUserId:"", LatestReply:"", Files:[]slack.File(nil), Upload:false, Comment:(*slack.Comment)(nil), ItemType:"", ReplyTo:0, Team:"TQ3MK2T9S", Reactions:[]slack.ItemReaction(nil), ResponseType:"", ReplaceOriginal:false, DeleteOriginal:false, Blocks:slack.Blocks{BlockSet:[]slack.Block{(*slack.RichTextBlock)(0xc0001348c0)}}}, SubMessage:(*slack.Msg)(nil), PreviousMessage:(*slack.Msg)(nil)}" func=handleSlackClient file="bridge/slack/handlers.go:53" prefix=slack
time="2023-02-01T17:52:26Z" level=debug msg="<= Sending message from Eric on slack.itou to gateway" func=handleSlack file="bridge/slack/handlers.go:32" prefix=slack
time="2023-02-01T17:52:26Z" level=debug msg="<= Message is &config.Message{Text:"BRAVO de faire de ce service un service reconnu et incontournable dans le monde de l'emploi aujourd'hui.", Channel:"c1-emplois", Username:"Eric", UserID:"UQ6BZ0F2S", Avatar:"https://avatars.slack-edge.com/2022-04-27/3443591702406_bcb336f56f9824304f94_48.jpg", Account:"slack.itou", Event:"", Protocol:"slack", Gateway:"", ParentID:"1675273266.332239", Timestamp:time.Date(1, time.January, 1, 0, 0, 0, 0, time.UTC), ID:"1675273946.495669", Extra:map[string][]interface {}{}}" func=handleSlack file="bridge/slack/handlers.go:45" prefix=slack
time="2023-02-01T17:52:26Z" level=debug msg="=> Sending config.Message{Text:"BRAVO de faire de ce service un service reconnu et incontournable dans le monde de l'emploi aujourd'hui.", Channel:"c1-emplois", Username:"Eric", UserID:"UQ6BZ0F2S", Avatar:"https://avatars.slack-edge.com/2022-04-27/3443591702406_bcb336f56f9824304f94_48.jpg", Account:"slack.itou", Event:"", Protocol:"slack", Gateway:"gateway-c1-faciliter", ParentID:"1675273266.332239", Timestamp:time.Date(2023, time.February, 1, 17, 52, 26, 598094781, time.Local), ID:"1675273946.495669", Extra:map[string][]interface {}{}} from slack.itou (c1-emplois) to mattermost.betagouv (startup-itou)" func=SendMessage file="gateway/gateway.go:499" prefix=gateway
time="2023-02-01T17:52:26Z" level=debug msg="=> Receiving config.Message{Text:"BRAVO de faire de ce service un service reconnu et incontournable dans le monde de l'emploi aujourd'hui..", Channel:"startup-itou", Username:"**Eric** : ", UserID:"UQ6BZ0F2S", Avatar:"https://avatars.slack-edge.com/2022-04-27/3443591702406_bcb336f56f9824304f94_48.jpg", Account:"slack.itou", Event:"", Protocol:"slack", Gateway:"gateway-c1-faciliter", ParentID:"slack 1675273266.332239", Timestamp:time.Date(2023, time.February, 1, 17, 52, 26, 598094781, time.Local), ID:"", Extra:map[string][]interface {}{}}" func=Send file="bridge/mattermost/mattermost.go:149" prefix=mattermost
time="2023-02-01T17:52:26Z" level=error msg="getting post slack 1675273266.332239 failed: : Sorry, we could not find the page., There doesn't appear to be an api call for the url='/api/v4/posts/slack 1675273266.332239'.  Typo? are you missing a team_id or user_id as part of the url?" func=Send file="bridge/mattermost/mattermost.go:189" prefix=mattermost
time="2023-02-01T17:52:26Z" level=debug msg="=> Send from slack.itou (c1-emplois) to mattermost.betagouv (startup-itou) took 27.330047ms" func=func1 file="gateway/gateway.go:508" prefix=gateway
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x60 pc=0xf99905]

goroutine 64 [running]:
github.com/42wim/matterbridge/bridge/mattermost.(*Bmattermost).Send(0xc000107570, {{0xc000681000, 0x1e7}, {0xc000242cd0, 0xc}, {0xc0030d1b20, 0xb}, {0xc004759f30, 0x9}, {0xc000e7e1e0, ...}, ...})
    /go/src/github.com/42wim/matterbridge/bridge/mattermost/mattermost.go:191 +0x4e5
github.com/42wim/matterbridge/gateway.(*Gateway).SendMessage(0xc0004127e0, 0xc00140e750, 0xc00057d100, 0xc000655480, {0xc002ec33e0, 0x17})
    /go/src/github.com/42wim/matterbridge/gateway/gateway.go:511 +0x998
github.com/42wim/matterbridge/gateway.(*Gateway).handleMessage(0xc0004127e0, 0xc00140e750, 0xc00057d100)
    /go/src/github.com/42wim/matterbridge/gateway/handlers.go:226 +0x37c
github.com/42wim/matterbridge/gateway.(*Router).handleReceive(0xc0002760a0)
    /go/src/github.com/42wim/matterbridge/gateway/router.go:154 +0x535
created by github.com/42wim/matterbridge/gateway.(*Router).Start
    /go/src/github.com/42wim/matterbridge/gateway/router.go:102 +0x64e

42wim commented 1 year ago

This should be fixed now in master

celine-m-s commented 1 year ago

GREAT! Thank you! Just for my information, do you plan to schedule a new release soon? If so, do you have an approximative date?

42wim commented 1 year ago

probably in the next 30 days, but you can build it yourself from master (master is stable enough)

celine-m-s commented 1 year ago

Thanks! I did it yesterday and it worked perfectly well. Again, I'd like to thank you for your dedication and your hard work. THANKS! :muscle: :tada:

42wim / matterbridge

Slack to Mattermost: panic: runtime error: invalid memory address or nil pointer dereference #1947