os: GOOS=wasip1 returns non-IsNotExist errors on non-existent files

[bradfitz]

I'm trying to run some code with to-be Go 1.21's wasip1/wasm support.

We have some code:

	cfgPath := filepath.Join(s.rootPath, "tailscaled.log.conf")
	lpc, err := logpolicy.ConfigFromFile(cfgPath)
	switch {
	case os.IsNotExist(err):
		lpc = logpolicy.NewConfig(logtail.CollectionNode)
		if err := lpc.Save(cfgPath); err != nil {
			return fmt.Errorf("logpolicy.Config.Save for %v: %w", cfgPath, err)
		}
	case err != nil:
		return fmt.Errorf("logpolicy.LoadConfig for %v: %w", cfgPath, err)
	}

And instead of hitting that os.IsNotExist path, it's going into the case err != nil path with:

$ wasmtime run --env=HOME=$HOME --dir=. ~/go/bin/wasip1_wasm/tshello
2023/06/12 00:28:09 tsnet: logpolicy.LoadConfig for tailscaled.log.conf: open tailscaled.log.conf: Bad file number

It's possible I'm holding wasmtime wrong, but "Bad file number" doesn't tell me much. Is that a not found error or a sandbox violation error, or ...?

/cc @johanbrandhorst

[johanbrandhorst]

CC @golang/wasm

[cuonglm]

It seems to me that using . as argument to --dir causes wasmtime confusing:

$ wasmtime run --dir=. main     
8 Bad file number
[] open ./non-existent-file: Bad file number

vs:

$ wasmtime run --dir=$PWD main
44 No such file or directory
[] open ./non-existent-file: No such file or directory

[achille-roussel]

I believe this is working "as intended" based on the documentation in https://github.com/bytecodealliance/wasmtime/blob/main/docs/WASI-tutorial.md#executing-in-wasmtime-runtime

Like @cuonglm reported, wasmtime --dir=. does not expose a directory with a path equal to $PWD, it exposes a directory named . pointing to the current working directory, which then defeats the current directory emulation that we do on GOOS=wasip1 (due to WASI not having the concept of working directory).

It's possible that there is a better way to handle this runtime-specific behavior tho, "Bad file number" is difficult to interpret correctly as a user. At the same time, I would like to avoid making too many special cases in Go, especially because there is no convention to reliably detect which wasm runtime is in use from the guest side.

Maybe we can try to align on the behavior of other compilers (e.g. TinyGo, Zig, Rust), so it's not "more broken" with Go.

[HarikrishnanBalagopal]

@achille-roussel I am facing a similar issue, PTAL if #63466 is intended behaviour or not.
The Go compiler provides -1 as fd to path_open leading to Bad file number error while TinyGo provides 3 so it's able to open and read the file.

[achille-roussel]

@HarikrishnanBalagopal, it appears the difference comes from TinyGo and Go possibly using different default working directories.

Unfortunately, there is no concept of working directory in the wasip1 specification, so it's expected that different compilers will end up with diverging behaviors.

Go interprets the PWD environment variable to set the default. Have you tried setting PWD=/ when running the program?

[HarikrishnanBalagopal]

@HarikrishnanBalagopal, it appears the difference comes from TinyGo and Go possibly using different default working directories.

Unfortunately, there is no concept of working directory in the wasip1 specification, so it's expected that different compilers will end up with diverging behaviors.

Go interprets the PWD environment variable to set the default. Have you tried setting PWD=/ when running the program?

@achille-roussel Setting the environment variable PWD to / seems to fail even earlier on ReadDir (because we pass do ReadDir(pwd) and pwd is an empty string). For some reason even though Golang reads the value of the environment variable correctly, it returns the empty string from the Getwd call.

time="2023-10-09T19:14:14Z" level=info msg="start 8!!"
time="2023-10-09T19:14:14Z" level=info msg="just before Getwd, environment variable FOO is bar"
time="2023-10-09T19:14:14Z" level=info msg="just before Getwd, environment variable PWD is /"
time="2023-10-09T19:14:14Z" level=info msg="just before Getwd, environment variable MYPWD is /"
time="2023-10-09T19:14:14Z" level=info msg="pwd: ''"
panic: stat .: Bad file number

goroutine 1 [running]:
main.must(...)
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:22 +0x7d

The JS Code is as shown in the README https://github.com/bjorn3/browser_wasi_shim#usage

const env = ["FOO=bar", "PWD=/", "MYPWD=/"];
......
const wasi = new WASI(args, env, fds);

The Golang code is

	logrus.Infof("start 8!!")
	logrus.Infof("just before Getwd, environment variable FOO is %s", os.Getenv("FOO"))
	logrus.Infof("just before Getwd, environment variable PWD is %s", os.Getenv("PWD"))
	logrus.Infof("just before Getwd, environment variable MYPWD is %s", os.Getenv("MYPWD"))
	pwd, err := os.Getwd()
	logrus.Infof("pwd: '%s'", pwd)
	must(err)
	fs, err := os.ReadDir(pwd)
	must(err)

Update:
Setting PWD to . has a similar effect

time="2023-10-09T19:20:18Z" level=info msg="start 8!!"
time="2023-10-09T19:20:18Z" level=info msg="just before Getwd, environment variable FOO is bar"
time="2023-10-09T19:20:18Z" level=info msg="just before Getwd, environment variable PWD is ."
time="2023-10-09T19:20:18Z" level=info msg="just before Getwd, environment variable MYPWD is ."
time="2023-10-09T19:20:18Z" level=info msg="pwd: ''"
panic: stat .: Bad file number

goroutine 1 [running]:
main.must(...)
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:22 +0x7d

Update 2:
Changing the ReadDir call still fails

	fs, err := os.ReadDir(".")

This was working previously when we were not setting the PWD environment variable.

time="2023-10-09T19:25:12Z" level=info msg="start 9!!"
time="2023-10-09T19:25:12Z" level=info msg="just before Getwd, environment variable FOO is bar"
time="2023-10-09T19:25:12Z" level=info msg="just before Getwd, environment variable PWD is /"
time="2023-10-09T19:25:12Z" level=info msg="just before Getwd, environment variable MYPWD is /"
time="2023-10-09T19:25:12Z" level=info msg="pwd: ''"
panic: stat .: Bad file number

goroutine 1 [running]:
main.must(...)
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:22 +0x7d

Update 3:
If we don't set the PWD

    const env = ["FOO=bar", "MYPWD=/"];

Then we get back to our previous failure at ReadFile

time="2023-10-09T19:28:47Z" level=info msg="start 10!!"
time="2023-10-09T19:28:47Z" level=info msg="just before Getwd, environment variable FOO is bar"
time="2023-10-09T19:28:47Z" level=info msg="just before Getwd, environment variable PWD is "
time="2023-10-09T19:28:47Z" level=info msg="just before Getwd, environment variable MYPWD is /"
time="2023-10-09T19:28:47Z" level=info msg="pwd: '.'"
time="2023-10-09T19:28:47Z" level=info msg="f: - dep.json"
time="2023-10-09T19:28:47Z" level=info msg="f: - example.c"
time="2023-10-09T19:28:47Z" level=info msg="f: - hello.rs"
time="2023-10-09T19:28:47Z" level=info msg="just before ReadFile, environment variable FOO is bar"
time="2023-10-09T19:28:47Z" level=info msg="just before ReadFile, environment variable PWD is "
time="2023-10-09T19:28:47Z" level=info msg="just before ReadFile, environment variable MYPWD is /"
panic: open dep.json: Bad file number

goroutine 1 [running]:
main.must(...)
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
        /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:36 +0x74

Update 5:

Another thing I noticed is the difference in output of TinyGo and Go when printing the file infos returned by ReadDir

	fs, err := os.ReadDir(".")
	must(err)
	for _, f := range fs {
		logrus.Infof("f: %+v", f)
	}

The Go compiler produces this output

time="2023-10-09T19:28:47Z" level=info msg="f: - dep.json"
time="2023-10-09T19:28:47Z" level=info msg="f: - example.c"
time="2023-10-09T19:28:47Z" level=info msg="f: - hello.rs"

while TinyGo actually prints the struct fields as expected of %+v

time="2023-10-09T13:58:41Z" level=info msg="f: &{parent:/ name:dep.json typ:0 info:<nil>}"
time="2023-10-09T13:58:41Z" level=info msg="f: &{parent:/ name:example.c typ:0 info:<nil>}"
time="2023-10-09T13:58:41Z" level=info msg="f: &{parent:/ name:hello.rs typ:0 info:<nil>}"

The discrepancy seems to be because it's an interface

go/src/io/fs/fs.go

Lines 86 to 106 in 8222423

	type DirEntry interface {
	// Name returns the name of the file (or subdirectory) described by the entry.
	// This name is only the final element of the path (the base name), not the entire path.
	// For example, Name would return "hello.go" not "home/gopher/hello.go".
	Name() string
	// IsDir reports whether the entry describes a directory.
	IsDir() bool
	// Type returns the type bits for the entry.
	// The type bits are a subset of the usual FileMode bits, those returned by the FileMode.Type method.
	Type() FileMode
	// Info returns the FileInfo for the file or subdirectory described by the entry.
	// The returned FileInfo may be from the time of the original directory read
	// or from the time of the call to Info. If the file has been removed or renamed
	// since the directory read, Info may return an error satisfying errors.Is(err, ErrNotExist).
	// If the entry denotes a symbolic link, Info reports the information about the link itself,
	// not the link's target.
	Info() (FileInfo, error)
	}

[achille-roussel]

This is working OK:

# main.go
package main

import (
	"os"

	"github.com/sirupsen/logrus"
)

func must(err error) {
	if err != nil {
		panic(err)
	}
}

func main() {
	logrus.Infof("start v7!!")
	fs, err := os.ReadDir("/")
	must(err)
	for _, f := range fs {
		logrus.Infof("f: %+v", f)
	}
	b, err := os.ReadFile("/dep.json")
	must(err)
	logrus.Infof("The contents are:\n%s", string(b))
	logrus.Infof("done")
}

# dep.json
{"hello":"world"}

$ wasmtime run --mapdir=/::$PWD test.wasm
time="2023-10-09T19:28:21Z" level=info msg="start v7!!"
time="2023-10-09T19:28:21Z" level=info msg="f: - dep.json"
time="2023-10-09T19:28:21Z" level=info msg="f: - go.mod"
time="2023-10-09T19:28:21Z" level=info msg="f: - go.sum"
time="2023-10-09T19:28:21Z" level=info msg="f: - main.go"
time="2023-10-09T19:28:21Z" level=info msg="f: - test.wasm"
time="2023-10-09T19:28:21Z" level=info msg="The contents are:\n{\"hello\":\"world\"}\n"
time="2023-10-09T19:28:21Z" level=info msg=done

$ wazero run -mount=$PWD:/ test.wasm
time="2023-10-09T19:29:24Z" level=info msg="start v7!!"
time="2023-10-09T19:29:24Z" level=info msg="f: - dep.json"
time="2023-10-09T19:29:24Z" level=info msg="f: - go.mod"
time="2023-10-09T19:29:24Z" level=info msg="f: - go.sum"
time="2023-10-09T19:29:24Z" level=info msg="f: - main.go"
time="2023-10-09T19:29:24Z" level=info msg="f: - test.wasm"
time="2023-10-09T19:29:24Z" level=info msg="The contents are:\n{\"hello\":\"world\"}\n"
time="2023-10-09T19:29:24Z" level=info msg=done

I'm tempted to say it is due to a behavior difference between the WASI shim and those other WASI runtimes.

Are you able to make it work with the WASI module of Node 20?

[HarikrishnanBalagopal]

@achille-roussel Nice! I also just got it to work by changing the JS code a bit

Old code

        new PreopenDirectory(".", {

New code

        new PreopenDirectory("/", {

time="2023-10-09T19:47:50Z" level=info msg="start 13!!"
time="2023-10-09T19:47:51Z" level=info msg="just before Getwd, environment variable FOO is bar"
time="2023-10-09T19:47:51Z" level=info msg="just before Getwd, environment variable PWD is "
time="2023-10-09T19:47:51Z" level=info msg="just before Getwd, environment variable MYPWD is /"
time="2023-10-09T19:47:51Z" level=info msg="pwd: '/'"
time="2023-10-09T19:47:51Z" level=info msg="f: - dep.json"
time="2023-10-09T19:47:51Z" level=info msg="f: - example.c"
time="2023-10-09T19:47:51Z" level=info msg="f: - hello.rs"
time="2023-10-09T19:47:51Z" level=info msg="just before ReadFile, environment variable FOO is bar"
time="2023-10-09T19:47:51Z" level=info msg="just before ReadFile, environment variable PWD is "
time="2023-10-09T19:47:51Z" level=info msg="just before ReadFile, environment variable MYPWD is /"
time="2023-10-09T19:47:51Z" level=info msg="The contents are:\n{\"a\": 42, \"b\": 12}"
time="2023-10-09T19:47:51Z" level=info msg=done

The Go code

package main

import (
	"os"

	"github.com/sirupsen/logrus"
)

func must(err error) {
	if err != nil {
		panic(err)
	}
}

func main() {
	logrus.Infof("start 13!!")
	logrus.Infof("just before Getwd, environment variable FOO is %s", os.Getenv("FOO"))
	logrus.Infof("just before Getwd, environment variable PWD is %s", os.Getenv("PWD"))
	logrus.Infof("just before Getwd, environment variable MYPWD is %s", os.Getenv("MYPWD"))
	pwd, err := os.Getwd()
	logrus.Infof("pwd: '%s'", pwd)
	must(err)
	fs, err := os.ReadDir(".")
	must(err)
	for _, f := range fs {
		logrus.Infof("f: %+v", f)
	}
	logrus.Infof("just before ReadFile, environment variable FOO is %s", os.Getenv("FOO"))
	logrus.Infof("just before ReadFile, environment variable PWD is %s", os.Getenv("PWD"))
	logrus.Infof("just before ReadFile, environment variable MYPWD is %s", os.Getenv("MYPWD"))
	b, err := os.ReadFile("dep.json")
	must(err)
	logrus.Infof("The contents are:\n%s", string(b))
	logrus.Infof("done")
}

[HarikrishnanBalagopal]

I'm tempted to say it is due to a behavior difference between the WASI shim and those other WASI runtimes.

I notice significant difference between runtimes as well, wasmer fails earlier while wasmtime and wasmedge fail at ReadFile. BTW this is the same Golang code that works in the Chrome browser with the WASI shim JS library.

Wasmer

Harikrishnans-MacBook-Pro:test-wasi-fs-browser haribala$ wasmer run --dir=. bin/test.wasm 
time="2023-10-09T19:59:23Z" level=info msg="start 13!!"
time="2023-10-09T19:59:23Z" level=info msg="just before Getwd, environment variable FOO is "
time="2023-10-09T19:59:23Z" level=info msg="just before Getwd, environment variable PWD is "
time="2023-10-09T19:59:23Z" level=info msg="just before Getwd, environment variable MYPWD is "
time="2023-10-09T19:59:23Z" level=info msg="pwd: '/\x00'"
panic: open /: Capabilities insufficient

goroutine 1 [running]:
main.must(...)
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:27 +0x79

Wasmtime

Harikrishnans-MacBook-Pro:test-wasi-fs-browser haribala$ wasmtime run --dir=. bin/test.wasm 
time="2023-10-09T19:59:28Z" level=info msg="start 13!!"
time="2023-10-09T19:59:28Z" level=info msg="just before Getwd, environment variable FOO is "
time="2023-10-09T19:59:28Z" level=info msg="just before Getwd, environment variable PWD is "
time="2023-10-09T19:59:28Z" level=info msg="just before Getwd, environment variable MYPWD is "
time="2023-10-09T19:59:28Z" level=info msg="pwd: '.'"
time="2023-10-09T19:59:28Z" level=info msg="f: d .git/"
time="2023-10-09T19:59:28Z" level=info msg="f: - .gitignore"
time="2023-10-09T19:59:28Z" level=info msg="f: - LICENSE"
time="2023-10-09T19:59:28Z" level=info msg="f: - Makefile"
time="2023-10-09T19:59:28Z" level=info msg="f: - README.md"
time="2023-10-09T19:59:28Z" level=info msg="f: d bin/"
time="2023-10-09T19:59:28Z" level=info msg="f: - dep.json"
time="2023-10-09T19:59:28Z" level=info msg="f: - go.mod"
time="2023-10-09T19:59:28Z" level=info msg="f: - go.sum"
time="2023-10-09T19:59:28Z" level=info msg="f: - image.png"
time="2023-10-09T19:59:28Z" level=info msg="f: - main.go"
time="2023-10-09T19:59:28Z" level=info msg="f: d public/"
time="2023-10-09T19:59:28Z" level=info msg="just before ReadFile, environment variable FOO is "
time="2023-10-09T19:59:28Z" level=info msg="just before ReadFile, environment variable PWD is "
time="2023-10-09T19:59:28Z" level=info msg="just before ReadFile, environment variable MYPWD is "
panic: open dep.json: Bad file number

goroutine 1 [running]:
main.must(...)
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:37 +0x74

Wasmedge

Harikrishnans-MacBook-Pro:test-wasi-fs-browser haribala$ wasmedge run --dir=. bin/test.wasm 
time="2023-10-09T19:59:31Z" level=info msg="start 13!!"
time="2023-10-09T19:59:31Z" level=info msg="just before Getwd, environment variable FOO is "
time="2023-10-09T19:59:31Z" level=info msg="just before Getwd, environment variable PWD is "
time="2023-10-09T19:59:31Z" level=info msg="just before Getwd, environment variable MYPWD is "
time="2023-10-09T19:59:31Z" level=info msg="pwd: '.'"
time="2023-10-09T19:59:31Z" level=info msg="f: d .git/"
time="2023-10-09T19:59:31Z" level=info msg="f: - .gitignore"
time="2023-10-09T19:59:31Z" level=info msg="f: - LICENSE"
time="2023-10-09T19:59:31Z" level=info msg="f: - Makefile"
time="2023-10-09T19:59:31Z" level=info msg="f: - README.md"
time="2023-10-09T19:59:31Z" level=info msg="f: d bin/"
time="2023-10-09T19:59:31Z" level=info msg="f: - dep.json"
time="2023-10-09T19:59:31Z" level=info msg="f: - go.mod"
time="2023-10-09T19:59:31Z" level=info msg="f: - go.sum"
time="2023-10-09T19:59:31Z" level=info msg="f: - image.png"
time="2023-10-09T19:59:31Z" level=info msg="f: - main.go"
time="2023-10-09T19:59:31Z" level=info msg="f: d public/"
time="2023-10-09T19:59:31Z" level=info msg="just before ReadFile, environment variable FOO is "
time="2023-10-09T19:59:31Z" level=info msg="just before ReadFile, environment variable PWD is "
time="2023-10-09T19:59:31Z" level=info msg="just before ReadFile, environment variable MYPWD is "
panic: open dep.json: Bad file number

goroutine 1 [running]:
main.must(...)
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:37 +0x74

Chrome browser with WASI FS shim JS library

time="2023-10-09T19:47:50Z" level=info msg="start 13!!"
time="2023-10-09T19:47:51Z" level=info msg="just before Getwd, environment variable FOO is bar"
time="2023-10-09T19:47:51Z" level=info msg="just before Getwd, environment variable PWD is "
time="2023-10-09T19:47:51Z" level=info msg="just before Getwd, environment variable MYPWD is /"
time="2023-10-09T19:47:51Z" level=info msg="pwd: '/'"
time="2023-10-09T19:47:51Z" level=info msg="f: - dep.json"
time="2023-10-09T19:47:51Z" level=info msg="f: - example.c"
time="2023-10-09T19:47:51Z" level=info msg="f: - hello.rs"
time="2023-10-09T19:47:51Z" level=info msg="just before ReadFile, environment variable FOO is bar"
time="2023-10-09T19:47:51Z" level=info msg="just before ReadFile, environment variable PWD is "
time="2023-10-09T19:47:51Z" level=info msg="just before ReadFile, environment variable MYPWD is /"
time="2023-10-09T19:47:51Z" level=info msg="The contents are:\n{\"a\": 42, \"b\": 12}"
time="2023-10-09T19:47:51Z" level=info msg=done

Node 20 WASI

Are you able to make it work with the WASI module of Node 20?

Harikrishnans-MacBook-Pro:temp-node haribala$ node index.js 
__dirname /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/temp-node
(node:89607) ExperimentalWarning: WASI is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
time="2023-10-09T20:32:13Z" level=info msg="start 13!!"
time="2023-10-09T20:32:13Z" level=info msg="just before Getwd, environment variable FOO is "
time="2023-10-09T20:32:13Z" level=info msg="just before Getwd, environment variable PWD is /Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/temp-node"
time="2023-10-09T20:32:13Z" level=info msg="just before Getwd, environment variable MYPWD is "
time="2023-10-09T20:32:13Z" level=info msg="pwd: ''"
panic: stat .: No such file or directory

goroutine 1 [running]:
main.must(...)
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:11
main.main()
	/Users/haribala/Documents/code/remote/github.com/HarikrishnanBalagopal/test-wasi-fs-browser/main.go:23 +0x7d

NodeJS code

'use strict';
const { readFile } = require('node:fs/promises');
const { WASI } = require('wasi');
const { argv, env } = require('node:process');
const { join } = require('node:path');

const wasi = new WASI({
  version: 'preview1',
  args: argv,
  env,
  preopens: {
    '/': __dirname,
  },
});
console.log('__dirname', __dirname);
(async () => {
  const wasm = await WebAssembly.compile(
    await readFile(join(__dirname, 'test.wasm')),
  );
  const instance = await WebAssembly.instantiate(wasm, wasi.getImportObject());

  wasi.start(instance);
})();

[achille-roussel]

@HarikrishnanBalagopal based on your examples, I think the guidelines here are the following:

• the runtime should set the PWD environment variable explicitly (default to PWD=/ is acceptable)
• the preopen for the root directory should be named / (and not .)

If you can contribute, having working examples of a simple program like yours demonstrating how to run on different runtimes would be a great addition to the wiki as well!