logging: adds memory scope (#1076)

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.

Signed-off-by: Adrian Cole <adrian@tetrate.io>
This commit is contained in:
Crypt Keeper
2023-01-29 10:58:59 +02:00
committed by GitHub
parent da99a7f5c0
commit 282ffc5ced
10 changed files with 83 additions and 20 deletions

View File

@@ -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":

View File

@@ -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"},

View File

@@ -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 {

View File

@@ -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)

View File

@@ -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
}

View File

@@ -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}

View File

@@ -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,
},
{

View File

@@ -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) {

View File

@@ -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

View File

@@ -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: