From 44b17c0a620ae649fc9541c1fe09d8ff1af9a6b1 Mon Sep 17 00:00:00 2001 From: Igor Krestov Date: Wed, 17 Dec 2025 15:54:02 +0100 Subject: [PATCH] feat: track request cpu and peak memory usage and expose in caddy replacer vars This captures request cpu (user+system) and peak memory usage similar to FPM and Apache2 SAPIs. To propagate this back to Go we store it in FrankenPHP context first, before retrieving it in embedder / runtime (e.g. Caddy) from context. For better compatibility with FPM logging we expose script and script filename vars as well. CPU usage is nanoseconds user space and system space thread runtime (only works on POSIX that supports clock_gettime(CLOCK_THREAD_CPUTIME_ID)). Memory usage is retrieved at the end of every request. In worker mode we reset peak memory usage before every request. Using in Caddy: ``` log_append cpu_usage_human {http.frankenphp.cpu_usage_human} log_append cpu_usage {http.frankenphp.cpu_usage} log_append memory_usage {http.frankenphp.memory_usage} log_append memory_usage_human {http.frankenphp.memory_usage_human} log_append script {http.frankenphp.script} log_append script_filename {http.frankenphp.script_filename} ``` --- caddy/module.go | 54 +++++++++++++++++++++++++++++++++++++++++++++++- cgi.go | 2 ++ context.go | 10 +++++++++ frankenphp.c | 5 +++++ frankenphp.go | 23 +++++++++++++++++++++ phpthread.go | 34 +++++++++++++++++++++++------- threadregular.go | 2 ++ threadworker.go | 6 ++++++ 8 files changed, 128 insertions(+), 8 deletions(-) diff --git a/caddy/module.go b/caddy/module.go index b116a5e1a..5fccb3390 100644 --- a/caddy/module.go +++ b/caddy/module.go @@ -10,6 +10,7 @@ import ( "slices" "strconv" "strings" + "time" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig" @@ -235,13 +236,64 @@ func (f *FrankenPHPModule) ServeHTTP(w http.ResponseWriter, r *http.Request, _ c // TODO: set caddyhttp.ServerHeader when https://github.com/caddyserver/caddy/pull/7338 will be released w.Header()["Server"] = serverHeader - if err = frankenphp.ServeHTTP(w, fr); err != nil && !errors.As(err, &frankenphp.ErrRejected{}) { + err = frankenphp.ServeHTTP(w, fr) + + // Retrieve and add stats to the Caddy Replacer + stats, ok := frankenphp.StatusFromContext(fr.Context()) + if ok { + repl.Map(func(key string) (any, bool) { + switch key { + case "http.frankenphp.cpu_usage": + return stats.CpuUsage.Nanoseconds(), true + case "http.frankenphp.cpu_usage_human": + return stats.CpuUsage.String(), true + case "http.frankenphp.memory_usage": + return stats.MemoryUsage, true + case "http.frankenphp.memory_usage_human": + return formatBytes(stats.MemoryUsage), true + case "http.frankenphp.script": + return stats.Script, true + case "http.frankenphp.script_filename": + return stats.ScriptFilename, true + default: + return "", false + } + }) + } + + if err != nil && !errors.As(err, &frankenphp.ErrRejected{}) { return caddyhttp.Error(http.StatusInternalServerError, err) } return nil } +func formatDuration(d time.Duration) string { + if d.Hours() >= 1 { + return fmt.Sprintf("%.2f h", d.Hours()) + } + if d.Minutes() >= 1 { + return fmt.Sprintf("%.2f m", d.Minutes()) + } + if d.Seconds() >= 1 { + return fmt.Sprintf("%.2f s", d.Seconds()) + } + return fmt.Sprintf("%d ms", d.Milliseconds()) +} + +func formatBytes(b uint64) string { + if (b >> 30) > 0 { + return fmt.Sprintf("%.2f GB", float64(b)/float64(1<<30)) + } + if (b >> 20) > 0 { + return fmt.Sprintf("%.2f MB", float64(b)/float64(1<<20)) + } + if (b >> 10) > 0 { + return fmt.Sprintf("%.2f KB", float64(b)/float64(1<<10)) + } + return fmt.Sprintf("%d B", b) +} + // UnmarshalCaddyfile implements caddyfile.Unmarshaler. func (f *FrankenPHPModule) UnmarshalCaddyfile(d *caddyfile.Dispenser) error { for d.Next() { diff --git a/cgi.go b/cgi.go index 63fb1339b..8a34fcb76 100644 --- a/cgi.go +++ b/cgi.go @@ -311,6 +311,8 @@ func go_update_request_info(threadIndex C.uintptr_t, info *C.sapi_request_info) info.request_uri = thread.pinCString(request.URL.RequestURI()) info.proto_num = C.int(request.ProtoMajor*1000 + request.ProtoMinor) + + C.clock_gettime(C.CLOCK_THREAD_CPUTIME_ID, &thread.cpuRequestStartTime) } // SanitizedPathJoin performs filepath.Join(root, reqPath) that diff --git a/context.go b/context.go index 3126e8f9a..c2599e725 100644 --- a/context.go +++ b/context.go @@ -38,6 +38,16 @@ type frankenPHPContext struct { done chan any startedAt time.Time + + memoryUsage uint64 + cpuUsage time.Duration +} + +type Stats struct { + MemoryUsage uint64 + CpuUsage time.Duration + Script string + ScriptFilename string } type contextHolder struct { diff --git a/frankenphp.c b/frankenphp.c index a6772a86e..3564d9f95 100644 --- a/frankenphp.c +++ b/frankenphp.c @@ -456,6 +456,9 @@ PHP_FUNCTION(frankenphp_handle_request) { fci.params = result.r1; fci.param_count = result.r1 == NULL ? 0 : 1; + // Reset memory peak usage at the start of the request + zend_memory_reset_peak_usage(); + if (zend_call_function(&fci, &fcc) == SUCCESS && Z_TYPE(retval) != IS_UNDEF) { callback_ret = &retval; } @@ -609,6 +612,8 @@ static zend_module_entry frankenphp_module = { STANDARD_MODULE_PROPERTIES}; static void frankenphp_request_shutdown() { + go_frankenphp_set_memory_peak_usage(thread_index, zend_memory_peak_usage(1)); + frankenphp_free_request_context(); php_request_shutdown((void *)0); } diff --git a/frankenphp.go b/frankenphp.go index 744439138..af52c534b 100644 --- a/frankenphp.go +++ b/frankenphp.go @@ -382,6 +382,29 @@ func Shutdown() { resetGlobals() } +// Stats returns FrankenPHP-specific execution stats from the given context. +func StatusFromContext(ctx context.Context) (Stats, bool) { + fc, ok := fromContext(ctx) + if !ok { + return Stats{}, false + } + if fc.worker != nil { + return Stats{ + CpuUsage: fc.cpuUsage, + MemoryUsage: fc.memoryUsage, + Script: fc.worker.fileName, + ScriptFilename: fc.worker.fileName, + }, true + } else { + return Stats{ + CpuUsage: fc.cpuUsage, + MemoryUsage: fc.memoryUsage, + Script: fc.scriptName, + ScriptFilename: fc.scriptFilename, + }, true + } +} + // ServeHTTP executes a PHP script according to the given context. func ServeHTTP(responseWriter http.ResponseWriter, request *http.Request) error { h := responseWriter.Header() diff --git a/phpthread.go b/phpthread.go index 1726cf9d1..e173a992d 100644 --- a/phpthread.go +++ b/phpthread.go @@ -7,6 +7,7 @@ import ( "context" "runtime" "sync" + "time" "unsafe" "github.com/dunglas/frankenphp/internal/state" @@ -16,13 +17,16 @@ import ( // identified by the index in the phpThreads slice type phpThread struct { runtime.Pinner - threadIndex int - requestChan chan contextHolder - drainChan chan struct{} - handlerMu sync.Mutex - handler threadHandler - state *state.ThreadState - sandboxedEnv map[string]*C.zend_string + threadIndex int + requestChan chan contextHolder + drainChan chan struct{} + handlerMu sync.Mutex + handler threadHandler + state *state.ThreadState + sandboxedEnv map[string]*C.zend_string + cpuRequestStartTime C.struct_timespec + lastRequestCpuUsage time.Duration + lastRequestMemoryUsage uint64 } // interface that defines how the callbacks from the C thread should be handled @@ -147,6 +151,12 @@ func (*phpThread) updateContext(isWorker bool) { C.frankenphp_update_local_thread_context(C.bool(isWorker)) } +func (thread *phpThread) requestCpuUsage() time.Duration { + var cpuEndTime C.struct_timespec + C.clock_gettime(C.CLOCK_THREAD_CPUTIME_ID, &cpuEndTime) + return time.Duration(float64(cpuEndTime.tv_sec-thread.cpuRequestStartTime.tv_sec)*1e9 + float64(cpuEndTime.tv_nsec-thread.cpuRequestStartTime.tv_nsec)) +} + //export go_frankenphp_before_script_execution func go_frankenphp_before_script_execution(threadIndex C.uintptr_t) *C.char { thread := phpThreads[threadIndex] @@ -167,12 +177,22 @@ func go_frankenphp_after_script_execution(threadIndex C.uintptr_t, exitStatus C. if exitStatus < 0 { panic(ErrScriptExecution) } + + // Calculate CPU usage + thread.lastRequestCpuUsage = thread.requestCpuUsage() + thread.handler.afterScriptExecution(int(exitStatus)) // unpin all memory used during script execution thread.Unpin() } +//export go_frankenphp_set_memory_peak_usage +func go_frankenphp_set_memory_peak_usage(threadIndex C.uintptr_t, memoryPeakUsage C.size_t) { + thread := phpThreads[threadIndex] + thread.lastRequestMemoryUsage = uint64(memoryPeakUsage) +} + //export go_frankenphp_on_thread_shutdown func go_frankenphp_on_thread_shutdown(threadIndex C.uintptr_t) { thread := phpThreads[threadIndex] diff --git a/threadregular.go b/threadregular.go index ad44c5717..c6e2217dc 100644 --- a/threadregular.go +++ b/threadregular.go @@ -100,6 +100,8 @@ func (handler *regularThread) waitForRequest() string { } func (handler *regularThread) afterRequest() { + handler.contextHolder.frankenPHPContext.cpuUsage = handler.thread.lastRequestCpuUsage + handler.contextHolder.frankenPHPContext.memoryUsage = handler.thread.lastRequestMemoryUsage handler.contextHolder.frankenPHPContext.closeContext() handler.contextHolder.frankenPHPContext = nil handler.ctx = nil diff --git a/threadworker.go b/threadworker.go index ae7e4545f..58737e306 100644 --- a/threadworker.go +++ b/threadworker.go @@ -285,6 +285,12 @@ func go_frankenphp_finish_worker_request(threadIndex C.uintptr_t, retval *C.zval ctx := thread.context() fc := ctx.Value(contextKey).(*frankenPHPContext) + // Stats + thread.lastRequestCpuUsage = thread.requestCpuUsage() + thread.lastRequestMemoryUsage = uint64(C.zend_memory_peak_usage(C.bool(true))) + fc.cpuUsage = thread.lastRequestCpuUsage + fc.memoryUsage = thread.lastRequestMemoryUsage + if retval != nil { r, err := GoValue[any](unsafe.Pointer(retval)) if err != nil && globalLogger.Enabled(ctx, slog.LevelError) {