Docker Prod Server: Using CLI Breaks Plugins

Troubleshooting
1

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

2

@jeff_mm, I’m sorry you’ve run into this class of problems. We recently triaged a similar issue over at https://mattermost.atlassian.net/browse/MM-18312. The root cause is the manner in which our CLI starts up, invoking much of the same share code with the server.

We’re in the midst of re-working our CLI to function more akin to an API interacting with a server. See https://github.com/mattermost/mmctl for how this is expected to look when it’s folded into the server proper. Given the work here, we decided not to change the way the CLI works with plugins (or worse in some cases: tries to update the database schema, etc.)

For the time being, I might suggest spawning a new container that isn’t part of your load balanced cluster in which to use the CLI. Might that be a suitable workaround for your usage of the CLI?

3

Yes, that would probably be fine. Would it be sufficient to provide this container RO access to the same mounts the primary server container gets RW on?

4

Yes, that should suffice! I suspect the only reason it needs access at all is for the config.json. If that’s the case, you might also want to consider moving your config to the database as described in https://docs.mattermost.com/administration/config-in-database.html, simplifying your setup as a result.