Summary
When execing into the container and running mattermost commands mattermost appears to attempt to do maintenance on the plugins. It seems to start by trying to delete existing prepackaged plugins, then attempts to unpack them from the archives.
The issue is when the server is running some files for the plugins are in use and aren’t deleted. This results in a state where the plugins are missing files, but won’t be overwritten because the folder already exists.
I’ve run into this issue in 5.14.2, 15.14.3, and 5.15.0.
Steps to reproduce
Setup a basic stack with server and database using the prod images in docker hub (or build from Dockerfile). Go to the system consoel and enable some plugins, like Jenkins and WelcomeBot. Enable debug level logs.
Run docker exec containerid mattermost version
Restart the container either with docker restart or docker service update --force
Go back to the system console and open plugin management, you’ll see the plugins you enabled no longer show up in the list and no longer function.
Expected behavior
When running cli commands I would expect it to not break things that are seemingly not relevant to the action I was attempting to perform.
Observed behavior
[root@ip-10-114-7-105 ~]# docker exec 4400b1c9947d mattermost version
{“level”:“info”,“ts”:1568784302.063578,“caller”:“utils/i18n.go:83”,“msg”:“Loaded system translations for ‘en’ from ‘/mattermost/i18n/en.json’”}
{“level”:“info”,“ts”:1568784302.066977,“caller”:“app/server_app_adapters.go:58”,“msg”:“Server is initializing…”}
{“level”:“debug”,“ts”:1568784302.0676672,“caller”:“utils/html.go:31”,“msg”:“Parsing server templates at /mattermost/templates”}
{“level”:“info”,“ts”:1568784302.0698736,“caller”:“sqlstore/supplier.go:223”,“msg”:“Pinging SQL master database”}
{“level”:“debug”,“ts”:1568784302.245916,“caller”:“sqlstore/preference_store.go:41”,“msg”:“Deleting any unused pre-release features”}
{“level”:“error”,“ts”:1568784302.2549455,“caller”:“app/server_app_adapters.go:125”,“msg”:“SiteURL must be set. Some features will operate incorrectly if the SiteURL is not set. See documentation for details: <>.com/default-site-url”}
{“level”:“debug”,“ts”:1568784302.2867243,“caller”:“filesstore/localstore.go:33”,“msg”:“Able to write files to local storage.”}
{“level”:“debug”,“ts”:1568784302.2901008,“caller”:“utils/license.go:84”,“msg”:“We could not find the license key in the database or on disk at /mattermost/config/mattermost.mattermost-license”}
{“level”:“info”,“ts”:1568784302.2915592,“caller”:“app/license.go:41”,“msg”:“License key from https://mattermost.com required to unlock enterprise features.”}
{“level”:“info”,“ts”:1568784302.3058558,“caller”:“mlog/log.go:165”,“msg”:“Starting up plugins”}
{“level”:“info”,“ts”:1568784302.305944,“caller”:“app/plugin.go:195”,“msg”:“Syncing plugins from the file store”}
{“level”:“debug”,“ts”:1568784302.3884583,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“antivirus”}
{“level”:“debug”,“ts”:1568784302.5222385,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“com.github.manland.mattermost-plugin-gitlab”}
{“level”:“debug”,“ts”:1568784302.7039819,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“com.mattermost.aws-sns”}
{“level”:“debug”,“ts”:1568784302.8233697,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“com.mattermost.custom-attributes”}
{“level”:“debug”,“ts”:1568784302.9671445,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“com.mattermost.nps”}
{“level”:“error”,“ts”:1568784303.1162744,“caller”:“app/plugin.go:219”,“msg”:“Failed to remove local installation of managed plugin before sync”,“plugin_id”:“com.mattermost.nps”,“error”:“removePlugin: Unable to delete plugin, directory not empty”}
{“level”:“debug”,“ts”:1568784303.1180725,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“com.mattermost.welcomebot”}
{“level”:“error”,“ts”:1568784303.2182393,“caller”:“app/plugin.go:219”,“msg”:“Failed to remove local installation of managed plugin before sync”,“plugin_id”:“com.mattermost.welcomebot”,“error”:“removePlugin: Unable to delete plugin, directory not empty”}
{“level”:“debug”,“ts”:1568784303.2198906,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“github”}
{“level”:“debug”,“ts”:1568784303.3731613,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“jenkins”}
{“level”:“error”,“ts”:1568784303.4779425,“caller”:“app/plugin.go:219”,“msg”:“Failed to remove local installation of managed plugin before sync”,“plugin_id”:“jenkins”,“error”:“removePlugin: Unable to delete plugin, directory not empty”}
{“level”:“debug”,“ts”:1568784303.4796555,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“jira”}
{“level”:“debug”,“ts”:1568784303.7167351,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“mattermost-autolink”}
{“level”:“debug”,“ts”:1568784303.7961576,“caller”:“app/plugin.go:217”,“msg”:“Removing local installation of managed plugin before sync”,“plugin_id”:“zoom”}
{“level”:“info”,“ts”:1568784303.8985367,“caller”:“app/plugin.go:230”,“msg”:“Found no files in plugins file store”}
{“level”:“error”,“ts”:1568784308.7453022,“caller”:“app/plugin.go:166”,“msg”:“Failed to unpack prepackaged plugin”,“error”:“installPluginLocally: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., destination already exists”,“path”:"/mattermost/prepackaged_plugins/mattermost-plugin-jenkins-v1.0.0.tar.gz"}
{“level”:“error”,“ts”:1568784310.453479,“caller”:“app/plugin.go:166”,“msg”:“Failed to unpack prepackaged plugin”,“error”:“installPluginLocally: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., destination already exists”,“path”:"/mattermost/prepackaged_plugins/mattermost-plugin-nps-v1.0.3.tar.gz"}
{“level”:“error”,“ts”:1568784310.7147207,“caller”:“app/plugin.go:166”,“msg”:“Failed to unpack prepackaged plugin”,“error”:“installPluginLocally: Unable to move plugin from temporary directory to final destination. Another plugin may be using the same directory name., destination already exists”,“path”:"/mattermost/prepackaged_plugins/mattermost-plugin-welcomebot-v1.1.0.tar.gz"}
{“level”:“debug”,“ts”:1568784311.604409,“caller”:“plugin/health_check.go:31”,“msg”:“Enabling plugin health check job”,“interval_s”:30}
{“level”:“debug”,“ts”:1568784311.6044757,“caller”:“plugin/health_check.go:49”,“msg”:“Plugin health check job starting.”}
{“level”:“info”,“ts”:1568784311.6045232,“caller”:“app/server.go:216”,“msg”:“Current version is 5.15.0 (5.15.0/Mon Sep 16 19:14:33 UTC 2019/f4f7fd0829d74fcd5e290fd1ba76845af18e553e/ae36beb963c7fe86e95bf33a0ea41b1fe107de9e)”}
{“level”:“info”,“ts”:1568784311.6045487,“caller”:“app/server.go:217”,“msg”:“Enterprise Enabled: true”}
{“level”:“info”,“ts”:1568784311.6045916,“caller”:“app/server.go:219”,“msg”:“Current working directory is /mattermost”}
{“level”:“info”,“ts”:1568784311.6046174,“caller”:“app/server.go:220”,“msg”:“Loaded config”,“source”:“file:///mattermost/config/config.json”}
{“level”:“info”,“ts”:1568784311.7763257,“caller”:“sqlstore/post_store.go:1301”,“msg”:“Post.Message supports at most 16383 characters (65535 bytes)”}
{“level”:“debug”,“ts”:1568784312.0816884,“caller”:“jobs/schedulers.go:29”,“msg”:“Initialising schedulers.”}
{“level”:“error”,“ts”:1568784312.0859077,“caller”:“app/server.go:745”,“msg”:"Elasticsearch.start: Elasticsearch is already stopped, "}
{“level”:“debug”,“ts”:1568784312.0866668,“caller”:“utils/license.go:84”,“msg”:“We could not find the license key in the database or on disk at /mattermost/config/mattermost.mattermost-license”}
{“level”:“info”,“ts”:1568784312.0878057,“caller”:“app/license.go:41”,“msg”:“License key from <> required to unlock enterprise features.”}
Version: 5.15.0
Build Number: 5.15.0
Build Date: Mon Sep 16 19:14:33 UTC 2019
Build Hash: f4f7fd0829d74fcd5e290fd1ba76845af18e553e
Build Enterprise Ready: true
DB Version: 5.15.0