diff --git a/fn.go b/fn.go index a27b443..60ca442 100644 --- a/fn.go +++ b/fn.go @@ -139,7 +139,7 @@ func (f *Function) RunFunction(_ context.Context, req *fnv1.RunFunctionRequest) exportCmds = exportCmds + "export " + k + "=\"" + v + "\";" } - log.Info(shellCmd) + log.Debug(shellCmd) var stdout, stderr bytes.Buffer cmd := shell.Commandf(exportCmds + shellCmd) @@ -150,7 +150,7 @@ func (f *Function) RunFunction(_ context.Context, req *fnv1.RunFunctionRequest) sout := strings.TrimSpace(stdout.String()) serr := strings.TrimSpace(stderr.String()) - log.Debug(shellCmd, "stdout", sout, "stderr", serr) + log.Info("Function output", "tag", req.GetMeta().GetTag(), "stdout", sout, "stderr", serr) err = dxr.Resource.SetValue(stdoutField, sout) if err != nil { diff --git a/fn_test.go b/fn_test.go index 9518340..7ca4b95 100644 --- a/fn_test.go +++ b/fn_test.go @@ -17,6 +17,172 @@ import ( "github.com/crossplane/function-sdk-go/response" ) +type logEntry struct { + msg string + keysAndValues []any +} + +type testLogger struct { + infoEntries []logEntry + debugEntries []logEntry + withValuesEntries [][]any +} + +func (l *testLogger) Info(msg string, keysAndValues ...any) { + l.infoEntries = append(l.infoEntries, logEntry{msg: msg, keysAndValues: keysAndValues}) +} +func (l *testLogger) Debug(msg string, keysAndValues ...any) { + l.debugEntries = append(l.debugEntries, logEntry{msg: msg, keysAndValues: keysAndValues}) +} +func (l *testLogger) WithValues(keysAndValues ...any) logging.Logger { + l.withValuesEntries = append(l.withValuesEntries, keysAndValues) + return l +} + +// assertLogContainsKVs checks that at least one log entry in entries has the specified message and contains all of the specified key-value pairs. +func assertLogContainsKVs(t *testing.T, entries []logEntry, msg string, wantKVs map[string]any) { + t.Helper() + for _, entry := range entries { + if entry.msg != msg { + continue + } + got := make(map[any]any, len(entry.keysAndValues)/2) + for i := 0; i+1 < len(entry.keysAndValues); i += 2 { + got[entry.keysAndValues[i]] = entry.keysAndValues[i+1] + } + for k, want := range wantKVs { + v, ok := got[k] + if !ok { + t.Errorf("log %q: missing key %q (got keys: %v)", msg, k, entry.keysAndValues) + continue + } + if v != want { + t.Errorf("log %q key %q: want %q, got %q", msg, k, want, v) + } + } + return + } + t.Errorf("no log entry with msg %q found (entries: %v)", msg, entries) +} + +func TestRunFunctionLogs(t *testing.T) { + type args struct { + ctx context.Context + req *fnv1.RunFunctionRequest + } + type wantLog struct { + level string // "info" or "debug" + msg string + kvs map[string]any + } + type want struct { + logs []wantLog + withValues []any + } + + cases := map[string]struct { + reason string + args args + want want + }{ + "LogsStdoutOnSuccess": { + reason: "Function output log should contain stdout key and empty stderr", + args: args{ + req: &fnv1.RunFunctionRequest{ + Meta: &fnv1.RequestMeta{Tag: "foo"}, + Input: resource.MustStructJSON(`{ + "apiVersion": "template.fn.crossplane.io/v1alpha1", + "kind": "Parameters", + "shellCommand": "echo hello", + "stdoutField": "spec.atFunction.shell.stdout" + }`), + }, + }, + want: want{ + logs: []wantLog{ + {level: "info", msg: "Running function", kvs: map[string]any{"tag": "foo"}}, + {level: "debug", msg: "echo hello"}, + {level: "info", msg: "Function output", kvs: map[string]any{"stdout": "hello", "stderr": "", "tag": "foo"}}, + }, + }, + }, + "LogsStderrOnError": { + reason: "Function output log should contain stderr key and empty stdout", + args: args{ + req: &fnv1.RunFunctionRequest{ + Meta: &fnv1.RequestMeta{Tag: "foo"}, + Input: resource.MustStructJSON(`{ + "apiVersion": "template.fn.crossplane.io/v1alpha1", + "kind": "Parameters", + "shellCommand": "echo hello> /dev/stderr; exit 1", + "stdoutField": "spec.atFunction.shell.stdout", + "stderrField": "spec.atFunction.shell.stderr" + }`), + }, + }, + want: want{ + logs: []wantLog{ + {level: "info", msg: "Running function", kvs: map[string]any{"tag": "foo"}}, + {level: "debug", msg: "echo hello> /dev/stderr; exit 1"}, + {level: "info", msg: "Function output", kvs: map[string]any{"stdout": "", "stderr": "hello", "tag": "foo"}}, + }, + }, + }, + "LogsWithValuesContextOnSuccess": { + reason: "WithValues should be called with oxr-version, oxr-kind and oxr-name", + args: args{ + req: &fnv1.RunFunctionRequest{ + Meta: &fnv1.RequestMeta{Tag: "foo"}, + Input: resource.MustStructJSON(`{ + "apiVersion": "template.fn.crossplane.io/v1alpha1", + "kind": "Parameters", + "shellCommand": "echo hello", + "stdoutField": "spec.atFunction.shell.stdout" + }`), + Observed: &fnv1.State{ + Composite: &fnv1.Resource{ + Resource: resource.MustStructJSON(`{ + "apiVersion": "example.crossplane.io/v1", + "kind": "TestXRD", + "metadata": {"name": "my-xr"} + }`), + }, + }, + }, + }, + want: want{ + withValues: []any{"oxr-version", "example.crossplane.io/v1", "oxr-kind", "TestXRD", "oxr-name", "my-xr"}, + }, + }, + } + + for name, tc := range cases { + t.Run(name, func(t *testing.T) { + log := &testLogger{} + f := &Function{log: log} + + _, err := f.RunFunction(tc.args.ctx, tc.args.req) + if err != nil { + t.Fatalf("%s\nf.RunFunction(...): unexpected error: %v", tc.reason, err) + } + + for _, wl := range tc.want.logs { + entries := log.infoEntries + if wl.level == "debug" { + entries = log.debugEntries + } + assertLogContainsKVs(t, entries, wl.msg, wl.kvs) + } + + if tc.want.withValues != nil { + if diff := cmp.Diff([][]any{tc.want.withValues}, log.withValuesEntries); diff != "" { + t.Errorf("%s\nf.RunFunction(...): -want withValues, +got withValues:\n%s", tc.reason, diff) + } + } + }) + } +} + func TestRunFunction(t *testing.T) { type args struct { ctx context.Context