We're Hiring!

Mattermost, Inc.

Http: panic serving on start 5.26

Hello.

Summary

After upgrade 5.25.3 to 5.26 server mattermost work slow.

Steps to reproduce

I use 5.26. on Ubuntu 20.04.1 LTS (GNU/Linux 5.4.0-42-generic x86_64) with MySQL.
After upgrade
Started server normaly
Connect to authentification form normaly
But loading web form after authentication is very slow

Observed behavior

In logs i get

{"level":"info","ts":1597680017.604918,"caller":"sqlstore/supplier.go:227","msg":"Pinging SQL","database":"master"} {"level":"info","ts":1597680019.2873225,"caller":"app/license.go:54","msg":"License key from https://mattermost.com required to unlock enterprise features."} {"level":"info","ts":1597680019.5445077,"caller":"app/server.go:440","msg":"Current version is 5.26.0 (5.26.0/Wed Aug 12 20:40:27 UTC 2020/773ab352e845e1313c4b6a273ad1aae19e31f58c/2b8058134209f7600afade1268a7bae10fbe65ae)","current_version":"5.26.0","build_number":"5.26.0","build_date":"Wed Aug 12 20:40:27 UTC 2020","build_hash":"773ab352e845e1313c4b6a273ad1aae19e31f58c","build_hash_enterprise":"2b8058134209f7600afade1268a7bae10fbe65ae"} {"level":"info","ts":1597680019.5446043,"caller":"app/server.go:449","msg":"Enterprise Build","enterprise_build":true} {"level":"info","ts":1597680019.5446403,"caller":"app/server.go:455","msg":"Printing current working","directory":"/opt/mattermost"} {"level":"info","ts":1597680019.5446599,"caller":"app/server.go:456","msg":"Loaded config","source":"file:///opt/mattermost/config/config.json"} {"level":"info","ts":1597680019.6189072,"caller":"sqlstore/post_store.go:1597","msg":"Post.Message has size restrictions","max_characters":16383,"max_bytes":65535} {"level":"info","ts":1597680019.7175636,"caller":"app/server.go:479","msg":"Shutting down advanced logging"} {"level":"info","ts":1597680019.7191744,"caller":"bleveengine/bleve.go:267","msg":"UpdateConf Bleve"} {"level":"info","ts":1597680020.772833,"caller":"app/server.go:783","msg":"Starting Server..."} {"level":"info","ts":1597680020.7739294,"caller":"app/server.go:860","msg":"Server is listening on [::]:8065","address":"[::]:8065"} {"level":"info","ts":1597680020.7740173,"caller":"commands/server.go:106","msg":"Sending systemd READY notification."} {"level":"info","ts":1597680027.4229162,"caller":"mlog/log.go:176","msg":"Starting up plugins"} {"level":"info","ts":1597680027.4240222,"caller":"app/plugin.go:211","msg":"Syncing plugins from the file store"} {"level":"warn","ts":1597680027.5525587,"caller":"app/plugin.go:231","msg":"Skipping sync for unmanaged plugin","plugin_id":"rssfeed"} {"level":"info","ts":1597680027.6094174,"caller":"app/plugin.go:271","msg":"Syncing plugin from file store","bundle":"plugins/com.github.matterpoll.matterpoll.tar.gz"} {"level":"info","ts":1597680027.6097116,"caller":"app/plugin.go:271","msg":"Syncing plugin from file store","bundle":"plugins/zoom.tar.gz"} {"level":"info","ts":1597680027.6094053,"caller":"app/plugin.go:271","msg":"Syncing plugin from file store","bundle":"plugins/com.github.scottleedavis.mattermost-plugin-remind.tar.gz"} {"level":"info","ts":1597680027.609489,"caller":"app/plugin.go:271","msg":"Syncing plugin from file store","bundle":"plugins/custom-css-10124.tar.gz"} {"level":"info","ts":1597680027.6095157,"caller":"app/plugin.go:271","msg":"Syncing plugin from file store","bundle":"plugins/com.mattermost.plugin-todo.tar.gz"} {"level":"info","ts":1597680027.6095443,"caller":"app/plugin.go:271","msg":"Syncing plugin from file store","bundle":"plugins/topdf.tar.gz"} {"level":"error","ts":1597680050.1454568,"caller":"app/plugin.go:802","msg":"Failed to install prepackaged plugin","path":"/opt/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.1.tar.gz","error":"Failed to install extracted prepackaged plugin /opt/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.1.tar.gz: installExtractedPlugin: Невозможно переместить плагин из временного каталога в конечный пункт назначения. Другой плагин может использовать то же имя каталога., destination already exists","errorVerbose":"installExtractedPlugin: Невозможно переместить плагин из временного каталога в конечный пункт назначения. Другой плагин может использовать то же имя каталога., destination already exists\nFailed to install extracted prepackaged plugin /opt/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.1.tar.gz\ngithub.com/mattermost/mattermost-server/v5/app.(*App).processPrepackagedPlugin\n\tgithub.com/mattermost/mattermost-server/v5/app/plugin.go:854\ngithub.com/mattermost/mattermost-server/v5/app.(*App).processPrepackagedPlugins.func2\n\tgithub.com/mattermost/mattermost-server/v5/app/plugin.go:800\nruntime.goexit\n\truntime/asm_amd64.s:1373"} {"level":"error","ts":1597680052.3376102,"caller":"app/plugin.go:802","msg":"Failed to install prepackaged plugin","path":"/opt/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.4-linux-amd64.tar.gz","error":"Failed to install extracted prepackaged plugin /opt/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.4-linux-amd64.tar.gz: installExtractedPlugin: Невозможно переместить плагин из временного каталога в конечный пункт назначения. Другой плагин может использовать то же имя каталога., destination already exists","errorVerbose":"installExtractedPlugin: Невозможно переместить плагин из временного каталога в конечный пункт назначения. Другой плагин может использовать то же имя каталога., destination already exists\nFailed to install extracted prepackaged plugin /opt/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.4-linux-amd64.tar.gz\ngithub.com/mattermost/mattermost-server/v5/app.(*App).processPrepackagedPlugin\n\tgithub.com/mattermost/mattermost-server/v5/app/plugin.go:854\ngithub.com/mattermost/mattermost-server/v5/app.(*App).processPrepackagedPlugins.func2\n\tgithub.com/mattermost/mattermost-server/v5/app/plugin.go:800\nruntime.goexit\n\truntime/asm_amd64.s:1373"} {"level":"info","ts":1597680052.8198671,"caller":"mlog/sugar.go:19","msg":"Ensuring Surveybot exists","plugin_id":"com.mattermost.nps"} {"level":"info","ts":1597680053.356231,"caller":"jobs/workers.go:77","msg":"Starting workers"} {"level":"info","ts":1597680053.408569,"caller":"app/license.go:54","msg":"License key from https://mattermost.com required to unlock enterprise features."} {"level":"info","ts":1597680053.41388,"caller":"jobs/schedulers.go:78","msg":"Starting schedulers."} {"level":"error","ts":1597680056.1287546,"caller":"http/server.go:3088","msg":"http: panic serving 127.0.0.1:53856: runtime error: invalid memory address or nil pointer dereference\ngoroutine 3550 [running]:\nnet/http.(*conn).serve.func1(0xc00186ebe0)\n\tnet/http/server.go:1800 +0x139\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:975 +0x3e3\ngithub.com/getsentry/sentry-go/http.(*Handler).recoverWithSentry(0xc001354340, 0xc004cffe30, 0xc004d32700)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:89 +0x148\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:969 +0x166\ngithub.com/mattermost/mattermost-server/v5/app.(*App).GetSidebarCategories(0xc0049234a0, 0xc004a9a862, 0x1a, 0xc004a9a883, 0x1a, 0x173fc68f415, 0x17496e7bc15)\n\tgithub.com/mattermost/mattermost-server/v5/app/channel.go:2632 +0x86\ngithub.com/mattermost/mattermost-server/v5/api4.getCategoriesForTeamForUser(0xc004c9b8c0, 0x26f10e0, 0xc004c9b880, 0xc004d32a00)\n\tgithub.com/mattermost/mattermost-server/v5/api4/channel.go:1892 +0x171\ngithub.com/mattermost/mattermost-server/v5/web.Handler.ServeHTTP(0xc0015e40b0, 0x23c8ed0, 0x354c468, 0x1b, 0x10001, 0x0, 0x0, 0x26f4220, 0xc001a66770, 0xc004d32a00)\n\tgithub.com/mattermost/mattermost-server/v5/web/handlers.go:240 +0x1d1a\ngithub.com/NYTimes/gziphandler.GzipHandlerWithOpts.func1.1(0x26f3c60, 0xc004cc4700, 0xc004d32a00)\n\tgithub.com/NYTimes/gziphandler@v1.1.1/gzip.go:336 +0x211\nnet/http.HandlerFunc.ServeHTTP(0xc001a45a40, 0x26f3c60, 0xc004cc4700, 0xc004d32a00)\n\tnet/http/server.go:2041 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000250540, 0x26f3c60, 0xc004cc4700, 0xc004d32800)\n\tgithub.com/gorilla/mux@v1.7.4/mux.go:210 +0xe2\ngithub.com/getsentry/sentry-go/http.(*Handler).Handle.func1(0x26f3c60, 0xc004cc4700, 0xc004d32700)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:61 +0x234\nnet/http.HandlerFunc.ServeHTTP(0xc001f58460, 0x26f3c60, 0xc004cc4700, 0xc004d32700)\n\tnet/http/server.go:2041 +0x44\nnet/http.serverHandler.ServeHTTP(0xc0001f21c0, 0x26f3c60, 0xc004cc4700, 0xc004d32700)\n\tnet/http/server.go:2836 +0xa3\nnet/http.(*conn).serve(0xc00186ebe0, 0x26fc820, 0xc003b77680)\n\tnet/http/server.go:1924 +0x86c\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:2962 +0x35c","source":"httpserver"} {"level":"error","ts":1597680056.1585217,"caller":"http/server.go:3088","msg":"http: panic serving [::1]:46696: runtime error: invalid memory address or nil pointer dereference\ngoroutine 3776 [running]:\nnet/http.(*conn).serve.func1(0xc001de4960)\n\tnet/http/server.go:1800 +0x139\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:975 +0x3e3\ngithub.com/getsentry/sentry-go/http.(*Handler).recoverWithSentry(0xc001354340, 0xc005197560, 0xc004d33700)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:89 +0x148\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:969 +0x166\ngithub.com/mattermost/mattermost-server/v5/app.(*App).GetSidebarCategories(0xc004923a40, 0xc004a9ab02, 0x1a, 0xc004a9ab23, 0x1a, 0x173fc68f415, 0x17496e7bc15)\n\tgithub.com/mattermost/mattermost-server/v5/app/channel.go:2632 +0x86\ngithub.com/mattermost/mattermost-server/v5/api4.getCategoriesForTeamForUser(0xc005198a40, 0x26f10e0, 0xc005198a00, 0xc004d33a00)\n\tgithub.com/mattermost/mattermost-server/v5/api4/channel.go:1892 +0x171\ngithub.com/mattermost/mattermost-server/v5/web.Handler.ServeHTTP(0xc0015e40b0, 0x23c8ed0, 0x354c468, 0x1b, 0x10001, 0x0, 0x0, 0x26f4220, 0xc001abc700, 0xc004d33a00)\n\tgithub.com/mattermost/mattermost-server/v5/web/handlers.go:240 +0x1d1a\ngithub.com/NYTimes/gziphandler.GzipHandlerWithOpts.func1.1(0x26f3c60, 0xc004cc4b60, 0xc004d33a00)\n\tgithub.com/NYTimes/gziphandler@v1.1.1/gzip.go:336 +0x211\nnet/http.HandlerFunc.ServeHTTP(0xc001a45a40, 0x26f3c60, 0xc004cc4b60, 0xc004d33a00)\n\tnet/http/server.go:2041 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000250540, 0x26f3c60, 0xc004cc4b60, 0xc004d33800)\n\tgithub.com/gorilla/mux@v1.7.4/mux.go:210 +0xe2\ngithub.com/getsentry/sentry-go/http.(*Handler).Handle.func1(0x26f3c60, 0xc004cc4b60, 0xc004d33700)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:61 +0x234\nnet/http.HandlerFunc.ServeHTTP(0xc001f58460, 0x26f3c60, 0xc004cc4b60, 0xc004d33700)\n\tnet/http/server.go:2041 +0x44\nnet/http.serverHandler.ServeHTTP(0xc0001f21c0, 0x26f3c60, 0xc004cc4b60, 0xc004d33700)\n\tnet/http/server.go:2836 +0xa3\nnet/http.(*conn).serve(0xc001de4960, 0x26fc820, 0xc0046fac80)\n\tnet/http/server.go:1924 +0x86c\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:2962 +0x35c","source":"httpserver"} {"level":"error","ts":1597680094.3473387,"caller":"mlog/log.go:190","msg":"You do not have the appropriate permissions.","path":"/api/v4/warn_metrics/status","request_id":"gmpefkgdb38idmege89u9395ty","ip_addr":"192.168.128.66","user_id":"n3yaoyrf9brw9bkxz65zwnicmo","method":"GET","err_where":"Permissions","http_code":403,"err_details":"userId=n3yaoyrf9brw9bkxz65zwnicmo, permission=manage_system"} {"level":"error","ts":1597680094.988071,"caller":"http/server.go:3088","msg":"http: panic serving [::1]:46736: runtime error: invalid memory address or nil pointer dereference\ngoroutine 4238 [running]:\nnet/http.(*conn).serve.func1(0xc004fb0820)\n\tnet/http/server.go:1800 +0x139\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:975 +0x3e3\ngithub.com/getsentry/sentry-go/http.(*Handler).recoverWithSentry(0xc001354340, 0xc003582ea0, 0xc0034ade00)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:89 +0x148\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:969 +0x166\ngithub.com/mattermost/mattermost-server/v5/app.(*App).GetSidebarCategories(0xc0034bd0e0, 0xc0034e9512, 0x1a, 0xc0034e9533, 0x1a, 0x1737ab21eff, 0x174970d5a01)\n\tgithub.com/mattermost/mattermost-server/v5/app/channel.go:2632 +0x86\ngithub.com/mattermost/mattermost-server/v5/api4.getCategoriesForTeamForUser(0xc003584bc0, 0x26f10e0, 0xc003584b80, 0xc003592100)\n\tgithub.com/mattermost/mattermost-server/v5/api4/channel.go:1892 +0x171\ngithub.com/mattermost/mattermost-server/v5/web.Handler.ServeHTTP(0xc0015e40b0, 0x23c8ed0, 0x354c468, 0x1b, 0x10001, 0x0, 0x0, 0x26f4220, 0xc001c476c0, 0xc003592100)\n\tgithub.com/mattermost/mattermost-server/v5/web/handlers.go:240 +0x1d1a\ngithub.com/NYTimes/gziphandler.GzipHandlerWithOpts.func1.1(0x26f3c60, 0xc004f38ee0, 0xc003592100)\n\tgithub.com/NYTimes/gziphandler@v1.1.1/gzip.go:336 +0x211\nnet/http.HandlerFunc.ServeHTTP(0xc001a45a40, 0x26f3c60, 0xc004f38ee0, 0xc003592100)\n\tnet/http/server.go:2041 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000250540, 0x26f3c60, 0xc004f38ee0, 0xc0034adf00)\n\tgithub.com/gorilla/mux@v1.7.4/mux.go:210 +0xe2\ngithub.com/getsentry/sentry-go/http.(*Handler).Handle.func1(0x26f3c60, 0xc004f38ee0, 0xc0034ade00)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:61 +0x234\nnet/http.HandlerFunc.ServeHTTP(0xc001f58460, 0x26f3c60, 0xc004f38ee0, 0xc0034ade00)\n\tnet/http/server.go:2041 +0x44\nnet/http.serverHandler.ServeHTTP(0xc0001f21c0, 0x26f3c60, 0xc004f38ee0, 0xc0034ade00)\n\tnet/http/server.go:2836 +0xa3\nnet/http.(*conn).serve(0xc004fb0820, 0x26fc820, 0xc005224500)\n\tnet/http/server.go:1924 +0x86c\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:2962 +0x35c","source":"httpserver"} {"level":"error","ts":1597680094.995129,"caller":"http/server.go:3088","msg":"http: panic serving 127.0.0.1:53902: runtime error: invalid memory address or nil pointer dereference\ngoroutine 4090 [running]:\nnet/http.(*conn).serve.func1(0xc001d75c20)\n\tnet/http/server.go:1800 +0x139\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:975 +0x3e3\ngithub.com/getsentry/sentry-go/http.(*Handler).recoverWithSentry(0xc001354340, 0xc0035833b0, 0xc003592200)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:89 +0x148\npanic(0x1fb00a0, 0x39a7160)\n\truntime/panic.go:969 +0x166\ngithub.com/mattermost/mattermost-server/v5/app.(*App).GetSidebarCategories(0xc0034bd2c0, 0xc0034e9662, 0x1a, 0xc0034e9683, 0x1a, 0x1737ab21eff, 0x174970d5a01)\n\tgithub.com/mattermost/mattermost-server/v5/app/channel.go:2632 +0x86\ngithub.com/mattermost/mattermost-server/v5/api4.getCategoriesForTeamForUser(0xc003584d00, 0x26f10e0, 0xc003584cc0, 0xc003592500)\n\tgithub.com/mattermost/mattermost-server/v5/api4/channel.go:1892 +0x171\ngithub.com/mattermost/mattermost-server/v5/web.Handler.ServeHTTP(0xc0015e40b0, 0x23c8ed0, 0x354c468, 0x1b, 0x10001, 0x0, 0x0, 0x26f4220, 0xc001c47810, 0xc003592500)\n\tgithub.com/mattermost/mattermost-server/v5/web/handlers.go:240 +0x1d1a\ngithub.com/NYTimes/gziphandler.GzipHandlerWithOpts.func1.1(0x26f3c60, 0xc004f390a0, 0xc003592500)\n\tgithub.com/NYTimes/gziphandler@v1.1.1/gzip.go:336 +0x211\nnet/http.HandlerFunc.ServeHTTP(0xc001a45a40, 0x26f3c60, 0xc004f390a0, 0xc003592500)\n\tnet/http/server.go:2041 +0x44\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc000250540, 0x26f3c60, 0xc004f390a0, 0xc003592300)\n\tgithub.com/gorilla/mux@v1.7.4/mux.go:210 +0xe2\ngithub.com/getsentry/sentry-go/http.(*Handler).Handle.func1(0x26f3c60, 0xc004f390a0, 0xc003592200)\n\tgithub.com/getsentry/sentry-go@v0.6.1/http/sentryhttp.go:61 +0x234\nnet/http.HandlerFunc.ServeHTTP(0xc001f58460, 0x26f3c60, 0xc004f390a0, 0xc003592200)\n\tnet/http/server.go:2041 +0x44\nnet/http.serverHandler.ServeHTTP(0xc0001f21c0, 0x26f3c60, 0xc004f390a0, 0xc003592200)\n\tnet/http/server.go:2836 +0xa3\nnet/http.(*conn).serve(0xc001d75c20, 0x26fc820, 0xc003e61880)\n\tnet/http/server.go:1924 +0x86c\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:2962 +0x35c","source":"httpserver"}

A ticket was opened here: https://mattermost.atlassian.net/browse/MM-27961

1 Like