golang os.Environ() leading to panic: runtime error: nil pointer dereference

[voigt]

Hey,

Wanted to write a golang program that reads environment variables and stumbled upon a nasty nil pointer dereference. I was able to isolate the problem to os.Environ().

The crash only happens in spin. Compiling to wasm and executing with wasmtime works as expected.

main.go

package main

import (
	"log"
	"net/http"
	"os"

	spinhttp "github.com/fermyon/spin/sdk/go/http"
)

func init() {
	spinhttp.Handle(func(w http.ResponseWriter, r *http.Request) {
		log.Println("Calling os.Environ()...")
		log.Println(os.Environ())
	})
}

func main() {}

Leading to

$ spin build && spin up
Executing the build command for component asd: tinygo build -target=wasi -gc=leaking -no-debug -o main.wasm main.go
Successfully ran the build command for the Spin components.
Serving http://127.0.0.1:3000
Available Routes:
  asd: http://127.0.0.1:3000 (wildcard)

# [note: curling `curl http://127.0.0.1:3000/`]

2023/03/11 14:39:58 Calling os.Environ()...
panic: runtime error: nil pointer dereference
2023-03-11T14:39:58.900825Z ERROR spin_http: Error processing request: error while executing at wasm backtrace:
    0: 0x7365 - <unknown>!runtime.runtimePanic.llvm.6040120704999441655
    1: 0x2c881 - <unknown>!byn$mgfn-shared$runtime.lookupPanic.llvm.6040120704999441655
    2: 0x2c91 - <unknown>!runtime.nilPanic.llvm.6040120704999441655
    3: 0x2bf51 - <unknown>!spin_http_handle_http_request
    4: 0x2c732 - <unknown>!__wasm_export_spin_http_handle_http_request

Caused by:
    wasm trap: wasm `unreachable` instruction executed

Doing the same in tinygo && executing in wasmtime works:

main.go

package main

import (
	"log"
	"os"
)

func init() {
	log.Println("os.Environ()")
	log.Println(os.Environ())
}

func main() {}

$ tinygo build -target=wasi -gc=leaking -no-debug -o main.wasm main.go
$ wasmtime main.wasm
2023/03/11 14:37:11 os.Environ()
2023/03/11 14:37:11 []

Versions

$ tinygo version  
tinygo version 0.27.0 darwin/amd64 (using go version go1.20.1 and LLVM version 15.0.0)
$ spin --version       
spin 1.0.0-rc.1 (2076c97 2023-03-09)
$ wasmtime --version
wasmtime-cli 6.0.1

Would be great to hear an expert opinion to understand whether os.Environ() is supposed to work... :)

[itowlson]

I also see this with os.Environ(). os.Getenv() works fine. So we can access individual variables but not browse the list.

The equivalent Rust API (std::env::vars()) seems to work fine. And the TinyGo mapping works in Wasmtime (even in init) . So I'm not quite sure where this issue might lie. @adamreese any ideas?

[dicej]

I just verified this with TinyGo 0.27.0. My guess is that there's something about how TinyGo compiles main that initializes os.Environ's state, and that doesn't happen when calling other functions. We might be able to work around that by having Spin call _start if present in the module prior to calling the trigger function.

[dicej]

Update: I can confirm that calling _start prior to the trigger function fixes the issue, e.g.:

diff --git a/crates/core/src/lib.rs b/crates/core/src/lib.rs
index f6756c8..319d6ad 100644
--- a/crates/core/src/lib.rs
+++ b/crates/core/src/lib.rs
@@ -20,7 +20,7 @@ use std::{
 use anyhow::Result;
 use crossbeam_channel::Sender;
 use tracing::instrument;
-pub use wasmtime::{self, Instance, Module, Trap};
+pub use wasmtime::{self, Extern, Instance, Module, Trap};
 pub use wasmtime_wasi::I32Exit;
 use wasmtime_wasi::WasiCtx;
 
@@ -267,7 +267,13 @@ impl<T: Send + Sync> InstancePre<T> {
     /// Instantiates this instance with the given [`Store`].
     #[instrument(skip_all)]
     pub async fn instantiate_async(&self, store: &mut Store<T>) -> Result<Instance> {
-        self.inner.instantiate_async(store).await
+        let instance = self.inner.instantiate_async(&mut *store).await?;
+
+        if let Some(Extern::Func(func)) = instance.get_export(&mut *store, "_start") {
+            func.call_async(store, &[], &mut []).await?;
+        }
+
+        Ok(instance)
     }
 }

Not sure yet if that's an appropriate way to address this, though.

[lann]

I'm a little wary of adding a call to _start where we haven't done it before. It's supposed to be for WASI command modules, and I don't know how safe it is to reenter modules after _start exits...

[lann]

See wasi-libc's implementation of _start calling destructors: https://github.com/WebAssembly/wasi-libc/blob/f2a35a454e8472b63831885daacc7f5fadd46747/libc-bottom-half/crt/crt1-command.c#L45-L46

[itowlson]

Is it worth raising this with the TinyGo folks? That is, should libc be fully up and working even if only init and not main is called?

(I seem to recall a similar (though bigger) issue with AssemblyScript, where they relied on things entering through main; things that needed the memory manager failed if called through a non-_start entry point. We hit it with .NET too, and 'solved' it with an explicit call to __wasi_call_ctors early in the exported entry point.)

@voigt It seems like the answer might be that this isn't working at least in the short term - is this a blocker for you, or does os.GetEnv() suffice for your needs?

[dicej]

Seems relevant: tinygo-org/tinygo#2735

[lann]

I've been digging through the tinygo source and these errors still don't make sense to me, but one hack to try might be to call os.Getenv("ANY_KEY") and then see if os.Environ() is initialized. I think it might work based on how wasi-libc handles lazy init. I'll try to test later but my local tinygo install is real messed up atm.

[itowlson]

@lann I gave that a quick try and it didn't seem to help I'm afraid (though never discount the possibility of user error).

[adamreese]

I hit this a while back also. @lann I tried your suggestion and had the same results

[voigt]

@voigt It seems like the answer might be that this isn't working at least in the short term - is this a blocker for you, or does os.GetEnv() suffice for your needs?

@itowlson I worked on some PoCs, comparing Spin implementations in Rust and Go. Therefore I wouldn't consider it a blocker. This is precisely the kind of the reason I was doing it :)

Thank you, all, for quickly triaging and sorting the issue!

[rajatjindal]

I am running into a similar issue when trying to use github-sdk into a Spin app. In the sdk there is a private map. It seems like when trying to use this sdk with Spin, this map has 0 entries.

Following code seems to work fine with wasmtime but fails when running with Spin up

could someone please confirm if this is related to the original issue or should I report a new issue for tracking this

package main

import (
	"fmt"
	"os"

	"github.com/google/go-github/v51/github"
)

// ---- this one works ----
// comment out below init func
// uncomment following func
// spin build
// wasmtime main.wasm
func init() {
	err := parse()
	if err != nil {
		fmt.Printf("Error: %s\n", err)
		os.Exit(1)
	}

	fmt.Println("parse was successful")
}

// ---- this one fails ----
// steps to reproduce
// comment out above init func
// uncomment following func
// spin build && spin up
// curl http://localhost:3000
// func init() {
// 	spinhttp.Handle(func(w http.ResponseWriter, r *http.Request) {
// 		err := parse()
// 		if err != nil {
// 			http.Error(w, err.Error(), http.StatusInternalServerError)
// 			return
// 		}

// 		fmt.Fprintln(w, "Hello Fermyon!")
// 	})
// }

func main() {}

func parse() error {
	payload := `{"action":"labeled","issue":{}}`
	_, err := github.ParseWebHook("issues", []byte(payload))
	if err != nil {
		return fmt.Errorf("failed to parse payload. Error: %v", err)
	}

	return nil
}

[adamreese]

@rajatjindal It's an unrelated isssue. But... I couldn't reproduce this working in wasmtime but the issue is refection not being fully implemented in tinygo.