Fatal error in combination with Jira addon
0x3dlux opened this issue · 4 comments
0x3dlux commented
We run https://mattermost.com/marketplace/jira-plugin besides MatteIRCd. A colleague was doing /jira issue view <issue ID> then clicked "Share publically" inside Mattermost when MatterIRCd crashed with the following:
DEBU[2022-04-08T16:48:20+02:00] handleWsActionPost() receiving userid sespg78ifjbumktcp1xos97mdo
DEBU[2022-04-08T16:48:20+02:00] handleWsActionPost() user XYZ sent
DEBU[2022-04-08T16:48:20+02:00] model.Post{Id:"gx9f1zz8stdufbo6arn4aioexw", CreateAt:1649429300507, UpdateAt:1649429300507, EditAt:0, DeleteAt:0, IsPinned:false, UserId:"sespg78ifjbumktcp1xos97mdo", ChannelId:"jfu4oh5uppyubdcjpudjnupdgw", RootId:"", OriginalId:"", Message:"\n", MessageSource:"", Type:"", propsMu:sync.RWMutex{w:sync.Mutex{state:0, sema:0x0}, writerSem:0x0, readerSem:0x0, readerCount:0, readerWait:0}, Props:model.StringInterface{"attachments":[]interface {}{map[string]interface {}{"author_icon":"", "author_link":"", "author_name":"", "color":"#95b7d0", "fallback":"", "fields":[]interface {}{map[string]interface {}{"short":true, "title":"Priority", "value":"Medium"}, map[string]interface {}{"short":true, "title":"Reporter", "value":" David"}}, "footer":"", "footer_icon":"", "id":0, "image_url":"", "pretext":"", "text":"[P4A-1487: Bug on translated names for folders (Unassessed Issues)](https://<Jira URL>/browse/<issue ID>)\n\n*Description:*\r\n\r\nThe app when used in catalan displays \"=== App-speci... ====\" instead of the correct remote folder name, in this case Gmail\r\n\r\n*How to reproduce/Unexpected behaviour:*\r\n * Switching the app to Catalan\r\n\r\n*Expected behaviour:*\r\n\r\nDisplay correct titles in catalan\r\n\r\n*Additional info:*\r\n\r\n*!photo1648625587.jpeg|width=225,height=364!!photo1648625587 (1).jpeg|width=224,height=364!*\n", "thumb_url":"", "title":"", "title_link":"", "ts":interface {}(nil)}}}, Hashtags:"", Filenames:model.StringArray(nil), FileIds:model.StringArray(nil), PendingPostId:"", HasReactions:false, RemoteId:(*string)(nil), ReplyCount:0, LastReplyAt:0, Participants:[]*model.User(nil), IsFollowing:(*bool)(nil), Metadata:(*model.PostMetadata)(0xc0003fecb0)}
DEBU[2022-04-08T16:48:20+02:00] in handleWsMessage0
[2022-04-08T16:48:20+02:00] DEBUG matterclient: WsReceiver event: &model.WebSocketEvent{event:"post_deleted", data:map[string]interface {}{"post":"{\"id\":\"muo9co7zuj8kxqcwd6u3miayuo\",\"create_at\":0,\"update_at\":1649429300562,\"edit_at\":0,\"delete_at\":1649429300562,\"is_pinned\":false,\"user_id\":\"sespg78ifjbumktcp1xos97mdo\",\"channel_id\":\"\",\"root_id\":\"\",\"original_id\":\"\",\"message\":\"\",\"type\":\"system_ephemeral\",\"props\":null,\"hashtags\":\"\",\"pending_post_id\":\"\",\"reply_count\":0,\"last_reply_at\":0,\"participants\":null}"}, broadcast:(*model.WebsocketBroadcast)(0xc000622d00), sequence:1354, precomputedJSON:(*model.precomputedWebSocketEventJSON)(nil)}
DEBU[2022-04-08T16:48:20+02:00] MMUser WsReceiver: &model.WebSocketEvent{event:"post_deleted", data:map[string]interface {}{"post":"{\"id\":\"muo9co7zuj8kxqcwd6u3miayuo\",\"create_at\":0,\"update_at\":1649429300562,\"edit_at\":0,\"delete_at\":1649429300562,\"is_pinned\":false,\"user_id\":\"sespg78ifjbumktcp1xos97mdo\",\"channel_id\":\"\",\"root_id\":\"\",\"original_id\":\"\",\"message\":\"\",\"type\":\"system_ephemeral\",\"props\":null,\"hashtags\":\"\",\"pending_post_id\":\"\",\"reply_count\":0,\"last_reply_at\":0,\"participants\":null}"}, broadcast:(*model.WebsocketBroadcast)(0xc000622d00), sequence:1354, precomputedJSON:(*model.precomputedWebSocketEventJSON)(nil)}
TRAC[2022-04-08T16:48:20+02:00] handleWsMessage (*matterclient.Message)(0xc0003ff030)({
Raw: (*model.WebSocketEvent)(0xc0004f6510)({
event: (string) (len=12) "post_deleted",
data: (map[string]interface {}) (len=1) {
(string) (len=4) "post": (string) (len=357) "{\"id\":\"muo9co7zuj8kxqcwd6u3miayuo\",\"create_at\":0,\"update_at\":1649429300562,\"edit_at\":0,\"delete_at\":1649429300562,\"is_pinned\":false,\"user_id\":\"sespg78ifjbumktcp1xos97mdo\",\"channel_id\":\"\",\"root_id\":\"\",\"original_id\":\"\",\"message\":\"\",\"type\":\"system_ephemeral\",\"props\":null,\"hashtags\":\"\",\"pending_post_id\":\"\",\"reply_count\":0,\"last_reply_at\":0,\"participants\":null}"
},
broadcast: (*model.WebsocketBroadcast)(0xc000622d00)({
OmitUsers: (map[string]bool) <nil>,
UserId: (string) (len=26) "sespg78ifjbumktcp1xos97mdo",
ChannelId: (string) "",
TeamId: (string) "",
ContainsSanitizedData: (bool) false,
ContainsSensitiveData: (bool) false
}),
sequence: (int64) 1354,
precomputedJSON: (*model.precomputedWebSocketEventJSON)(<nil>)
}),
Post: (*model.Post)(<nil>),
Team: (string) (len=3) "XYZ",
Channel: (string) "",
Username: (string) "",
Text: (string) "",
Type: (string) "",
UserID: (string) ""
})
DEBU[2022-04-08T16:48:20+02:00] handleWsActionPost() receiving userid sespg78ifjbumktcp1xos97mdo
DEBU[2022-04-08T16:48:20+02:00] handleWsActionPost() user XYZ sent
DEBU[2022-04-08T16:48:20+02:00] model.Post{Id:"muo9co7zuj8kxqcwd6u3miayuo", CreateAt:0, UpdateAt:1649429300562, EditAt:0, DeleteAt:1649429300562, IsPinned:false, UserId:"sespg78ifjbumktcp1xos97mdo", ChannelId:"", RootId:"", OriginalId:"", Message:"", MessageSource:"", Type:"system_ephemeral", propsMu:sync.RWMutex{w:sync.Mutex{state:0, sema:0x0}, writerSem:0x0, readerSem:0x0, readerCount:0, readerWait:0}, Props:model.StringInterface(nil), Hashtags:"", Filenames:model.StringArray(nil), FileIds:model.StringArray(nil), PendingPostId:"", HasReactions:false, RemoteId:(*string)(nil), ReplyCount:0, LastReplyAt:0, Participants:[]*model.User(nil), IsFollowing:(*bool)(nil), Metadata:(*model.PostMetadata)(nil)}
DEBU[2022-04-08T16:48:20+02:00] in handleWsMessage0
TRAC[2022-04-08T16:48:20+02:00] eventchan (*bridge.Event)(0xc0004b17c0)({
Type: (string) (len=15) "channel_message",
Data: (*bridge.ChannelMessageEvent)(0xc000408870)({
Text: (string) (len=10) " (deleted)",
ChannelID: (string) "",
Sender: (*bridge.UserInfo)(0xc000558460)({
Nick: (string) (len=3) "XYZ",
User: (string) (len=26) "sespg78ifjbumktcp1xos97mdo",
Real: (string) (len=3) "XYZ",
Pass: ([]string) <nil>,
Host: (string) (len=24) "http://<censored>",
Roles: (string) (len=24) "system_user system_admin",
DisplayName: (string) "",
Ghost: (bool) true,
Me: (bool) true,
Username: (string) (len=3) "XYZ",
TeamID: (string) (len=26) "ykj1nb88hjfc9jwie9bg4bjner",
FirstName: (string) (len=3) "XYZ",
LastName: (string) (len=3) "XYZ",
MentionKeys: ([]string) (len=1 cap=1) {
(string) ""
}
}),
MessageType: (string) "",
ChannelType: (string) "",
Files: ([]*bridge.File) {
},
MessageID: (string) (len=26) "muo9co7zuj8kxqcwd6u3miayuo",
Event: (string) (len=12) "post_deleted",
ParentID: (string) ""
})
}) module=matterircd
DEBU[2022-04-08T16:48:20+02:00] in handleChannelMessageEvent module=matterircd
ERRO[2022-04-08T16:48:20+02:00] didn't find channel (): channel not found module=matterircd
DEBU[2022-04-08T16:48:20+02:00] new channel id: , name: module=matterircd
TRAC[2022-04-08T16:48:20+02:00] mayjoin 0 false ch: , match: [#town-square] module=matterircd
DEBU[2022-04-08T16:48:20+02:00] -> :XYZ/!XYZ/@XYZ/ PRIVMSG &messages : (deleted) module=matterircd
FATA[2022-04-08T16:48:20+02:00] key required module=matterircd
Seems like the Jira addon is deleting the message shown to the user before publishing the one shown to everyone.
42wim commented
what matterircd/mattermost versions are you running?
Also, I don't see a crash in your log here ?
0x3dlux commented
Mattermost
Version: 6.5.0
Build Number: 6.5.0
Build Date: Tue Mar 15 15:36:47 UTC 2022
Build Hash: 7fff157bcf85b54d595e22262a66d7f28d4b5a68
MatterIRCd version: 0.25.0 71b2c97
hloeung commented
I think the issue is related to the channels cache fixed recently and this:
ERRO[2022-04-08T16:48:20+02:00] didn't find channel (): channel not found module=matterircd
DEBU[2022-04-08T16:48:20+02:00] new channel id: , name: module=matterircd
With no channel ID, it then tries to save the last viewed passing through to bbolt and that's what gives us the FATAL key required.
PR #496 should fix this.
42wim commented
Fixed in master