diff --git a/internal/logger/logger.go b/internal/logger/logger.go index 32f355224..15a5a78d7 100644 --- a/internal/logger/logger.go +++ b/internal/logger/logger.go @@ -72,6 +72,8 @@ const ( PolicyProvider componentType = "policyProvider" // Verifier is the component type for verifier. Verifier componentType = "verifier" + // Plugin is the component type for plugin. + Plugin componentType = "plugin" traceIDHeaderName = "traceIDHeaderName" ) diff --git a/pkg/common/plugin/exec.go b/pkg/common/plugin/exec.go index 27693172c..9cbfdd065 100644 --- a/pkg/common/plugin/exec.go +++ b/pkg/common/plugin/exec.go @@ -16,14 +16,18 @@ limitations under the License. package plugin import ( + "bufio" "bytes" "context" + "encoding/json" "fmt" "io" + "os" "os/exec" "strings" "time" + "github.com/deislabs/ratify/internal/logger" "github.com/sirupsen/logrus" ) @@ -32,6 +36,10 @@ const ( waitDuration = time.Second ) +var logOpt = logger.Option{ + ComponentType: logger.Plugin, +} + // Executor is an interface that defines methods to lookup a plugin and execute it. type Executor interface { // ExecutePlugin executes the plugin with the given parameters @@ -92,14 +100,27 @@ func (e *DefaultExecutor) ExecutePlugin(ctx context.Context, pluginPath string, return nil, e.pluginErr(err, stdout.Bytes(), stderr.Bytes()) } - // Copy stderr to caller's buffer in case plugin printed to both - // stdout and stderr for some reason. Ignore failures as stderr is - // only informational. - if e.Stderr != nil && stderr.Len() > 0 { - _, _ = stderr.WriteTo(e.Stderr) + pluginOutputJSON, pluginOutputMsgs := parsePluginOutput(stdout, stderr) + + // Disregards plugin source stream and logs the plugin messages to stderr + for _, msg := range pluginOutputMsgs { + msg := strings.ToLower(msg) + switch { + case strings.HasPrefix(msg, "info"): + msg = strings.Replace(msg, "info: ", "", -1) + logger.GetLogger(ctx, logOpt).Infof("[Plugin] %s", msg) + case strings.HasPrefix(msg, "warn"): + msg = strings.Replace(msg, "warn: ", "", -1) + logger.GetLogger(ctx, logOpt).Warnf("[Plugin] %s", msg) + case strings.HasPrefix(msg, "debug"): + msg = strings.Replace(msg, "debug: ", "", -1) + logger.GetLogger(ctx, logOpt).Debugf("[Plugin] %s", msg) + default: + fmt.Fprintf(os.Stderr, "[Plugin] %s,", msg) + } } - // TODO stdout reader - return stdout.Bytes(), nil + + return pluginOutputJSON, nil } func (e *DefaultExecutor) pluginErr(err error, stdout, stderr []byte) error { @@ -118,3 +139,34 @@ func (e *DefaultExecutor) pluginErr(err error, stdout, stderr []byte) error { func (e *DefaultExecutor) FindInPaths(plugin string, paths []string) (string, error) { return FindInPaths(plugin, paths) } + +func parsePluginOutput(stdout *bytes.Buffer, stderr *bytes.Buffer) ([]byte, []string) { + var obj interface{} + var outputBuffer bytes.Buffer + var jsonBuffer bytes.Buffer + var messages []string + + // Combine stderr and stdout + outputBuffer.Write(stderr.Bytes()) + outputBuffer.Write(stdout.Bytes()) + + scanner := bufio.NewScanner(&outputBuffer) + for scanner.Scan() { + line := scanner.Text() + // Assumes a single JSON object is returned somewhere in the output + // does not handle multiple JSON objects + if strings.Contains(line, "{") { + err := json.NewDecoder(strings.NewReader(line)).Decode(&obj) + if err != nil { + continue + } + + jsonString, _ := json.Marshal(obj) + jsonBuffer.WriteString(string(jsonString)) + } else { + messages = append(messages, line) + } + } + + return jsonBuffer.Bytes(), messages +} diff --git a/pkg/common/plugin/exec_test.go b/pkg/common/plugin/exec_test.go index 95847c6d4..3a506ada4 100644 --- a/pkg/common/plugin/exec_test.go +++ b/pkg/common/plugin/exec_test.go @@ -16,6 +16,7 @@ limitations under the License. package plugin import ( + "bytes" "strings" "testing" ) @@ -44,3 +45,65 @@ func TestPluginErr(t *testing.T) { t.Fatalf("error msg should contain stdErr msg, actual '%v'", err.Error()) } } + +func TestParsePluginOutput_EmptyBuffers(t *testing.T) { + stdOut := bytes.NewBufferString("") + stdErr := bytes.NewBufferString("") + + json, messages := parsePluginOutput(stdOut, stdErr) + + if len(messages) != 0 { + t.Fatalf("unexpected messages, expected 0, got %d", len(messages)) + } + + if len(json) != 0 { + t.Fatalf("unexpected json, expected empty, got '%s'", json) + } +} + +func TestParsePluginOutput_StdErrNonEmpty(t *testing.T) { + stdOut := bytes.NewBufferString("") + stdErr := bytes.NewBufferString("This is a string from std err\n") + + json, messages := parsePluginOutput(stdOut, stdErr) + + if len(messages) != 1 { + t.Fatalf("unexpected messages, expected 1, got %d", len(messages)) + } + + if len(json) != 0 { + t.Fatalf("unexpected json, expected empty, got '%s'", json) + } +} + +func TestParsePluginOutput_StdOutNonEmpty(t *testing.T) { + stdOut := bytes.NewBufferString("{\"key\":\"value\"}\n") + stdErr := bytes.NewBufferString("") + + expectedJSON := []byte(`{"key":"value"}`) + + json, messages := parsePluginOutput(stdOut, stdErr) + + if len(messages) != 0 { + t.Fatalf("unexpected messages, expected 0, got %d", len(messages)) + } + + if !bytes.Equal(expectedJSON, json) { + t.Fatalf("unexpected json, expected '%s', got '%s'", expectedJSON, json) + } +} + +func TestParsePluginOutput_InvalidJson(t *testing.T) { + stdOut := bytes.NewBufferString("This is not a valid json\n") + stdErr := bytes.NewBufferString("") + + json, messages := parsePluginOutput(stdOut, stdErr) + + if len(messages) != 1 { + t.Fatalf("unexpected messages, expected 1, got %d", len(messages)) + } + + if len(json) != 0 { + t.Fatalf("unexpected json, expected empty, got '%s'", json) + } +} diff --git a/pkg/common/plugin/logger/logger.go b/pkg/common/plugin/logger/logger.go new file mode 100644 index 000000000..70f5e740f --- /dev/null +++ b/pkg/common/plugin/logger/logger.go @@ -0,0 +1,70 @@ +/* +Copyright The Ratify Authors. +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + +http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package logger + +import ( + "fmt" + "io" + "log" + "os" +) + +type Logger struct { + infoLogger *log.Logger + debugLogger *log.Logger + warnLogger *log.Logger +} + +func NewLogger() *Logger { + return &Logger{ + infoLogger: log.New(os.Stderr, "INFO: ", 0), + debugLogger: log.New(os.Stderr, "DEBUG: ", 0), + warnLogger: log.New(os.Stderr, "WARN: ", 0), + } +} + +func (l *Logger) SetOutput(out io.Writer) { + l.infoLogger.SetOutput(out) + l.debugLogger.SetOutput(out) + l.warnLogger.SetOutput(out) +} + +func (l *Logger) Info(message string) { + l.infoLogger.Println(message) +} + +func (l *Logger) Infof(format string, args ...interface{}) { + message := fmt.Sprintf(format, args...) + l.infoLogger.Println(message) +} + +func (l *Logger) Debug(message string) { + l.debugLogger.Println(message) +} + +func (l *Logger) Debugf(format string, args ...interface{}) { + message := fmt.Sprintf(format, args...) + l.debugLogger.Println(message) +} + +func (l *Logger) Warn(message string) { + l.warnLogger.Println(message) +} + +func (l *Logger) Warnf(format string, args ...interface{}) { + message := fmt.Sprintf(format, args...) + l.warnLogger.Println(message) +} diff --git a/plugins/verifier/sample/sample.go b/plugins/verifier/sample/sample.go index 51ce8f658..8fc48554a 100644 --- a/plugins/verifier/sample/sample.go +++ b/plugins/verifier/sample/sample.go @@ -18,8 +18,10 @@ package main import ( "encoding/json" "fmt" + "os" "github.com/deislabs/ratify/pkg/common" + "github.com/deislabs/ratify/pkg/common/plugin/logger" "github.com/deislabs/ratify/pkg/ocispecs" "github.com/deislabs/ratify/pkg/referrerstore" "github.com/deislabs/ratify/pkg/verifier" @@ -37,7 +39,19 @@ type PluginInputConfig struct { } func main() { + // create a plugin logger + pluginlogger := logger.NewLogger() + + // output info and Debug to stderr + pluginlogger.Info("initialized plugin") + pluginlogger.Debugf("plugin %s %s", "sample", "1.0.0") + skel.PluginMain("sample", "1.0.0", VerifyReference, []string{"1.0.0"}) + + // By default, the pluginlogger writes to stderr. To change the output, use SetOutput + pluginlogger.SetOutput(os.Stdout) + // output warning to stdout + pluginlogger.Warn("example warning message...") } func parseInput(stdin []byte) (*PluginConfig, error) {