go icon indicating copy to clipboard operation
go copied to clipboard
Published 3 weeks ago • verified publisher icon golang

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

Open bradfitz opened this issue 2 years ago • 12 comments

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

bradfitz avatar Jun 12 '23 00:06 bradfitz

CC @golang/wasm

johanbrandhorst avatar Jun 12 '23 05:06 johanbrandhorst

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

cuonglm avatar Jun 12 '23 17:06 cuonglm

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.

achille-roussel avatar Jun 15 '23 19:06 achille-roussel

@achille-roussel I am facing a similar issue, PTAL if https://github.com/golang/go/issues/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.

HarikrishnanBalagopal avatar Oct 09 '23 16:10 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 avatar Oct 09 '23 17:10 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?

@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 https://github.com/golang/go/blob/8222423e0384cce56de31fe2c38572da0a5c1943/src/io/fs/fs.go#L86-L106

HarikrishnanBalagopal avatar Oct 09 '23 19:10 HarikrishnanBalagopal

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?

achille-roussel avatar Oct 09 '23 19:10 achille-roussel

@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 avatar Oct 09 '23 19:10 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);
})();

HarikrishnanBalagopal avatar Oct 09 '23 20:10 HarikrishnanBalagopal

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

achille-roussel avatar Oct 10 '23 21:10 achille-roussel

Hi @HarikrishnanBalagopal and @achille-roussel,

I tested these issues locally and applied the suggested fixes. I also created a document explaining the details and have opened a PR here: https://github.com/golang/wiki/pull/75. Could you please review it?

Regarding Wasmer, I didn’t add a section for it because I’m currently blocked by this issue, which needs to be resolved first: https://github.com/golang/go/issues/59907.

iamrajiv avatar Dec 06 '25 02:12 iamrajiv

Change https://go.dev/cl/727580 mentions this issue: WebAssembly: add WASIP1 runtime configuration examples

gopherbot avatar Dec 06 '25 12:12 gopherbot