diff --git a/internal/simulation/userspace.go b/internal/simulation/userspace.go index 5e8abca..00e6007 100644 --- a/internal/simulation/userspace.go +++ b/internal/simulation/userspace.go @@ -74,7 +74,8 @@ func setupSlog(machineLabel string) { panic(err) } - // TODO: capture stdout? stderr? + // stdout and stderr are currently captured with some special logic in + // LinuxOS for writes to their file descriptors, see TestStdoutStderr. ho := slog.HandlerOptions{ Level: level, @@ -91,14 +92,15 @@ func setupSlog(machineLabel string) { } func setupUserspace(gosimOS_ *GosimOS, linuxOS_ *LinuxOS, machineID int, label string) { - // XXX: does logging work during global init? - gosimruntime.InitGlobals(false, false) - - // yikes... how do we order this? should machine exist first? should these happen in an init() in here SOMEHOW? short-circuit this package? - // XXX: provide directoyr + // initialize gosimOS etc. before invoking initializers so that init() calls + // can make syscalls, see TestSyscallsDuringInit. gosimOS = gosimOS_ linuxOS = linuxOS_ currentMachineID = machineID + gosimruntime.InitGlobals(false, false) + + // setupSlog only works once globals are initialized. logs during init are + // printed to stdout/stderr, see TestLogDuringInit. setupSlog(label) } diff --git a/internal/tests/behavior/log_meta_test.go b/internal/tests/behavior/log_meta_test.go index 80bfe27..0ed5be9 100644 --- a/internal/tests/behavior/log_meta_test.go +++ b/internal/tests/behavior/log_meta_test.go @@ -33,7 +33,7 @@ func parseLog(t *testing.T, log []byte) []map[string]any { return logs } -func TestMetaLogMachineGoroutineTime(t *testing.T) { +func TestLogMachineGoroutineTime(t *testing.T) { mt := metatesting.ForCurrentPackage(t) run, err := mt.Run(t, &metatesting.RunConfig{ Test: "TestLogMachineGoroutineTime", @@ -55,7 +55,7 @@ func TestMetaLogMachineGoroutineTime(t *testing.T) { } } -func TestMetaLogSLog(t *testing.T) { +func TestLogSLog(t *testing.T) { mt := metatesting.ForCurrentPackage(t) run, err := mt.Run(t, &metatesting.RunConfig{ Test: "TestLogSLog", @@ -74,7 +74,7 @@ func TestMetaLogSLog(t *testing.T) { } } -func TestMetaStdoutStderr(t *testing.T) { +func TestStdoutStderr(t *testing.T) { mt := metatesting.ForCurrentPackage(t) run, err := mt.Run(t, &metatesting.RunConfig{ Test: "TestStdoutStderr", @@ -93,3 +93,26 @@ func TestMetaStdoutStderr(t *testing.T) { t.Error("diff", diff) } } + +func TestLogDuringInit(t *testing.T) { + mt := metatesting.ForCurrentPackage(t) + run, err := mt.Run(t, &metatesting.RunConfig{ + Test: "TestLogDuringInit", + Seed: 1, + ExtraEnv: []string{ + "LOGDURINGINIT=1", + }, + }) + if err != nil { + t.Fatal(err) + } + + actual := parseLog(t, run.LogOutput) + expected := parseLog(t, []byte(`{"time":"2020-01-15T14:10:03.000001234Z","level":"INFO","msg":"hello\n","machine":"os","method":"stdout","from":"main","goroutine":1,"step":1} +{"time":"2020-01-15T14:10:03.000001234Z","level":"INFO","msg":"2020/01/15 14:10:03 INFO help\n","machine":"os","method":"stderr","from":"main","goroutine":1,"step":2} +`)) + + if diff := cmp.Diff(expected, actual); diff != "" { + t.Error("diff", diff) + } +} diff --git a/internal/tests/behavior/log_test.go b/internal/tests/behavior/log_test.go index ef6f439..10aaa7c 100644 --- a/internal/tests/behavior/log_test.go +++ b/internal/tests/behavior/log_test.go @@ -3,6 +3,7 @@ package behavior_test import ( + "fmt" "log" "log/slog" "os" @@ -62,3 +63,15 @@ func TestLogForPrettyTest(t *testing.T) { m.Wait() log.Println("never") } + +func init() { + // logs during init will print to stdout/stderr bypassing the gosim handler + if os.Getenv("LOGDURINGINIT") == "1" { + fmt.Println("hello") + slog.Info("help") + } +} + +func TestLogDuringInit(t *testing.T) { + // logs in above init() should print +} diff --git a/internal/tests/behavior/os_sim_test.go b/internal/tests/behavior/os_sim_test.go index 71c9e45..fa9eac1 100644 --- a/internal/tests/behavior/os_sim_test.go +++ b/internal/tests/behavior/os_sim_test.go @@ -41,3 +41,30 @@ func TestGetpagesize(t *testing.T) { t.Fatalf("bad page size %d", pgsize) } } + +var globalHostname string + +func init() { + globalHostname, _ = os.Hostname() +} + +func TestSyscallsDuringInit(t *testing.T) { + // Test that os.Hostname() called in an init func can make syscalls. + + expected := "main" + if globalHostname != expected { + t.Errorf("bad name %q, expected %q", globalHostname, expected) + } + + m := gosim.NewMachine(gosim.MachineConfig{ + Label: "hello123", + MainFunc: func() { + expected := "hello123" + if globalHostname != expected { + t.Errorf("bad name %q, expected %q", globalHostname, expected) + } + }, + }) + + m.Wait() +}