diff --git a/testdata/crashing-worker.php b/testdata/crashing-worker.php new file mode 100644 index 0000000000..a1243a78cf --- /dev/null +++ b/testdata/crashing-worker.php @@ -0,0 +1,15 @@ += 2) { + exit(1); + } + + echo 'ok'; +}; + +while (frankenphp_handle_request($handler)) { +} diff --git a/threadworker.go b/threadworker.go index 843e1dd331..1b08b91591 100644 --- a/threadworker.go +++ b/threadworker.go @@ -160,8 +160,10 @@ func tearDownWorkerScript(handler *workerThread, exitStatus int) { if !handler.isBootingScript { // fatal error (could be due to exit(1), timeouts, etc.) - if globalLogger.Enabled(globalCtx, slog.LevelDebug) { - globalLogger.LogAttrs(globalCtx, slog.LevelDebug, "restarting", slog.String("worker", worker.name), slog.Int("thread", handler.thread.threadIndex), slog.Int("exit_status", exitStatus)) + // unlike a clean restart, this took down any in-flight request, so + // surface it above debug level, with the exit status needed to triage it + if globalLogger.Enabled(globalCtx, slog.LevelWarn) { + globalLogger.LogAttrs(globalCtx, slog.LevelWarn, "unexpected termination, restarting", slog.String("worker", worker.name), slog.Int("thread", handler.thread.threadIndex), slog.Int("exit_status", exitStatus)) } return @@ -175,7 +177,7 @@ func tearDownWorkerScript(handler *workerThread, exitStatus int) { if watcherIsEnabled { // worker script has probably failed due to script changes while watcher is enabled - if globalLogger.Enabled(globalCtx, slog.LevelError) { + if globalLogger.Enabled(globalCtx, slog.LevelWarn) { globalLogger.LogAttrs(globalCtx, slog.LevelWarn, "(watcher enabled) worker script has not reached frankenphp_handle_request()", slog.String("worker", worker.name), slog.Int("thread", handler.thread.threadIndex)) } } else { diff --git a/worker_test.go b/worker_test.go index 3fd2d63f94..dc423294f6 100644 --- a/worker_test.go +++ b/worker_test.go @@ -112,6 +112,18 @@ func TestWorkerGetOpt(t *testing.T) { assert.NotRegexp(t, buf.String(), "exit_status=[1-9]") } +func TestWorkerCrashIsLoggedAboveDebugLevel(t *testing.T) { + logger, buf := newTestLogger(t) + + runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { + req := httptest.NewRequest("GET", "http://example.com/crashing-worker.php", nil) + w := httptest.NewRecorder() + handler(w, req) + }, &testOptions{logger: logger, workerScript: "crashing-worker.php", nbWorkers: 1, nbParallelRequests: 4}) + + assert.Regexp(t, `level=WARN msg="unexpected termination, restarting" worker=\S+ thread=\d+ exit_status=1`, buf.String()) +} + func ExampleServeHTTP_workers() { if err := frankenphp.Init( frankenphp.WithWorkers("worker1", "worker1.php", 4,