feat!: provide plugins get_log_level runtime function & support levels

extism.go

@@ -10,9 +10,11 @@ import (
 	"fmt"
 	"io"
 	"log"
+	"math"
 	"net/http"
 	"os"
 	"strings"
+	"sync/atomic"
 	"time"
 
 	observe "github.com/dylibso/observe-sdk/go"
@@ -27,6 +29,9 @@ type module struct {
 	wasm   []byte
 }
 
+type PluginCtxKey string
+type InputOffsetKey string
+
 //go:embed extism-runtime.wasm
 var extismRuntimeWasm []byte
 
@@ -63,31 +68,51 @@ type HttpRequest struct {
 }
 
 // LogLevel defines different log levels.
-type LogLevel uint8
+type LogLevel int32
 
 const (
 	logLevelUnset LogLevel = iota // unexporting this intentionally so its only ever the default
-	LogLevelOff
-	LogLevelError
-	LogLevelWarn
-	LogLevelInfo
-	LogLevelDebug
 	LogLevelTrace
+	LogLevelDebug
+	LogLevelInfo
+	LogLevelWarn
+	LogLevelError
+
+	LogLevelOff LogLevel = math.MaxInt32
 )
 
+func (l LogLevel) ExtismCompat() int32 {
+	switch l {
+	case LogLevelTrace:
+		return 0
+	case LogLevelDebug:
+		return 1
+	case LogLevelInfo:
+		return 2
+	case LogLevelWarn:
+		return 3
+	case LogLevelError:
+		return 4
+	default:
+		return int32(LogLevelOff)
+	}
+}
+
 func (l LogLevel) String() string {
 	s := ""
 	switch l {
-	case LogLevelError:
-		s = "ERROR"
-	case LogLevelWarn:
-		s = "WARN"
-	case LogLevelInfo:
-		s = "INFO"
-	case LogLevelDebug:
-		s = "DEBUG"
 	case LogLevelTrace:
 		s = "TRACE"
+	case LogLevelDebug:
+		s = "DEBUG"
+	case LogLevelInfo:
+		s = "INFO"
+	case LogLevelWarn:
+		s = "WARN"
+	case LogLevelError:
+		s = "ERROR"
+	default:
+		s = "OFF"
 	}
 	return s
 }
@@ -107,7 +132,6 @@ type Plugin struct {
 	MaxHttpResponseBytes int64
 	MaxVarBytes          int64
 	log                  func(LogLevel, string)
-	logLevel             LogLevel
 	guestRuntime         guestRuntime
 	Adapter              *observe.AdapterBase
 	TraceCtx             *observe.TraceCtx
@@ -122,13 +146,8 @@ func (p *Plugin) SetLogger(logger func(LogLevel, string)) {
 	p.log = logger
 }
 
-// SetLogLevel sets the minim logging level, applies to custom logging callbacks too
-func (p *Plugin) SetLogLevel(level LogLevel) {
-	p.logLevel = level
-}
-
 func (p *Plugin) Log(level LogLevel, message string) {
-	if level > p.logLevel {
+	if level < LogLevel(pluginLogLevel.Load()) {
 		return
 	}
 
@@ -311,7 +330,7 @@ func (m *Manifest) UnmarshalJSON(data []byte) error {
 				Name:    w.Name,
 			})
 		} else {
-			return errors.New("Invalid Wasm entry")
+			return errors.New("invalid Wasm entry")
 		}
 	}
 	return nil
@@ -327,6 +346,14 @@ func (p *Plugin) CloseWithContext(ctx context.Context) error {
 	return p.Runtime.Wazero.Close(ctx)
 }
 
+// add an atomic global to store the plugin runtime-wide log level
+var pluginLogLevel = atomic.Int32{}
+
+// SetPluginLogLevel sets the log level for the plugin
+func SetLogLevel(level LogLevel) {
+	pluginLogLevel.Store(int32(level.ExtismCompat()))
+}
+
 // NewPlugin creates a new Extism plugin with the given manifest, configuration, and host functions.
 // The returned plugin can be used to call WebAssembly functions and interact with the plugin.
 func NewPlugin(
@@ -390,7 +417,7 @@ func NewPlugin(
 
 	count := len(manifest.Wasm)
 	if count == 0 {
-		return nil, fmt.Errorf("Manifest can't be empty.")
+		return nil, fmt.Errorf("manifest can't be empty")
 	}
 
 	modules := map[string]module{}
@@ -444,7 +471,7 @@ func NewPlugin(
 		if data.Name == "main" && config.ObserveAdapter != nil {
 			trace, err = config.ObserveAdapter.NewTraceCtx(ctx, c.Wazero, data.Data, config.ObserveOptions)
 			if err != nil {
-				return nil, fmt.Errorf("Failed to initialize Observe Adapter: %v", err)
+				return nil, fmt.Errorf("failed to initialize Observe Adapter: %v", err)
 			}
 
 			trace.Finish()
@@ -454,13 +481,13 @@ func NewPlugin(
 		_, okm := modules[data.Name]
 
 		if data.Name == "extism:host/env" || okh || okm {
-			return nil, fmt.Errorf("Module name collision: '%s'", data.Name)
+			return nil, fmt.Errorf("module name collision: '%s'", data.Name)
 		}
 
 		if data.Hash != "" {
 			calculatedHash := calculateHash(data.Data)
 			if data.Hash != calculatedHash {
-				return nil, fmt.Errorf("Hash mismatch for module '%s'", data.Name)
+				return nil, fmt.Errorf("hash mismatch for module '%s'", data.Name)
 			}
 		}
 
@@ -472,11 +499,6 @@ func NewPlugin(
 		modules[data.Name] = module{module: m, wasm: data.Data}
 	}
 
-	logLevel := LogLevelWarn
-	if config.LogLevel != logLevelUnset {
-		logLevel = config.LogLevel
-	}
-
 	i := 0
 	httpMax := int64(1024 * 1024 * 50)
 	if manifest.Memory != nil && manifest.Memory.MaxHttpResponseBytes >= 0 {
@@ -502,7 +524,6 @@ func NewPlugin(
 				MaxHttpResponseBytes: httpMax,
 				MaxVarBytes:          varMax,
 				log:                  logStd,
-				logLevel:             logLevel,
 				Adapter:              config.ObserveAdapter,
 				TraceCtx:             trace,
 			}
@@ -514,7 +535,7 @@ func NewPlugin(
 		i++
 	}
 
-	return nil, errors.New("No main module found")
+	return nil, errors.New("no main module found")
 }
 
 // SetInput sets the input data for the plugin to be used in the next WebAssembly function call.
@@ -612,28 +633,28 @@ func (plugin *Plugin) CallWithContext(ctx context.Context, name string, data []b
 		defer cancel()
 	}
 
-	ctx = context.WithValue(ctx, "plugin", plugin)
+	ctx = context.WithValue(ctx, PluginCtxKey("plugin"), plugin)
 
 	intputOffset, err := plugin.SetInput(data)
 	if err != nil {
 		return 1, []byte{}, err
 	}
 
-	ctx = context.WithValue(ctx, "inputOffset", intputOffset)
+	ctx = context.WithValue(ctx, InputOffsetKey("inputOffset"), intputOffset)
 
 	var f = plugin.Main.module.ExportedFunction(name)
 
 	if f == nil {
-		return 1, []byte{}, errors.New(fmt.Sprintf("Unknown function: %s", name))
+		return 1, []byte{}, fmt.Errorf("unknown function: %s", name)
 	} else if n := len(f.Definition().ResultTypes()); n > 1 {
-		return 1, []byte{}, errors.New(fmt.Sprintf("Function %s has %v results, expected 0 or 1", name, n))
+		return 1, []byte{}, fmt.Errorf("function %s has %v results, expected 0 or 1", name, n)
 	}
 
 	var isStart = name == "_start"
 	if plugin.guestRuntime.init != nil && !isStart && !plugin.guestRuntime.initialized {
 		err := plugin.guestRuntime.init(ctx)
 		if err != nil {
-			return 1, []byte{}, errors.New(fmt.Sprintf("failed to initialize runtime: %v", err))
+			return 1, []byte{}, fmt.Errorf("failed to initialize runtime: %v", err)
 		}
 		plugin.guestRuntime.initialized = true
 	}
@@ -678,14 +699,14 @@ func (plugin *Plugin) CallWithContext(ctx context.Context, name string, data []b
 	if rc != 0 {
 		errMsg := plugin.GetError()
 		if errMsg == "" {
-			errMsg = "Encountered an unknown error in call to Extism plugin function " + name
+			errMsg = "encountered an unknown error in call to Extism plugin function " + name
 		}
 		return rc, []byte{}, errors.New(errMsg)
 	}
 
 	output, err := plugin.GetOutput()
 	if err != nil {
-		return rc, []byte{}, fmt.Errorf("Failed to get output: %v", err)
+		return rc, []byte{}, fmt.Errorf("failed to get output: %v", err)
 	}
 
 	return rc, output, nil

extism_test.go

@@ -6,8 +6,8 @@ import (
 	"encoding/json"
 	"fmt"
 	"log"
-	"math/rand"
 	"os"
+	"strings"
 	"testing"
 	"time"
 
@@ -443,13 +443,16 @@ func TestLog_default(t *testing.T) {
 	if plugin, ok := plugin(t, manifest); ok {
 		defer plugin.Close()
 
+		SetLogLevel(LogLevelWarn) // Only warn and error logs should be printed to the console
 		exit, _, err := plugin.Call("run_test", []byte{})
 
 		if assertCall(t, err, exit) {
 			logs := buf.String()
-
 			assert.Contains(t, logs, "this is a warning log")
 			assert.Contains(t, logs, "this is an error log")
+			assert.NotContains(t, logs, "this is a trace log")
+			assert.NotContains(t, logs, "this is a debug log")
+			assert.NotContains(t, logs, "this is an info log")
 		}
 	}
 }
@@ -465,34 +468,68 @@ func TestLog_custom(t *testing.T) {
 	if plugin, ok := plugin(t, manifest); ok {
 		defer plugin.Close()
 
-		var actual []LogEntry
+		var actual strings.Builder
+
+		var fmtLogMessage = func(level LogLevel, message string) string {
+			return fmt.Sprintf("%s: %s\n", level.String(), message)
+		}
 
 		plugin.SetLogger(func(level LogLevel, message string) {
-			actual = append(actual, LogEntry{message: message, level: level})
+			actual.WriteString(fmtLogMessage(level, message))
 			switch level {
+			case LogLevelDebug:
+				assert.Equal(t, level.String(), "DEBUG")
 			case LogLevelInfo:
-				assert.Equal(t, fmt.Sprintf("%s", level), "INFO")
+				assert.Equal(t, level.String(), "INFO")
 			case LogLevelWarn:
-				assert.Equal(t, fmt.Sprintf("%s", level), "WARN")
+				assert.Equal(t, level.String(), "WARN")
 			case LogLevelError:
-				assert.Equal(t, fmt.Sprintf("%s", level), "ERROR")
+				assert.Equal(t, level.String(), "ERROR")
 			case LogLevelTrace:
-				assert.Equal(t, fmt.Sprintf("%s", level), "TRACE")
+				assert.Equal(t, level.String(), "TRACE")
 			}
 		})
 
-		plugin.SetLogLevel(LogLevelInfo)
+		SetLogLevel(LogLevelTrace)
 
 		exit, _, err := plugin.Call("run_test", []byte{})
 
 		if assertCall(t, err, exit) {
 			expected := []LogEntry{
+				{message: "this is a trace log", level: LogLevelTrace},
+				{message: "this is a debug log", level: LogLevelDebug},
 				{message: "this is an info log", level: LogLevelInfo},
 				{message: "this is a warning log", level: LogLevelWarn},
 				{message: "this is an error log", level: LogLevelError},
-				{message: "this is a trace log", level: LogLevelTrace}}
+			}
+			actualLogs := actual.String()
+			for _, log := range expected {
+				assert.Contains(t, actualLogs, fmtLogMessage(log.level, log.message))
+			}
+		}
 
-			assert.Equal(t, expected, actual)
+		SetLogLevel(LogLevelWarn)
+		actual.Reset()
+
+		exit, _, err = plugin.Call("run_test", []byte{})
+
+		if assertCall(t, err, exit) {
+			expected := []LogEntry{
+				{message: "this is a warning log", level: LogLevelWarn},
+				{message: "this is an error log", level: LogLevelError},
+			}
+			expectedNot := []LogEntry{
+				{message: "this is a trace log", level: LogLevelTrace},
+				{message: "this is a debug log", level: LogLevelDebug},
+				{message: "this is an info log", level: LogLevelInfo},
+			}
+			actualLogs := actual.String()
+			for _, log := range expected {
+				assert.Contains(t, actualLogs, fmtLogMessage(log.level, log.message))
+			}
+			for _, log := range expectedNot {
+				assert.NotContains(t, actualLogs, fmtLogMessage(log.level, log.message))
+			}
 		}
 	}
 }
@@ -699,7 +736,7 @@ func TestHelloHaskell(t *testing.T) {
 	if plugin, ok := plugin(t, manifest); ok {
 		defer plugin.Close()
 
-		plugin.SetLogLevel(LogLevelTrace)
+		SetLogLevel(LogLevelTrace)
 		plugin.Config["greeting"] = "Howdy"
 
 		exit, output, err := plugin.Call("testing", []byte("John"))
@@ -1068,16 +1105,6 @@ func BenchmarkReplace(b *testing.B) {
 	}
 }
 
-func generateRandomString(length int, seed int64) string {
-	rand.Seed(seed)
-	const charset = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ"
-	result := make([]byte, length)
-	for i := range result {
-		result[i] = charset[rand.Intn(len(charset))]
-	}
-	return string(result)
-}
-
 func wasiPluginConfig() PluginConfig {
 	config := PluginConfig{
 		ModuleConfig: wazero.NewModuleConfig().WithSysWalltime(),