MM-17489: fixed racy tryExecutePluginCommand (#11780)

* MM-17489: fixed racy tryExecutePluginCommand

* PR feedback

* MM 7971 dockerhost -> localhost && docker -> docker-compose (#10872)

* replace dockerhost with localhost

* remove uneeded setup-max build step (no more dockerhost)

* changes as recommended by @cpanato

* make clean-docker with docker-compose

* added ports to docker-compose.yml (needed for osx).   ignore error for ldapadd (when already exists)

* add clean-old-docker to legacy.mk

* docker-compose stop instead of down for `make stop-docker`

* MM-17117: Updates einterface for FirstLoginSync. (#11737)

* update sampledata users passwords (#11769)

* update sampledata users passwords

* update makefile

* Tweak docker compose setup (#11785)

* fix stray dockerhost mention

* fix stray whitespace

* fix missing mattermost-redix cleanup in clean-old-docker

* absolute path to docker-compose, plus simpler ldap initialization

* allow ldapadd to fail on CI

* MM-16366 - Prevent attachment duplication on import (#11770)

* prevent attachment duplication

* improved tests

* corrected import into a new post

* WIP: a failed attempt to add tests

* remove debugging statements

* fix godoc

* enable plugins when testing

* rework reentrant unit tests

app/command.go

@@ -187,7 +187,7 @@ func (a *App) ExecuteCommand(args *model.CommandArgs) (*model.CommandResponse, *
 	return nil, model.NewAppError("command", "api.command.execute_command.not_found.app_error", map[string]interface{}{"Trigger": trigger}, "", http.StatusNotFound)
 }
 
-// tryExecutePluginCommand attempts to run a built in command based on the given arguments. If no such command can be
+// tryExecuteBuiltInCommand attempts to run a built in command based on the given arguments. If no such command can be
 // found, returns nil for all arguments.
 func (a *App) tryExecuteBuiltInCommand(args *model.CommandArgs, trigger string, message string) (*model.Command, *model.CommandResponse) {
 	provider := GetCommandProvider(trigger)

app/plugin_commands.go

@@ -97,20 +97,29 @@ func (a *App) tryExecutePluginCommand(args *model.CommandArgs) (*model.Command,
 	trigger := parts[0][1:]
 	trigger = strings.ToLower(trigger)
 
+	var matched *PluginCommand
 	a.Srv.pluginCommandsLock.RLock()
-	defer a.Srv.pluginCommandsLock.RUnlock()
-
 	for _, pc := range a.Srv.pluginCommands {
 		if (pc.Command.TeamId == "" || pc.Command.TeamId == args.TeamId) && pc.Command.Trigger == trigger {
-			if pluginsEnvironment := a.GetPluginsEnvironment(); pluginsEnvironment != nil {
+			matched = pc
-				pluginHooks, err := pluginsEnvironment.HooksForPlugin(pc.PluginId)
+			break
-				if err != nil {
-					return pc.Command, nil, model.NewAppError("ExecutePluginCommand", "model.plugin_command.error.app_error", nil, "err="+err.Error(), http.StatusInternalServerError)
-				}
-				response, appErr := pluginHooks.ExecuteCommand(a.PluginContext(), args)
-				return pc.Command, response, appErr
-			}
 		}
 	}
-	return nil, nil, nil
+	a.Srv.pluginCommandsLock.RUnlock()
+	if matched == nil {
+		return nil, nil, nil
+	}
+
+	pluginsEnvironment := a.GetPluginsEnvironment()
+	if pluginsEnvironment == nil {
+		return nil, nil, nil
+	}
+
+	pluginHooks, err := pluginsEnvironment.HooksForPlugin(matched.PluginId)
+	if err != nil {
+		return matched.Command, nil, model.NewAppError("ExecutePluginCommand", "model.plugin_command.error.app_error", nil, "err="+err.Error(), http.StatusInternalServerError)
+	}
+
+	response, appErr := pluginHooks.ExecuteCommand(a.PluginContext(), args)
+	return matched.Command, response, appErr
 }

app/plugin_commands_test.go

@@ -5,6 +5,7 @@ package app
 
 import (
 	"testing"
+	"time"
 
 	"github.com/mattermost/mattermost-server/model"
 	"github.com/mattermost/mattermost-server/utils"
@@ -110,6 +111,110 @@ func TestPluginCommand(t *testing.T) {
 		th.App.RemovePlugin(pluginIds[0])
 	})
 
+	t.Run("re-entrant command registration on config change", func(t *testing.T) {
+		th.App.UpdateConfig(func(cfg *model.Config) {
+			cfg.PluginSettings.Plugins["testloadpluginconfig"] = map[string]interface{}{
+				"TeamId": args.TeamId,
+			}
+		})
+
+		tearDown, pluginIds, activationErrors := SetAppEnvironmentWithPlugins(t, []string{`
+			package main
+
+			import (
+				"github.com/mattermost/mattermost-server/plugin"
+				"github.com/mattermost/mattermost-server/model"
+			)
+
+			type configuration struct {
+				TeamId string
+			}
+
+			type MyPlugin struct {
+				plugin.MattermostPlugin
+
+				configuration configuration
+			}
+
+			func (p *MyPlugin) OnConfigurationChange() error {
+				p.API.LogInfo("OnConfigurationChange")
+				err := p.API.LoadPluginConfiguration(&p.configuration);
+				if err != nil {
+					return err
+				}
+
+				p.API.LogInfo("About to register")
+				err = p.API.RegisterCommand(&model.Command{
+					TeamId: p.configuration.TeamId,
+					Trigger: "plugin",
+					DisplayName: "Plugin Command",
+					AutoComplete: true,
+					AutoCompleteDesc: "autocomplete",
+				})
+				if err != nil {
+					p.API.LogInfo("Registered, with error", err, err.Error())
+					return err
+				}
+				p.API.LogInfo("Registered, without error")
+				return nil
+			}
+
+			func (p *MyPlugin) ExecuteCommand(c *plugin.Context, commandArgs *model.CommandArgs) (*model.CommandResponse, *model.AppError) {
+				p.API.LogInfo("ExecuteCommand")
+				// Saving the plugin config eventually results in a call to
+				// OnConfigurationChange. This used to deadlock on account of
+				// effectively acquiring a RWLock reentrantly.
+				err := p.API.SavePluginConfig(map[string]interface{}{
+					"TeamId": p.configuration.TeamId,
+				})
+				if err != nil {
+					p.API.LogError("Failed to save plugin config", err, err.Error())
+					return nil, err
+				}
+				p.API.LogInfo("ExecuteCommand, saved plugin config")
+
+				return &model.CommandResponse{
+					ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL,
+					Text: "text",
+				}, nil
+			}
+
+			func main() {
+				plugin.ClientMain(&MyPlugin{})
+			}
+		`}, th.App, th.App.NewPluginAPI)
+		defer tearDown()
+
+		require.Len(t, activationErrors, 1)
+		require.Nil(t, nil, activationErrors[0])
+
+		wait := make(chan bool)
+		killed := false
+		go func() {
+			defer close(wait)
+
+			resp, err := th.App.ExecuteCommand(args)
+
+			// Ignore if we kill below.
+			if !killed {
+				require.Nil(t, err)
+				require.Equal(t, model.COMMAND_RESPONSE_TYPE_EPHEMERAL, resp.ResponseType)
+				require.Equal(t, "text", resp.Text)
+			}
+		}()
+
+		select {
+		case <-wait:
+		case <-time.After(10 * time.Second):
+			killed = true
+		}
+
+		th.App.RemovePlugin(pluginIds[0])
+		if killed {
+			t.Fatal("execute command appears to have deadlocked")
+		}
+	})
+
 	t.Run("error after plugin command unregistered", func(t *testing.T) {
 		_, err := th.App.ExecuteCommand(args)
 		require.NotNil(t, err)

app/plugin_hooks_test.go

@@ -46,6 +46,12 @@ func SetAppEnvironmentWithPlugins(t *testing.T, pluginCode []string, app *App, a
 		_, _, activationErr := env.Activate(pluginId)
 		pluginIds = append(pluginIds, pluginId)
 		activationErrors = append(activationErrors, activationErr)
+
+		app.UpdateConfig(func(cfg *model.Config) {
+			cfg.PluginSettings.PluginStates[pluginId] = &model.PluginState{
+				Enable: true,
+			}
+		})
 	}
 
 	return func() {