chore: add context to logs to make the linter happy (#1533)

This commit is contained in:
Kévin Dunglas
2025-04-29 01:08:15 +02:00
committed by GitHub
parent d10a243f86
commit 8583afd83e
8 changed files with 52 additions and 35 deletions

View File

@@ -30,6 +30,7 @@ package frankenphp
import "C"
import (
"bytes"
"context"
"errors"
"fmt"
"io"
@@ -291,9 +292,10 @@ func Init(options ...Option) error {
initAutoScaling(mainThread)
logger.LogAttrs(nil, slog.LevelInfo, "FrankenPHP started 🐘", slog.String("php_version", Version().Version), slog.Int("num_threads", mainThread.numThreads), slog.Int("max_threads", mainThread.maxThreads))
ctx := context.Background()
logger.LogAttrs(ctx, slog.LevelInfo, "FrankenPHP started 🐘", slog.String("php_version", Version().Version), slog.Int("num_threads", mainThread.numThreads), slog.Int("max_threads", mainThread.maxThreads))
if EmbeddedAppPath != "" {
logger.LogAttrs(nil, slog.LevelInfo, "embedded PHP app 📦", slog.String("path", EmbeddedAppPath))
logger.LogAttrs(ctx, slog.LevelInfo, "embedded PHP app 📦", slog.String("path", EmbeddedAppPath))
}
return nil
@@ -428,7 +430,7 @@ func go_ub_write(threadIndex C.uintptr_t, cBuf *C.char, length C.int) (C.size_t,
i, e := writer.Write(unsafe.Slice((*byte)(unsafe.Pointer(cBuf)), length))
if e != nil {
fc.logger.LogAttrs(nil, slog.LevelError, "write error", slog.Any("error", e))
fc.logger.LogAttrs(context.Background(), slog.LevelError, "write error", slog.Any("error", e))
}
if fc.responseWriter == nil {
@@ -447,7 +449,7 @@ func go_apache_request_headers(threadIndex C.uintptr_t) (*C.go_string, C.size_t)
if fc.responseWriter == nil {
// worker mode, not handling a request
logger.LogAttrs(nil, slog.LevelDebug, "apache_request_headers() called in non-HTTP context", slog.String("worker", fc.scriptFilename))
logger.LogAttrs(context.Background(), slog.LevelDebug, "apache_request_headers() called in non-HTTP context", slog.String("worker", fc.scriptFilename))
return nil, 0
}
@@ -478,7 +480,7 @@ func go_apache_request_headers(threadIndex C.uintptr_t) (*C.go_string, C.size_t)
func addHeader(fc *frankenPHPContext, cString *C.char, length C.int) {
parts := strings.SplitN(C.GoStringN(cString, length), ": ", 2)
if len(parts) != 2 {
fc.logger.LogAttrs(nil, slog.LevelDebug, "invalid header", slog.String("header", parts[0]))
fc.logger.LogAttrs(context.Background(), slog.LevelDebug, "invalid header", slog.String("header", parts[0]))
return
}
@@ -532,7 +534,7 @@ func go_sapi_flush(threadIndex C.uintptr_t) bool {
}
if err := http.NewResponseController(fc.responseWriter).Flush(); err != nil {
logger.LogAttrs(nil, slog.LevelError, "the current responseWriter is not a flusher", slog.Any("error", err))
logger.LogAttrs(context.Background(), slog.LevelError, "the current responseWriter is not a flusher", slog.Any("error", err))
}
return false
@@ -585,15 +587,15 @@ func go_log(message *C.char, level C.int) {
switch le {
case emerg, alert, crit, err:
logger.LogAttrs(nil, slog.LevelError, m, slog.String("syslog_level", syslogLevel(level).String()))
logger.LogAttrs(context.Background(), slog.LevelError, m, slog.String("syslog_level", syslogLevel(level).String()))
case warning:
logger.LogAttrs(nil, slog.LevelWarn, m, slog.String("syslog_level", syslogLevel(level).String()))
logger.LogAttrs(context.Background(), slog.LevelWarn, m, slog.String("syslog_level", syslogLevel(level).String()))
case debug:
logger.LogAttrs(nil, slog.LevelDebug, m, slog.String("syslog_level", syslogLevel(level).String()))
logger.LogAttrs(context.Background(), slog.LevelDebug, m, slog.String("syslog_level", syslogLevel(level).String()))
default:
logger.LogAttrs(nil, slog.LevelInfo, m, slog.String("syslog_level", syslogLevel(level).String()))
logger.LogAttrs(context.Background(), slog.LevelInfo, m, slog.String("syslog_level", syslogLevel(level).String()))
}
}

View File

@@ -1,6 +1,7 @@
package main
import (
"context"
"log/slog"
"net/http"
"os"
@@ -31,6 +32,6 @@ func main() {
port = "8080"
}
logger.LogAttrs(nil, slog.LevelError, "server error", slog.Any("error", http.ListenAndServe(":"+port, nil)))
logger.LogAttrs(context.Background(), slog.LevelError, "server error", slog.Any("error", http.ListenAndServe(":"+port, nil)))
os.Exit(1)
}

View File

@@ -3,6 +3,7 @@
package watcher
import (
"context"
"log/slog"
"path/filepath"
"strings"
@@ -82,7 +83,7 @@ func isValidEventType(eventType int) bool {
// 0:dir,1:file,2:hard_link,3:sym_link,4:watcher,5:other,
func isValidPathType(pathType int, fileName string) bool {
if pathType == 4 {
logger.LogAttrs(nil, slog.LevelDebug, "special edant/watcher event", slog.String("fileName", fileName))
logger.LogAttrs(context.Background(), slog.LevelDebug, "special edant/watcher event", slog.String("fileName", fileName))
}
return pathType <= 2
}
@@ -165,7 +166,7 @@ func matchPattern(pattern string, fileName string) bool {
}
patternMatches, err := filepath.Match(pattern, fileName)
if err != nil {
logger.LogAttrs(nil, slog.LevelError, "failed to match filename", slog.String("file", fileName), slog.Any("error", err))
logger.LogAttrs(context.Background(), slog.LevelError, "failed to match filename", slog.String("file", fileName), slog.Any("error", err))
return false
}

View File

@@ -8,6 +8,7 @@ package watcher
// #include "watcher.h"
import "C"
import (
"context"
"errors"
"log/slog"
"runtime/cgo"
@@ -79,13 +80,15 @@ func DrainWatcher() {
// TODO: how to test this?
func retryWatching(watchPattern *watchPattern) {
ctx := context.Background()
failureMu.Lock()
defer failureMu.Unlock()
if watchPattern.failureCount >= maxFailureCount {
logger.LogAttrs(nil, slog.LevelWarn, "giving up watching", slog.String("dir", watchPattern.dir))
logger.LogAttrs(ctx, slog.LevelWarn, "giving up watching", slog.String("dir", watchPattern.dir))
return
}
logger.LogAttrs(nil, slog.LevelInfo, "watcher was closed prematurely, retrying...", slog.String("dir", watchPattern.dir))
logger.LogAttrs(ctx, slog.LevelInfo, "watcher was closed prematurely, retrying...", slog.String("dir", watchPattern.dir))
watchPattern.failureCount++
session, err := startSession(watchPattern)
@@ -132,15 +135,18 @@ func (w *watcher) stopWatching() {
}
func startSession(w *watchPattern) (C.uintptr_t, error) {
ctx := context.Background()
handle := cgo.NewHandle(w)
cDir := C.CString(w.dir)
defer C.free(unsafe.Pointer(cDir))
watchSession := C.start_new_watcher(cDir, C.uintptr_t(handle))
if watchSession != 0 {
logger.LogAttrs(nil, slog.LevelDebug, "watching", slog.String("dir", w.dir), slog.Any("patterns", w.patterns))
logger.LogAttrs(ctx, slog.LevelDebug, "watching", slog.String("dir", w.dir), slog.Any("patterns", w.patterns))
return watchSession, nil
}
logger.LogAttrs(nil, slog.LevelError, "couldn't start watching", slog.String("dir", w.dir))
logger.LogAttrs(ctx, slog.LevelError, "couldn't start watching", slog.String("dir", w.dir))
return watchSession, ErrUnableToStartWatching
}
@@ -190,7 +196,7 @@ func listenForFileEvents(triggerWatcher chan string, stopWatcher chan struct{})
timer.Reset(debounceDuration)
case <-timer.C:
timer.Stop()
logger.LogAttrs(nil, slog.LevelInfo, "filesystem change detected", slog.String("file", lastChangedFile))
logger.LogAttrs(context.Background(), slog.LevelInfo, "filesystem change detected", slog.String("file", lastChangedFile))
scheduleReload()
}
}

View File

@@ -8,6 +8,7 @@ package frankenphp
// #include "frankenphp.h"
import "C"
import (
"context"
"log/slog"
"strings"
"sync"
@@ -170,7 +171,7 @@ func (mainThread *phpMainThread) setAutomaticMaxThreads() {
maxAllowedThreads := totalSysMemory / uint64(perThreadMemoryLimit)
mainThread.maxThreads = int(maxAllowedThreads)
logger.LogAttrs(nil, slog.LevelDebug, "Automatic thread limit", slog.Int("perThreadMemoryLimitMB", int(perThreadMemoryLimit/1024/1024)), slog.Int("maxThreads", mainThread.maxThreads))
logger.LogAttrs(context.Background(), slog.LevelDebug, "Automatic thread limit", slog.Int("perThreadMemoryLimitMB", int(perThreadMemoryLimit/1024/1024)), slog.Int("maxThreads", mainThread.maxThreads))
}
//export go_frankenphp_shutdown_main_thread

View File

@@ -4,6 +4,7 @@ package frankenphp
// #include "frankenphp.h"
import "C"
import (
"context"
"log/slog"
"runtime"
"sync"
@@ -55,7 +56,7 @@ func (thread *phpThread) boot() {
// start the actual posix thread - TODO: try this with go threads instead
if !C.frankenphp_new_php_thread(C.uintptr_t(thread.threadIndex)) {
logger.LogAttrs(nil, slog.LevelError, "unable to create thread", slog.Int("threadIndex", thread.threadIndex))
logger.LogAttrs(context.Background(), slog.LevelError, "unable to create thread", slog.Int("threadIndex", thread.threadIndex))
panic("unable to create thread")
}

View File

@@ -4,6 +4,7 @@ package frankenphp
//#include <sys/resource.h>
import "C"
import (
"context"
"errors"
"log/slog"
"sync"
@@ -53,7 +54,7 @@ func initAutoScaling(mainThread *phpMainThread) {
func drainAutoScaling() {
scalingMu.Lock()
logger.LogAttrs(nil, slog.LevelDebug, "shutting down autoscaling", slog.Int("autoScaledThreads", len(autoScaledThreads)))
logger.LogAttrs(context.Background(), slog.LevelDebug, "shutting down autoscaling", slog.Int("autoScaledThreads", len(autoScaledThreads)))
scalingMu.Unlock()
}
@@ -93,7 +94,7 @@ func scaleWorkerThread(worker *worker) {
thread, err := addWorkerThread(worker)
if err != nil {
logger.LogAttrs(nil, slog.LevelWarn, "could not increase max_threads, consider raising this limit", slog.String("worker", worker.name), slog.Any("error", err))
logger.LogAttrs(context.Background(), slog.LevelWarn, "could not increase max_threads, consider raising this limit", slog.String("worker", worker.name), slog.Any("error", err))
return
}
@@ -116,7 +117,7 @@ func scaleRegularThread() {
thread, err := addRegularThread()
if err != nil {
logger.LogAttrs(nil, slog.LevelWarn, "could not increase max_threads, consider raising this limit", slog.Any("error", err))
logger.LogAttrs(context.Background(), slog.LevelWarn, "could not increase max_threads, consider raising this limit", slog.Any("error", err))
return
}
@@ -196,7 +197,7 @@ func deactivateThreads() {
// convert threads to inactive if they have been idle for too long
if thread.state.is(stateReady) && waitTime > maxThreadIdleTime.Milliseconds() {
logger.LogAttrs(nil, slog.LevelDebug, "auto-converting thread to inactive", slog.Int("threadIndex", thread.threadIndex))
logger.LogAttrs(context.Background(), slog.LevelDebug, "auto-converting thread to inactive", slog.Int("threadIndex", thread.threadIndex))
convertToInactiveThread(thread)
stoppedThreadCount++
autoScaledThreads = append(autoScaledThreads[:i], autoScaledThreads[i+1:]...)

View File

@@ -3,6 +3,7 @@ package frankenphp
// #include "frankenphp.h"
import "C"
import (
"context"
"log/slog"
"path/filepath"
"time"
@@ -93,13 +94,15 @@ func setupWorkerScript(handler *workerThread, worker *worker) {
handler.dummyContext = fc
handler.isBootingScript = true
clearSandboxedEnv(handler.thread)
logger.LogAttrs(nil, slog.LevelDebug, "starting", slog.String("worker", worker.name), slog.Int("thread", handler.thread.threadIndex))
logger.LogAttrs(context.Background(), slog.LevelDebug, "starting", slog.String("worker", worker.name), slog.Int("thread", handler.thread.threadIndex))
}
func tearDownWorkerScript(handler *workerThread, exitStatus int) {
worker := handler.worker
handler.dummyContext = nil
ctx := context.Background()
// if the worker request is not nil, the script might have crashed
// make sure to close the worker request context
if handler.workerContext != nil {
@@ -112,7 +115,7 @@ func tearDownWorkerScript(handler *workerThread, exitStatus int) {
// TODO: make the max restart configurable
metrics.StopWorker(worker.name, StopReasonRestart)
handler.backoff.recordSuccess()
logger.LogAttrs(nil, slog.LevelDebug, "restarting", slog.String("worker", worker.name))
logger.LogAttrs(ctx, slog.LevelDebug, "restarting", slog.String("worker", worker.name))
return
}
@@ -124,15 +127,15 @@ func tearDownWorkerScript(handler *workerThread, exitStatus int) {
return
}
logger.LogAttrs(nil, slog.LevelError, "worker script has not reached frankenphp_handle_request", slog.String("worker", worker.name))
logger.LogAttrs(ctx, slog.LevelError, "worker script has not reached frankenphp_handle_request", slog.String("worker", worker.name))
// panic after exponential backoff if the worker has never reached frankenphp_handle_request
if handler.backoff.recordFailure() {
if !watcherIsEnabled && !handler.state.is(stateReady) {
logger.LogAttrs(nil, slog.LevelError, "too many consecutive worker failures", slog.String("worker", worker.name), slog.Int("failures", handler.backoff.failureCount))
logger.LogAttrs(ctx, slog.LevelError, "too many consecutive worker failures", slog.String("worker", worker.name), slog.Int("failures", handler.backoff.failureCount))
panic("too many consecutive worker failures")
}
logger.LogAttrs(nil, slog.LevelWarn, "many consecutive worker failures", slog.String("worker", worker.name), slog.Int("failures", handler.backoff.failureCount))
logger.LogAttrs(ctx, slog.LevelWarn, "many consecutive worker failures", slog.String("worker", worker.name), slog.Int("failures", handler.backoff.failureCount))
}
}
@@ -141,7 +144,8 @@ func (handler *workerThread) waitForWorkerRequest() bool {
// unpin any memory left over from previous requests
handler.thread.Unpin()
logger.LogAttrs(nil, slog.LevelDebug, "waiting for request", slog.String("worker", handler.worker.name))
ctx := context.Background()
logger.LogAttrs(ctx, slog.LevelDebug, "waiting for request", slog.String("worker", handler.worker.name))
// Clear the first dummy request created to initialize the worker
if handler.isBootingScript {
@@ -164,7 +168,7 @@ func (handler *workerThread) waitForWorkerRequest() bool {
var fc *frankenPHPContext
select {
case <-handler.thread.drainChan:
logger.LogAttrs(nil, slog.LevelDebug, "shutting down", slog.String("worker", handler.worker.name))
logger.LogAttrs(ctx, slog.LevelDebug, "shutting down", slog.String("worker", handler.worker.name))
// flush the opcache when restarting due to watcher or admin api
// note: this is done right before frankenphp_handle_request() returns 'false'
@@ -180,11 +184,11 @@ func (handler *workerThread) waitForWorkerRequest() bool {
handler.workerContext = fc
handler.state.markAsWaiting(false)
logger.LogAttrs(nil, slog.LevelDebug, "request handling started", slog.String("worker", handler.worker.name), slog.String("url", fc.request.RequestURI))
logger.LogAttrs(ctx, slog.LevelDebug, "request handling started", slog.String("worker", handler.worker.name), slog.String("url", fc.request.RequestURI))
if err := updateServerContext(handler.thread, fc, true); err != nil {
// Unexpected error or invalid request
logger.LogAttrs(nil, slog.LevelDebug, "unexpected error", slog.String("worker", handler.worker.name), slog.String("url", fc.request.RequestURI), slog.Any("error", err))
logger.LogAttrs(ctx, slog.LevelDebug, "unexpected error", slog.String("worker", handler.worker.name), slog.String("url", fc.request.RequestURI), slog.Any("error", err))
fc.rejectBadRequest(err.Error())
handler.workerContext = nil
@@ -212,7 +216,7 @@ func go_frankenphp_finish_worker_request(threadIndex C.uintptr_t) {
fc.closeContext()
thread.handler.(*workerThread).workerContext = nil
fc.logger.LogAttrs(nil, slog.LevelDebug, "request handling finished", slog.String("worker", fc.scriptFilename), slog.String("url", fc.request.RequestURI))
fc.logger.LogAttrs(context.Background(), slog.LevelDebug, "request handling finished", slog.String("worker", fc.scriptFilename), slog.String("url", fc.request.RequestURI))
}
// when frankenphp_finish_request() is directly called from PHP
@@ -222,5 +226,5 @@ func go_frankenphp_finish_php_request(threadIndex C.uintptr_t) {
fc := phpThreads[threadIndex].getRequestContext()
fc.closeContext()
fc.logger.LogAttrs(nil, slog.LevelDebug, "request handling finished", slog.String("url", fc.request.RequestURI))
fc.logger.LogAttrs(context.Background(), slog.LevelDebug, "request handling finished", slog.String("url", fc.request.RequestURI))
}