diff --git a/pkg/plugins/pluggable/connection.go b/pkg/plugins/pluggable/connection.go index 51ab41123..b2b7d01d2 100644 --- a/pkg/plugins/pluggable/connection.go +++ b/pkg/plugins/pluggable/connection.go @@ -122,7 +122,7 @@ func (c *PluginConnection) Start(ctx context.Context, pluginCfg io.Reader) error logger := hclog.New(&hclog.LoggerOptions{ Name: "porter", Output: c.logsWriter, - Level: hclog.Warn, + Level: hclog.Debug, JSONFormat: true, }) c.client = plugin.NewClient(&plugin.ClientConfig{ @@ -337,6 +337,13 @@ func (c *PluginConnection) collectPluginLogs(ctx context.Context) { continue } + // This message is always printed when a plugin exists + // polluting the output. This is hardcoded in hashicorp/go-plugin. + // Always convert it to a debug log. + if msg == "plugin process exited" { + pluginLog["@level"] = "debug" + } + switch pluginLog["@level"] { case "error": _ = span.Error(fmt.Errorf(msg)) diff --git a/tests/integration/plugin_log_level_test.go b/tests/integration/plugin_log_level_test.go new file mode 100644 index 000000000..36c5cd514 --- /dev/null +++ b/tests/integration/plugin_log_level_test.go @@ -0,0 +1,67 @@ +//go:build integration + +package integration + +import ( + "fmt" + "testing" + + "get.porter.sh/porter/tests/tester" + "github.com/carolynvs/magex/shx" + "github.com/stretchr/testify/require" +) + +func TestPluginDebugLogsVerbosityArgument(t *testing.T) { + testcases := []struct { + name string + verbosity string + shouldContain bool + expectedPluginLog string + }{ + {"plugin debug logs", "debug", true, "plugin started"}, + {"plugin info logs doesn't contain plugin process exited", "info", false, "plugin process exited"}, + {"plugin debug logs contains plugin process exited", "debug", true, "plugin process exited"}, + {"plugin info logs", "info", false, "plugin started"}, + } + for _, tc := range testcases { + test, err := tester.NewTest(t) + require.NoError(t, err, "test setup failed") + defer test.Close() + + output, _ := test.RequirePorter("list", "--verbosity", tc.verbosity) + if tc.shouldContain { + require.Contains(t, output, tc.expectedPluginLog) + } else { + require.NotContains(t, output, tc.expectedPluginLog) + } + } +} + +func TestPluginDebugLogsVerbosityEnvironmentVariable(t *testing.T) { + testcases := []struct { + name string + verbosity string + shouldContain bool + expectedPluginLog string + }{ + {"plugin debug logs", "debug", true, "plugin started"}, + {"plugin info logs doesn't contain plugin process exited", "info", false, "plugin process exited"}, + {"plugin debug logs contains plugin process exited", "debug", true, "plugin process exited"}, + {"plugin info logs", "info", false, "plugin started"}, + } + for _, tc := range testcases { + test, err := tester.NewTest(t) + require.NoError(t, err, "test setup failed") + defer test.Close() + + output, _, err := test.RunPorterWith(func(cmd *shx.PreparedCommand) { + cmd.Args("list") + cmd.Env(fmt.Sprintf("PORTER_VERBOSITY=%s", tc.verbosity)) + }) + if tc.shouldContain { + require.Contains(t, output, tc.expectedPluginLog) + } else { + require.NotContains(t, output, tc.expectedPluginLog) + } + } +}