tinygo support, goroutine hack change, fix panic for invalid stderr, …

…add test (#66)

* Fix panic for invalid stderr, add test

* auto switch to stdout for wasm - manual tested

* Throw the towel on goroutine, use the original directly, maintained for changes in linkname

* add alternative used to benchmark

* happy linters, happy life

* Add comment about the mutex

* review comments, thanks @ccoVeille for the thorough look

* Update logger_test.go

* Update logger_test.go

indicate why we don't just use io.Discard, some more

cc @ccoVeille

* increase coverage where possible, ie not in init()

* Apply suggestions from code review

Co-authored-by: ccoVeille <3875889+ccoVeille@users.noreply.github.com>

* more explanations of

---------

Co-authored-by: ccoVeille <3875889+ccoVeille@users.noreply.github.com>

console_logging.go

@@ -88,13 +88,26 @@ var (
 	Color = false
 )
 
+// Is the file (e.g os.StdErr) Stat()able so we can detect if it's a tty or not.
+// If not we switch in init() to Stdout.
+func isValid(file *os.File) bool {
+	if file == nil {
+		return false
+	}
+	_, err := file.Stat()
+	return err == nil
+}
+
 // ConsoleLogging is a utility to check if the current logger output is a console (terminal).
 func ConsoleLogging() bool {
 	f, ok := jWriter.w.(*os.File)
 	if !ok {
 		return false
 	}
-	s, _ := f.Stat()
+	s, err := f.Stat()
+	if err != nil {
+		return false
+	}
 	return (s.Mode() & os.ModeCharDevice) == os.ModeCharDevice
 }
 

go.mod

@@ -2,4 +2,7 @@ module fortio.org/log
 
 go 1.18
 
-require fortio.org/struct2env v0.4.1
+require (
+	fortio.org/struct2env v0.4.1
+	github.com/kortschak/goroutine v1.1.2
+)

go.sum

@@ -1,2 +1,4 @@
 fortio.org/struct2env v0.4.1 h1:rJludAMO5eBvpWplWEQNqoVDFZr4RWMQX7RUapgZyc0=
 fortio.org/struct2env v0.4.1/go.mod h1:lENUe70UwA1zDUCX+8AsO663QCFqYaprk5lnPhjD410=
+github.com/kortschak/goroutine v1.1.2 h1:lhllcCuERxMIK5cYr8yohZZScL1na+JM5JYPRclWjck=
+github.com/kortschak/goroutine v1.1.2/go.mod h1:zKpXs1FWN/6mXasDQzfl7g0LrGFIOiA6cLs9eXKyaMY=

goroutine/gid.go

@@ -1,52 +1,14 @@
-// Copyright ©2020 Dan Kortschak. All rights reserved.
-// Use of this source code is governed by a BSD-style
-// license that can be found in the LICENSE file.
+//go:build !tinygo
 
-// Package goroutine provides a single function that will return the runtime's
-// ID number for the calling goroutine.
-//
-// The implementation is derived from Laevus Dexter's comment in Gophers' Slack #darkarts,
-// https://gophers.slack.com/archives/C1C1YSQBT/p1593885226448300 post which linked to
-// this playground snippet https://play.golang.org/p/CSOp9wyzydP.
 package goroutine
 
 import (
-	"reflect"
-	"unsafe"
+	"github.com/kortschak/goroutine" // Rely on and forward to the original rather than maintain our own copy.
 )
 
+const IsTinyGo = false
+
 // ID returns the runtime ID of the calling goroutine.
 func ID() int64 {
-	return *(*int64)(add(getg(), goidoff))
-}
-
-//go:nosplit
-func getg() unsafe.Pointer {
-	return *(*unsafe.Pointer)(add(getm(), curgoff))
+	return goroutine.ID()
 }
-
-//go:linkname add runtime.add
-//go:nosplit
-func add(p unsafe.Pointer, x uintptr) unsafe.Pointer
-
-//go:linkname getm runtime.getm
-//go:nosplit
-func getm() unsafe.Pointer
-
-var (
-	curgoff = offset("*runtime.m", "curg")
-	goidoff = offset("*runtime.g", "goid")
-)
-
-// offset returns the offset into typ for the given field.
-func offset(typ, field string) uintptr {
-	rt := toType(typesByString(typ)[0])
-	f, _ := rt.Elem().FieldByName(field)
-	return f.Offset
-}
-
-//go:linkname typesByString reflect.typesByString
-func typesByString(s string) []unsafe.Pointer
-
-//go:linkname toType reflect.toType
-func toType(t unsafe.Pointer) reflect.Type

goroutine/gid_test.go

@@ -10,6 +10,7 @@ import (
 	"strconv"
 	"strings"
 	"sync"
+	"sync/atomic"
 	"testing"
 )
 
@@ -19,8 +20,12 @@ func TestID(t *testing.T) {
 	if got != want {
 		t.Fatalf("unexpected id for main goroutine: got:%d want:%d", got, want)
 	}
+	n := 1000000 // for regular go
+	if IsTinyGo {
+		n = 1000 // for tinygo, it OOMs with 1000000 and we're only self testing that we get different increasing ids.
+	}
 	var wg sync.WaitGroup
-	for i := 0; i < 1000000; i++ {
+	for i := 0; i < n; i++ {
 		i := i
 		wg.Add(1)
 		go func() {
@@ -35,8 +40,14 @@ func TestID(t *testing.T) {
 	wg.Wait()
 }
 
+var testID int64
+
 // goid returns the goroutine ID extracted from a stack trace.
 func goid() int64 {
+	if IsTinyGo {
+		// pretty horrible test that aligns with the implementation, but at least it tests we get 1,2,3... different numbers.
+		return atomic.AddInt64(&testID, 1)
+	}
 	var buf [64]byte
 	n := runtime.Stack(buf[:], false)
 	idField := strings.Fields(strings.TrimPrefix(string(buf[:n]), "goroutine "))[0]
@@ -47,8 +58,9 @@ func goid() int64 {
 	return id
 }
 
+var gotid int64 // outside of the function to help avoiding compiler optimizations
+
 func BenchmarkGID(b *testing.B) {
-	var gotid int64
 	for n := 0; n < b.N; n++ {
 		gotid += ID()
 	}

goroutine/gid_tinygo.go

@@ -0,0 +1,39 @@
+//go:build tinygo
+
+package goroutine
+
+import (
+	"sync"
+	"unsafe"
+)
+
+const IsTinyGo = true
+
+var (
+	counter int64
+	mapping = make(map[uintptr]int64)
+	// TinyGo at the moment is single threaded, so this is not needed, but it's good to have anyway
+	// in case that changes. It does add ~5ns (from 20ns vs 4ns big go) but it's better to be correct.
+	// In theory, the mutex could be noop on platforms where everything is single threaded.
+	lock sync.Mutex
+)
+
+func ID() int64 {
+	task := uintptr(currentTask())
+	lock.Lock() // explicit minimal critical section without using defer, on purpose.
+	if id, ok := mapping[task]; ok {
+		lock.Unlock()
+		return id
+	}
+	counter++
+	mapping[task] = counter
+	lock.Unlock()
+	return counter
+	// or, super fast but ugly large numbers/pointers:
+	//return int64(uintptr(currentTask()))
+}
+
+// Call https://github.com/tinygo-org/tinygo/blob/v0.32.0/src/internal/task/task_stack.go#L39
+//
+//go:linkname currentTask internal/task.Current
+func currentTask() unsafe.Pointer

logger.go

@@ -174,6 +174,9 @@ func (l *JSONEntry) Time() time.Time {
 
 //nolint:gochecknoinits // needed
 func init() {
+	if !isValid(os.Stderr) { // wasm in browser case for instance
+		SetOutput(os.Stdout) // this could also be invalid too, but... we tried.
+	}
 	setLevel(Info) // starting value
 	levelToStrM = make(map[string]Level, 2*len(LevelToStrA))
 	JSONStringLevelToLevel = make(map[string]Level, len(LevelToJSON)-1) // -1 to not reverse info to NoLevel

logger_test.go

@@ -930,7 +930,26 @@ func TestConfigFromEnvOk(t *testing.T) {
 	}
 }
 
-// io.Discard but specially known to by logger optimizations for instance.
+func TestInvalidFile(t *testing.T) {
+	if isValid(nil) {
+		t.Errorf("expected nil to be invalid")
+	}
+	prev := jWriter.w
+	invalidFile := os.NewFile(^uintptr(0), "invalid-file")
+	jWriter.w = invalidFile
+	b := ConsoleLogging()
+	jWriter.w = prev
+	if b {
+		t.Errorf("expected not to be console logging")
+	}
+}
+
+// --- Benchmarks
+
+// This `discard` is like io.Discard, except that io.Discard is checked explicitly
+// (e.g. https://cs.opensource.google/go/go/+/refs/tags/go1.22.5:src/log/log.go;l=84)
+// in logger optimizations and we want to measure the actual production
+// of messages.
 type discard struct{}
 
 func (discard) Write(p []byte) (int, error) {