cannot create team from cli

[fbartels]

a bit as a followup to #9393. If I now try to create a team from the mattermost cli utility a get a segmentation violation error. The interesting part is that as soon as I disable the plugin framework team creation succeeds.

Steps to reproduce

{"level":"info","ts":1537185635.8894925,"caller":"utils/i18n.go:83","msg":"Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'"}
{"level":"info","ts":1537185635.8897147,"caller":"app/app.go:195","msg":"Server is initializing..."}
{"level":"info","ts":1537185635.8976705,"caller":"sqlstore/supplier.go:200","msg":"Pinging SQL master database"}
{"level":"info","ts":1537185635.9392107,"caller":"app/license.go:44","msg":"License key from https://mattermost.com required to unlock enterprise features."}
{"level":"info","ts":1537185635.9594605,"caller":"app/app.go:264","msg":"Stopping Server..."}
{"level":"info","ts":1537185635.9596405,"caller":"app/web_hub.go:120","msg":"stopping websocket hub connections"}
{"level":"warn","ts":1537185635.9597192,"caller":"app/web_hub.go:125","msg":"We appear to have already sent the stop checking for deadlocks command"}
{"level":"info","ts":1537185635.959787,"caller":"sqlstore/supplier.go:797","msg":"Closing SqlStore"}
{"level":"info","ts":1537185635.9600174,"caller":"app/app.go:285","msg":"Server stopped"}
root@matte-31291882:/# mattermost-platform version
{"level":"info","ts":1537189334.3611503,"caller":"utils/i18n.go:83","msg":"Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'"}
{"level":"info","ts":1537189334.3613765,"caller":"app/app.go:195","msg":"Server is initializing..."}
{"level":"info","ts":1537189334.366778,"caller":"sqlstore/supplier.go:200","msg":"Pinging SQL master database"}
{"level":"info","ts":1537189334.4097846,"caller":"app/license.go:44","msg":"License key from https://mattermost.com required to unlock enterprise features."}
Version: 5.3.0
Build Number: 5.3.0
Build Date: Fri Sep 14 13:54:52 UTC 2018
Build Hash: fd21e53365d504155ab87f9bef60b1ab4faeb38d
Build Enterprise Ready: true
DB Version: 5.3.0


root@matte-31291882:/# mattermost team create --name test2 --display_name test2
{"level":"info","ts":1537185593.0710216,"caller":"utils/i18n.go:83","msg":"Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'"}
{"level":"info","ts":1537185593.0712347,"caller":"app/app.go:195","msg":"Server is initializing..."}
{"level":"info","ts":1537185593.0804489,"caller":"sqlstore/supplier.go:200","msg":"Pinging SQL master database"}
{"level":"info","ts":1537185593.112243,"caller":"app/license.go:44","msg":"License key from https://mattermost.com required to unlock enterprise features."}
{"level":"info","ts":1537185593.1123745,"caller":"app/plugin.go:100","msg":"Starting up plugins"}
{"level":"info","ts":1537185593.1276698,"caller":"app/app.go:264","msg":"Stopping Server..."}
{"level":"info","ts":1537185593.1277962,"caller":"app/web_hub.go:120","msg":"stopping websocket hub connections"}
{"level":"warn","ts":1537185593.1278515,"caller":"app/web_hub.go:125","msg":"We appear to have already sent the stop checking for deadlocks command"}
{"level":"info","ts":1537185593.1279001,"caller":"app/plugin.go:156","msg":"Shutting down plugins"}
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xb52992]

goroutine 2303 [running]:
github.com/mattermost/mattermost-server/plugin.(*Environment).RunMultiPluginHook(0x0, 0xc421497f80, 0xd)
        /home/ubuntu/jenkins/workspace/msr/mattermost-platform-release/src/github.com/mattermost/mattermost-server/plugin/environment.go:273 +0x42
github.com/mattermost/mattermost-server/app.(*App).CreateChannel.func1()
        /home/ubuntu/jenkins/workspace/msr/mattermost-platform-release/src/github.com/mattermost/mattermost-server/app/channel.go:206 +0x84
github.com/mattermost/mattermost-server/app.(*App).Go.func1(0xc421a85f80, 0xc4200dc580)
        /home/ubuntu/jenkins/workspace/msr/mattermost-platform-release/src/github.com/mattermost/mattermost-server/app/app.go:483 +0x27
created by github.com/mattermost/mattermost-server/app.(*App).Go
        /home/ubuntu/jenkins/workspace/msr/mattermost-platform-release/src/github.com/mattermost/mattermost-server/app/app.go:482 +0x52

root@matte-31291882:/# mattermost team create --name test3 --display_name test3
{"level":"info","ts":1537185635.8894925,"caller":"utils/i18n.go:83","msg":"Loaded system translations for 'en' from '/opt/mattermost/i18n/en.json'"}
{"level":"info","ts":1537185635.8897147,"caller":"app/app.go:195","msg":"Server is initializing..."}
{"level":"info","ts":1537185635.8976705,"caller":"sqlstore/supplier.go:200","msg":"Pinging SQL master database"}
{"level":"info","ts":1537185635.9392107,"caller":"app/license.go:44","msg":"License key from https://mattermost.com required to unlock enterprise features."}
{"level":"info","ts":1537185635.9594605,"caller":"app/app.go:264","msg":"Stopping Server..."}
{"level":"info","ts":1537185635.9596405,"caller":"app/web_hub.go:120","msg":"stopping websocket hub connections"}
{"level":"warn","ts":1537185635.9597192,"caller":"app/web_hub.go:125","msg":"We appear to have already sent the stop checking for deadlocks command"}
{"level":"info","ts":1537185635.959787,"caller":"sqlstore/supplier.go:797","msg":"Closing SqlStore"}
{"level":"info","ts":1537185635.9600174,"caller":"app/app.go:285","msg":"Server stopped"}

Expected behavior

I can create teams from the mattermost cli

Observed behavior (that appears unintentional)

segmentation violation error

Possible fixes

Error output suggests an error in the plugin framework.

[amyblais]

@fbartels Thank you for letting us know!

Some breaking changes were introduced to the plugin framework in v5.2 - more information can be found here: https://developers.mattermost.com/extend/plugins/migration/.

If the above documentation doesn't seem to apply in your case, just let me know and I'll ping a dev to look at this.

[fbartels]

Hi @amyblais,

yes I am aware of the Plugin changes in 5.2. The above example is on a system where all plugins have been deleted (using the admin Web console), but even then I need to completely disable the Plugin functionality of Mattermost to create teams from the cli.

[amyblais]

@mkraft Can you help test the bug report above ^ (#9421 (comment)) - (reason for ping: you're Dev on rotation this week and I need dev's help to test CLI issues).

[mkraft]

@fbartels I'm not reproducing an error running this command on the same commit:

mattermost team create --name test2 --display_name test2

My PluginSettings section from my config/config.json looks like this:

    "PluginSettings": {
        "Enable": true,
        "EnableUploads": false,
        "Directory": "./plugins",
        "ClientDirectory": "./client/plugins",
        "Plugins": {},
        "PluginStates": {}
    },

Are you able to share yours please?

[fbartels]

Hi @mkraft ,

thanks for your response. my Plugin settings look like the following:

  "PluginSettings": {
    "Enable": true,
    "EnableUploads": false,
    "Directory": "./plugins",
    "ClientDirectory": "./client/plugins",
    "Plugins": {
      "kopanowebmeetings": {
        "kwmserverinternalurl": "http://127.0.0.1:8778",
        "kwmserverurl": "/",
        "stunuri": "stun:stun.l.google.com:19302",
        "turnsharedkey": null,
        "turnuri": null,
        "turnusername": "mattermost-kwm-user"
      }
    },
    "PluginStates": {
      "kopanowebmeetings": {
        "Enable": true
      }
    }
  },

The settings in there are from our own mattermost plugin. in my test I have deleted the plugin through the "System Console" and once remove the plugin itself is also gone from the plugin directory.

I had a look with one of our go developers and he was able to trace the issue down to a timing issue where (since mattermost startup and shutdown happen quite fast with the cli utility) teams and channel try to access a variable that was already set to nil on shutdown.

We are making a quick test if that is really the case and if it is, he will give a more concrete issue description.

[longsleep]

@mkraft @amyblais This is a timing issue when running Mattermost as a commandline utility which lets Mattermost run for a very short time only and essentially immediately triggers shutdown. During startup various Go routines are started accessing all kinds of stuff. If these Go routines run while already shutting down, the problem from above can appear.

In this particular case, app.Plugins is set to nil in https://github.com/mattermost/mattermost-server/blob/0788cdcadfb5d76b08758f42f01521b45ea76362/app/plugin.go#L162 - If any of the plugin hooks like in https://github.com/mattermost/mattermost-server/blob/531897b1f0d8176c1f983f921f1d1de618db0131/app/team.go#L804 have already been added as Go routine, this Go routine might run with a nil value for a.plugins leading to above error.

A workaround to this particular issue is, to remove https://github.com/mattermost/mattermost-server/blob/0788cdcadfb5d76b08758f42f01521b45ea76362/app/plugin.go#L162 line (avoid setting a.plugins to nil on shutdown).

The whole issue is larger, since shutdown does not terminate/abort running Go routines which might access values which got cleaned up while shutting down.

[amyblais]

Thank you all, I created a ticket here for our devs to investigate: https://mattermost.atlassian.net/browse/MM-12250.

[hanzei]

Hey @longsleep @fbartels,

Sorry for the late answer. Would you be open on trying to repo this bug on the latest server?

[fbartels]

Hi @hanzei,

sure. Which version do you mean with latest server? 5.10.0 or head of the git repository?

[hanzei]

v5.10.0 should be fine.

[fbartels]

Hi @hanzei,

I made some quick tests based on 5.10.0 and the script that was previously crashing Mattermost now no longer does so. Issue seems resolved.

Thanks