Repository: tetratelabs/wazero
Pull request #1076 (2023-01-29 08:53:36)

logging: adds memory scope
This allows you to specify the memory scope amongst existing logging scopes, both in API and the CLI.

e.g for the CLI.
```bash
$ wazero run --hostlogging=memory,filesystem --mount=.:/:ro cat.wasm
```

e.g. for Go
```go
loggingCtx := context.WithValue(testCtx, experimental.FunctionListenerFactoryKey{},
	logging.NewHostLoggingListenerFactory(&log, logging.LogScopeMemory|logging.LogScopeFilesystem))
```

This is helpful for emscripten and gojs which have memory reset callbacks. This will be much more interesting once #1075 is implemented.


Patch:
diff --git a/cmd/wazero/wazero.go b/cmd/wazero/wazero.go
index 33c273d8..053900d8 100644
--- a/cmd/wazero/wazero.go
+++ b/cmd/wazero/wazero.go
@@ -127,7 +127,7 @@ func doRun(args []string, stdOut io.Writer, stdErr logging.Writer, exit func(cod
 	var hostlogging logScopesFlag
 	flags.Var(&hostlogging, "hostlogging",
 		"A comma-separated list of host function scopes to log to stderr. "+
-			"This may be specified multiple times. Supported values: clock,exit,filesystem,poll,random")
+			"This may be specified multiple times. Supported values: clock,exit,filesystem,memory,poll,random")
 
 	cacheDir := cacheDirFlag(flags)
 
@@ -378,6 +378,8 @@ func (f *logScopesFlag) Set(input string) error {
 			*f |= logScopesFlag(logging.LogScopeExit)
 		case "filesystem":
 			*f |= logScopesFlag(logging.LogScopeFilesystem)
+		case "memory":
+			*f |= logScopesFlag(logging.LogScopeMemory)
 		case "poll":
 			*f |= logScopesFlag(logging.LogScopePoll)
 		case "random":
diff --git a/experimental/logging/log_listener.go b/experimental/logging/log_listener.go
index 95993783..0fa75c63 100644
--- a/experimental/logging/log_listener.go
+++ b/experimental/logging/log_listener.go
@@ -42,6 +42,9 @@ const (
 	//
 	// Note: This doesn't log writes to the console.
 	LogScopeFilesystem = logging.LogScopeFilesystem
+	// LogScopeMemory enables logging for functions such as
+	// `emscripten_notify_memory_growth`.
+	LogScopeMemory = logging.LogScopeMemory
 	// LogScopePoll enables logging for functions such as `poll_oneoff`.
 	LogScopePoll = logging.LogScopePoll
 	// LogScopeRandom enables logging for functions such as `random_get`.
@@ -115,10 +118,19 @@ func (f *loggingListenerFactory) NewListener(fnd api.FunctionDefinition) experim
 		}
 		pSampler, pLoggers, rLoggers = gologging.Config(fnd, f.scopes)
 	case "env":
-		if !aslogging.IsInLogScope(fnd, f.scopes) {
-			return nil
+		// env is difficult because the same module name is used for different
+		// ABI.
+		pLoggers, rLoggers = logging.Config(fnd)
+		switch fnd.Name() {
+		case "emscripten_notify_memory_growth":
+			if !logging.LogScopeMemory.IsEnabled(f.scopes) {
+				return nil
+			}
+		default:
+			if !aslogging.IsInLogScope(fnd, f.scopes) {
+				return nil
+			}
 		}
-		pSampler, pLoggers, rLoggers = aslogging.Config(fnd)
 	default:
 		// We don't know the scope of the function, so compare against all.
 		if f.scopes != logging.LogScopeAll {
diff --git a/internal/assemblyscript/logging/logging.go b/internal/assemblyscript/logging/logging.go
index ffc127b2..9e2f40ec 100644
--- a/internal/assemblyscript/logging/logging.go
+++ b/internal/assemblyscript/logging/logging.go
@@ -30,8 +30,3 @@ func IsInLogScope(fnd api.FunctionDefinition, scopes logging.LogScopes) bool {
 
 	return scopes == logging.LogScopeAll
 }
-
-func Config(fnd api.FunctionDefinition) (pSampler logging.ParamSampler, pLoggers []logging.ParamLogger, rLoggers []logging.ResultLogger) {
-	pLoggers, rLoggers = logging.Config(fnd)
-	return
-}
diff --git a/internal/gojs/logging/logging.go b/internal/gojs/logging/logging.go
index 8685b4d4..f5af99af 100644
--- a/internal/gojs/logging/logging.go
+++ b/internal/gojs/logging/logging.go
@@ -39,6 +39,13 @@ func IsInLogScope(fnd api.FunctionDefinition, scopes logging.LogScopes) bool {
 		}
 	}
 
+	if scopes.IsEnabled(logging.LogScopeMemory) {
+		switch fnd.Name() {
+		case custom.NameRuntimeResetMemoryDataView:
+			return true
+		}
+	}
+
 	if scopes.IsEnabled(logging.LogScopePoll) {
 		switch fnd.Name() {
 		case custom.NameRuntimeScheduleTimeoutEvent, custom.NameRuntimeClearTimeoutEvent:
@@ -60,9 +67,13 @@ func IsInLogScope(fnd api.FunctionDefinition, scopes logging.LogScopes) bool {
 
 func Config(fnd api.FunctionDefinition, scopes logging.LogScopes) (pSampler logging.ParamSampler, pLoggers []logging.ParamLogger, rLoggers []logging.ResultLogger) {
 	switch fnd.Name() {
-	case custom.NameRuntimeGetRandomData:
-		pLoggers = []logging.ParamLogger{runtimeGetRandomDataParamLogger}
+	case custom.NameRuntimeWasmExit:
+		pLoggers = []logging.ParamLogger{runtimeWasmExitParamLogger}
 		// no results
+	case custom.NameRuntimeWasmWrite:
+		return // Don't log NameRuntimeWasmWrite as it is used in panics
+	case custom.NameRuntimeResetMemoryDataView:
+		// no params or results
 	case custom.NameRuntimeNanotime1:
 		// no params
 		rLoggers = []logging.ResultLogger{runtimeNanotime1ResultLogger}
@@ -75,11 +86,9 @@ func Config(fnd api.FunctionDefinition, scopes logging.LogScopes) (pSampler logg
 	case custom.NameRuntimeClearTimeoutEvent:
 		pLoggers = []logging.ParamLogger{runtimeClearTimeoutEventParamLogger}
 		// no results
-	case custom.NameRuntimeWasmExit:
-		pLoggers = []logging.ParamLogger{runtimeWasmExitParamLogger}
+	case custom.NameRuntimeGetRandomData:
+		pLoggers = []logging.ParamLogger{runtimeGetRandomDataParamLogger}
 		// no results
-	case custom.NameRuntimeWasmWrite:
-		return // Don't log NameRuntimeWasmWrite as it is used in panics
 	case custom.NameSyscallValueCall:
 		pSampler = (&syscallValueCallParamSampler{scopes: scopes}).isSampled
 		pLoggers = []logging.ParamLogger{syscallValueCallParamLogger}
diff --git a/internal/gojs/runtime.go b/internal/gojs/runtime.go
index d93be861..ed545326 100644
--- a/internal/gojs/runtime.go
+++ b/internal/gojs/runtime.go
@@ -17,6 +17,8 @@ import (
 // See https://github.com/golang/go/blob/go1.19/src/cmd/link/internal/wasm/asm.go#L133-L138
 var Debug = goarch.StubFunction(custom.NameDebug)
 
+// TODO: should this call runtime.Breakpoint()?
+
 // WasmExit implements runtime.wasmExit which supports runtime.exit.
 //
 // See https://github.com/golang/go/blob/go1.19/src/runtime/sys_wasm.go#L28
diff --git a/internal/logging/logging.go b/internal/logging/logging.go
index 01739a36..a4755e1e 100644
--- a/internal/logging/logging.go
+++ b/internal/logging/logging.go
@@ -41,6 +41,7 @@ const (
 	LogScopeClock LogScopes = 1 << iota
 	LogScopeExit
 	LogScopeFilesystem
+	LogScopeMemory
 	LogScopePoll
 	LogScopeRandom
 	LogScopeAll = LogScopes(0xffffffffffffffff)
@@ -54,6 +55,8 @@ func scopeName(s LogScopes) string {
 		return "exit"
 	case LogScopeFilesystem:
 		return "filesystem"
+	case LogScopeMemory:
+		return "memory"
 	case LogScopePoll:
 		return "poll"
 	case LogScopeRandom:


Test patch:
diff --git a/cmd/wazero/wazero_test.go b/cmd/wazero/wazero_test.go
index e7445b21..a88d7483 100644
--- a/cmd/wazero/wazero_test.go
+++ b/cmd/wazero/wazero_test.go
@@ -590,6 +590,11 @@ func Test_logScopesFlag(t *testing.T) {
 			values:   []string{"filesystem"},
 			expected: logging.LogScopeFilesystem,
 		},
+		{
+			name:     "memory",
+			values:   []string{"memory"},
+			expected: logging.LogScopeMemory,
+		},
 		{
 			name:     "poll",
 			values:   []string{"poll"},
diff --git a/imports/emscripten/emscripten_test.go b/imports/emscripten/emscripten_test.go
index 1e84b17a..3d0e90a9 100644
--- a/imports/emscripten/emscripten_test.go
+++ b/imports/emscripten/emscripten_test.go
@@ -34,7 +34,8 @@ func TestGrow(t *testing.T) {
 	var log bytes.Buffer
 
 	// Set context to one that has an experimental listener
-	ctx := context.WithValue(testCtx, FunctionListenerFactoryKey{}, logging.NewLoggingListenerFactory(&log))
+	ctx := context.WithValue(testCtx, FunctionListenerFactoryKey{},
+		logging.NewHostLoggingListenerFactory(&log, logging.LogScopeMemory))
 
 	r := wazero.NewRuntime(ctx)
 	defer r.Close(ctx)
diff --git a/internal/gojs/logging/logging_test.go b/internal/gojs/logging/logging_test.go
index 8bec9d3d..741c1ac6 100644
--- a/internal/gojs/logging/logging_test.go
+++ b/internal/gojs/logging/logging_test.go
@@ -22,6 +22,7 @@ func (f *testFunctionDefinition) Name() string {
 
 func TestIsInLogScope(t *testing.T) {
 	runtimeGetRandomData := &testFunctionDefinition{name: custom.NameRuntimeGetRandomData}
+	runtimeResetMemoryDataView := &testFunctionDefinition{name: custom.NameRuntimeResetMemoryDataView}
 	runtimeWasmExit := &testFunctionDefinition{name: custom.NameRuntimeWasmExit}
 	syscallValueCall := &testFunctionDefinition{name: custom.NameSyscallValueCall}
 	tests := []struct {
@@ -61,9 +62,33 @@ func TestIsInLogScope(t *testing.T) {
 			expected: true,
 		},
 		{
-			name:     "runtimeGetRandomData in LogScopeRandom",
-			fnd:      runtimeGetRandomData,
-			scopes:   logging.LogScopeRandom,
+			name:     "runtimeResetMemoryDataView in LogScopeMemory",
+			fnd:      runtimeResetMemoryDataView,
+			scopes:   logging.LogScopeMemory,
+			expected: true,
+		},
+		{
+			name:     "runtimeResetMemoryDataView not in LogScopeFilesystem",
+			fnd:      runtimeResetMemoryDataView,
+			scopes:   logging.LogScopeFilesystem,
+			expected: false,
+		},
+		{
+			name:     "runtimeResetMemoryDataView in LogScopeMemory|LogScopeFilesystem",
+			fnd:      runtimeResetMemoryDataView,
+			scopes:   logging.LogScopeMemory | logging.LogScopeFilesystem,
+			expected: true,
+		},
+		{
+			name:     "runtimeResetMemoryDataView not in LogScopeNone",
+			fnd:      runtimeResetMemoryDataView,
+			scopes:   logging.LogScopeNone,
+			expected: false,
+		},
+		{
+			name:     "runtimeResetMemoryDataView in LogScopeAll",
+			fnd:      runtimeResetMemoryDataView,
+			scopes:   logging.LogScopeAll,
 			expected: true,
 		},
 		{
diff --git a/internal/gojs/misc_test.go b/internal/gojs/misc_test.go
index 42672aa3..e2aa0ff5 100644
--- a/internal/gojs/misc_test.go
+++ b/internal/gojs/misc_test.go
@@ -45,11 +45,20 @@ consumer
 func Test_mem(t *testing.T) {
 	t.Parallel()
 
-	stdout, stderr, err := compileAndRun(testCtx, "mem", wazero.NewModuleConfig())
+	var log bytes.Buffer
+	loggingCtx := context.WithValue(testCtx, experimental.FunctionListenerFactoryKey{},
+		logging.NewHostLoggingListenerFactory(&log, logging.LogScopeMemory))
+
+	stdout, stderr, err := compileAndRun(loggingCtx, "mem", wazero.NewModuleConfig())
 
 	require.EqualError(t, err, `module "" closed with exit_code(0)`)
 	require.Zero(t, stderr)
 	require.Zero(t, stdout)
+
+	// The memory view is reset at least once.
+	require.Contains(t, log.String(), `==> go.runtime.resetMemoryDataView()
+<==
+`)
 }
 
 func Test_stdio(t *testing.T) {