Mattermost-server: Invalid memory address or nil pointer

[discostur]

Hi,

we have seen a nil pointer dereference in mattermost server 5.25.0:

mattermost: {"level":"error","ts":1597215829.3807094,"caller":"http/server.go:3053","msg":"http: panic serving 127.0.0.1:52580: runtime error: invalid memory address or nil pointer dereference\ngoroutine 10238003 [running]:\nnet/http.(*conn).serve.func1(0xc00990d860)\n\tnet/http/server.go:1767 +0x139\npanic(0x1a5fc40, 0x2ef9ba0)\n\truntime/panic.go:679 +0x1b2\nencoding/json.(*encodeState).marshal.func1(0xc004480ae8)\n\tencoding/json/encode.go:305 +0x9a\npanic(0x1a5fc40, 0x2ef9ba0)\n\truntime/panic.go:679 +0x1b2\nencoding/json.(*encodeState).string(0xc003bf8070, 0x0, 0x1a, 0x1)\n\tencoding/json/encode.go:895 +0x5d\nencoding/json.stringEncoder(0xc003bf8070, 0x1996700, 0xc008835730, 0x198, 0x100)\n\tencoding/json/encode.go:610 +0xd9\nencoding/json.structEncoder.encode(0xc0039fe900, 0x5, 0x8, 0xc003929830, 0xc003bf8070, 0x1b762a0, 0xc008835700, 0x199, 0x740100)\n\tencoding/json/encode.go:664 +0x306\nencoding/json.ptrEncoder.encode(0xc003929860, 0xc003bf8070, 0x1a67fa0, 0xc008835700, 0x16, 0x1a60100)\n\tencoding/json/encode.go:810 +0xb1\nencoding/json.(*encodeState).reflectValue(0xc003bf8070, 0x1a67fa0, 0xc008835700, 0x16, 0x100)\n\tencoding/json/encode.go:337 +0x82\nencoding/json.(*encodeState).marshal(0xc003bf8070, 0x1a67fa0, 0xc008835700, 0xc000110100, 0x0, 0x0)\n\tencoding/json/encode.go:309 +0x10b\nencoding/json.Marshal(0x1a67fa0, 0xc008835700, 0x1a, 0x1a67fa0, 0xc008835700, 0x98d576, 0xbfc502f555c485f7)\n\tencoding/json/encode.go:161 +0x52\ngithub.com/mattermost/mattermost-server/v5/model.(*Status).ToClusterJson(...)\n\tgithub.com/mattermost/mattermost-server/v5@/model/status.go:39\ngithub.com/mattermost/mattermost-server/v5/app.(*App).AddStatusCache(0xc007cfa5a0, 0xc008835700)\n\tgithub.com/mattermost/mattermost-server/v5@/app/status.go:22 +0x9e\ngithub.com/mattermost/mattermost-server/v5/app.(*App).SetStatusOnline(0xc007cfa5a0, 0xc005e9e980, 0x1a, 0x0)\n\tgithub.com/mattermost/mattermost-server/v5@/app/status.go:200 +0x194\ngithub.com/mattermost/mattermost-server/v5/api4.createPost(0xc009804700, 0x200f500, 0xc006e97960, 0xc007980200)\n\tgithub.com/mattermost/mattermost-server/v5@/api4/post.go:89 +0x730\ngithub.com/mattermost/mattermost-server/v5/web.Handler.ServeHTTP(0xc000c8fce0, 0x1dbc528, 0x2b45670, 0xa, 0x10001, 0x0, 0x0, 0x200f500, 0xc006e97960, 0xc007980200)\n\tgithub.com/mattermost/mattermost-server/v5@/web/handlers.go:212 +0x1e9a\ngithub.com/NYTimes/gziphandler.GzipHandlerWithOpts.func1.1(0x200ef80, 0xc009be9b20, 0xc007980200)\n\tgithub.com/NYTimes/[email protected]/gzip.go:336 +0x23f\nnet/http.HandlerFunc.ServeHTTP(0xc003be7620, 0x200ef80, 0xc009be9b20, 0xc007980200)\n\tnet/http/server.go:2007 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000100180, 0x200ef80, 0xc009be9b20, 0xc007980000)\n\tgithub.com/gorilla/[email protected]/mux.go:212 +0xe2\ngithub.com/mattermost/mattermost-server/v5/app.(*RateLimiter).RateLimitHandler.func1(0x200ef80, 0xc009be9b20, 0xc007980000)\n\tgithub.com/mattermost/mattermost-server/v5@/app/ratelimit.go:108 +0xc8\nnet/http.HandlerFunc.ServeHTTP(0xc004752440, 0x200ef80, 0xc009be9b20, 0xc007980000)\n\tnet/http/server.go:2007 +0x44\nnet/http.serverHandler.ServeHTTP(0xc003f20380, 0x200ef80, 0xc009be9b20, 0xc007980000)\n\tnet/http/server.go:2802 +0xa4\nnet/http.(*conn).serve(0xc00990d860, 0x2015100, 0xc009804580)\n\tnet/http/server.go:1890 +0x875\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:2927 +0x38e","source":"httpserver"}

mattermost: {"level":"error","ts":1597215832.1530461,"caller":"http/server.go:3053","msg":"http: panic serving 127.0.0.1:49088: runtime error: invalid memory address or nil pointer dereference\ngoroutine 10231907 [running]:\nnet/http.(*conn).serve.func1(0xc004766640)\n\tnet/http/server.go:1767 +0x139\npanic(0x1a5fc40, 0x2ef9ba0)\n\truntime/panic.go:679 +0x1b2\nencoding/json.(*encodeState).marshal.func1(0xc0061447b0)\n\tencoding/json/encode.go:305 +0x9a\npanic(0x1a5fc40, 0x2ef9ba0)\n\truntime/panic.go:679 +0x1b2\nencoding/json.(*encodeState).string(0xc003af4070, 0x0, 0x1a, 0x1)\n\tencoding/json/encode.go:895 +0x5d\nencoding/json.stringEncoder(0xc003af4070, 0x1996700, 0xc007f96bb0, 0x198, 0x100)\n\tencoding/json/encode.go:610 +0xd9\nencoding/json.structEncoder.encode(0xc0039fe900, 0x5, 0x8, 0xc003929830, 0xc003af4070, 0x1b762a0, 0xc007f96b80, 0x199, 0x740100)\n\tencoding/json/encode.go:664 +0x306\nencoding/json.ptrEncoder.encode(0xc003929860, 0xc003af4070, 0x1a67fa0, 0xc007f96b80, 0x16, 0x1a60100)\n\tencoding/json/encode.go:810 +0xb1\nencoding/json.(*encodeState).reflectValue(0xc003af4070, 0x1a67fa0, 0xc007f96b80, 0x16, 0x100)\n\tencoding/json/encode.go:337 +0x82\nencoding/json.(*encodeState).marshal(0xc003af4070, 0x1a67fa0, 0xc007f96b80, 0xc000110100, 0x0, 0x0)\n\tencoding/json/encode.go:309 +0x10b\nencoding/json.Marshal(0x1a67fa0, 0xc007f96b80, 0x1a, 0x1a67fa0, 0xc007f96b80, 0x98d576, 0xbfc502f6091bce76)\n\tencoding/json/encode.go:161 +0x52\ngithub.com/mattermost/mattermost-server/v5/model.(*Status).ToClusterJson(...)\n\tgithub.com/mattermost/mattermost-server/v5@/model/status.go:39\ngithub.com/mattermost/mattermost-server/v5/app.(*App).AddStatusCache(0xc001e96780, 0xc007f96b80)\n\tgithub.com/mattermost/mattermost-server/v5@/app/status.go:22 +0x9e\ngithub.com/mattermost/mattermost-server/v5/app.(*App).SetStatusOnline(0xc001e96780, 0xc005e9e980, 0x1a, 0x0)\n\tgithub.com/mattermost/mattermost-server/v5@/app/status.go:200 +0x194\ngithub.com/mattermost/mattermost-server/v5/wsapi.(*API).userUpdateActiveStatus(0xc001e82c60, 0xc00941e340, 0x1, 0x1)\n\tgithub.com/mattermost/mattermost-server/v5@/wsapi/user.go:60 +0x112\ngithub.com/mattermost/mattermost-server/v5/wsapi.webSocketHandler.ServeWebSocket(0xc001e96780, 0xc001e82c90, 0xc006c78a50, 0xc00941e340)\n\tgithub.com/mattermost/mattermost-server/v5@/wsapi/websocket_handler.go:51 +0x232\ngithub.com/mattermost/mattermost-server/v5/app.(*WebSocketRouter).ServeWebSocket(0xc000f43920, 0xc006c78a50, 0xc00941e340)\n\tgithub.com/mattermost/mattermost-server/v5@/app/websocket_router.go:87 +0xea\ngithub.com/mattermost/mattermost-server/v5/app.(*WebConn).readPump(0xc006c78a50)\n\tgithub.com/mattermost/mattermost-server/v5@/app/web_conn.go:153 +0x15e\ngithub.com/mattermost/mattermost-server/v5/app.(*WebConn).Pump(0xc006c78a50)\n\tgithub.com/mattermost/mattermost-server/v5@/app/web_conn.go:117 +0x79\ngithub.com/mattermost/mattermost-server/v5/api4.connectWebSocket(0xc0095695c0, 0x200f500, 0xc003a69a40, 0xc006acb400)\n\tgithub.com/mattermost/mattermost-server/v5@/api4/websocket.go:39 +0x3ee\ngithub.com/mattermost/mattermost-server/v5/web.Handler.ServeHTTP(0xc000c8fce0, 0x1dbc4b8, 0x2b69580, 0x10, 0x100, 0x0, 0x0, 0x200f500, 0xc003a69a40, 0xc006acb400)\n\tgithub.com/mattermost/mattermost-server/v5@/web/handlers.go:212 +0x1e9a\ngithub.com/NYTimes/gziphandler.GzipHandlerWithOpts.func1.1(0x200ef80, 0xc00a170000, 0xc006acb400)\n\tgithub.com/NYTimes/[email protected]/gzip.go:336 +0x23f\nnet/http.HandlerFunc.ServeHTTP(0xc003d085d0, 0x200ef80, 0xc00a170000, 0xc006acb400)\n\tnet/http/server.go:2007 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000100180, 0x200ef80, 0xc00a170000, 0xc006acb200)\n\tgithub.com/gorilla/[email protected]/mux.go:212 +0xe2\ngithub.com/mattermost/mattermost-server/v5/app.(*RateLimiter).RateLimitHandler.func1(0x200ef80, 0xc00a170000, 0xc006acb200)\n\tgithub.com/mattermost/mattermost-server/v5@/app/ratelimit.go:108 +0xc8\nnet/http.HandlerFunc.ServeHTTP(0xc004752440, 0x200ef80, 0xc00a170000, 0xc006acb200)\n\tnet/http/server.go:2007 +0x44\nnet/http.serverHandler.ServeHTTP(0xc003f20380, 0x200ef80, 0xc00a170000, 0xc006acb200)\n\tnet/http/server.go:2802 +0xa4\nnet/http.(*conn).serve(0xc004766640, 0x2015100, 0xc009569140)\n\tnet/http/server.go:1890 +0x875\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:2927 +0x38e","source":"httpserver"}

The error occured randomly and we are not able to reproduce it. A simple restart of the process fixed it for the moment.

The errro hasen't occured on older mattermost versions, for example 5.22.1.

Regards,
Kilian

[agnivade]

Thanks @discostur. Sorry for the trouble you are having. This was actually caught by our load tests, and I had attempted a PR here: https://github.com/mattermost/mattermost-server/pull/14484. But then I couldn't really repro it any more and closed it.

This isn't a regression and has always been there AFAIK. It's just that you are unluckily observing this now.

I guess I will reopen the PR and get it merged. Thanks for filing a ticket.

[discostur]

@agnivade thanks for your fast response! looking forward to the new version when your fix gets merged ;)