Skip to content

Commit 44b17c0

Browse files
committed
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} ```
1 parent e01e40f commit 44b17c0

File tree

8 files changed

+128
-8
lines changed

8 files changed

+128
-8
lines changed

caddy/module.go

Lines changed: 53 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ import (
1010
"slices"
1111
"strconv"
1212
"strings"
13+
"time"
1314

1415
"github.com/caddyserver/caddy/v2"
1516
"github.com/caddyserver/caddy/v2/caddyconfig"
@@ -235,13 +236,64 @@ func (f *FrankenPHPModule) ServeHTTP(w http.ResponseWriter, r *http.Request, _ c
235236

236237
// TODO: set caddyhttp.ServerHeader when https://github.com/caddyserver/caddy/pull/7338 will be released
237238
w.Header()["Server"] = serverHeader
238-
if err = frankenphp.ServeHTTP(w, fr); err != nil && !errors.As(err, &frankenphp.ErrRejected{}) {
239+
err = frankenphp.ServeHTTP(w, fr)
240+
241+
// Retrieve and add stats to the Caddy Replacer
242+
stats, ok := frankenphp.StatusFromContext(fr.Context())
243+
if ok {
244+
repl.Map(func(key string) (any, bool) {
245+
switch key {
246+
case "http.frankenphp.cpu_usage":
247+
return stats.CpuUsage.Nanoseconds(), true
248+
case "http.frankenphp.cpu_usage_human":
249+
return stats.CpuUsage.String(), true
250+
case "http.frankenphp.memory_usage":
251+
return stats.MemoryUsage, true
252+
case "http.frankenphp.memory_usage_human":
253+
return formatBytes(stats.MemoryUsage), true
254+
case "http.frankenphp.script":
255+
return stats.Script, true
256+
case "http.frankenphp.script_filename":
257+
return stats.ScriptFilename, true
258+
default:
259+
return "", false
260+
}
261+
})
262+
}
263+
264+
if err != nil && !errors.As(err, &frankenphp.ErrRejected{}) {
239265
return caddyhttp.Error(http.StatusInternalServerError, err)
240266
}
241267

242268
return nil
243269
}
244270

271+
func formatDuration(d time.Duration) string {
272+
if d.Hours() >= 1 {
273+
return fmt.Sprintf("%.2f h", d.Hours())
274+
}
275+
if d.Minutes() >= 1 {
276+
return fmt.Sprintf("%.2f m", d.Minutes())
277+
}
278+
if d.Seconds() >= 1 {
279+
return fmt.Sprintf("%.2f s", d.Seconds())
280+
}
281+
return fmt.Sprintf("%d ms", d.Milliseconds())
282+
}
283+
284+
func formatBytes(b uint64) string {
285+
if (b >> 30) > 0 {
286+
return fmt.Sprintf("%.2f GB", float64(b)/float64(1<<30))
287+
}
288+
if (b >> 20) > 0 {
289+
return fmt.Sprintf("%.2f MB", float64(b)/float64(1<<20))
290+
}
291+
if (b >> 10) > 0 {
292+
return fmt.Sprintf("%.2f KB", float64(b)/float64(1<<10))
293+
}
294+
return fmt.Sprintf("%d B", b)
295+
}
296+
245297
// UnmarshalCaddyfile implements caddyfile.Unmarshaler.
246298
func (f *FrankenPHPModule) UnmarshalCaddyfile(d *caddyfile.Dispenser) error {
247299
for d.Next() {

cgi.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -311,6 +311,8 @@ func go_update_request_info(threadIndex C.uintptr_t, info *C.sapi_request_info)
311311
info.request_uri = thread.pinCString(request.URL.RequestURI())
312312

313313
info.proto_num = C.int(request.ProtoMajor*1000 + request.ProtoMinor)
314+
315+
C.clock_gettime(C.CLOCK_THREAD_CPUTIME_ID, &thread.cpuRequestStartTime)
314316
}
315317

316318
// SanitizedPathJoin performs filepath.Join(root, reqPath) that

context.go

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,16 @@ type frankenPHPContext struct {
3838

3939
done chan any
4040
startedAt time.Time
41+
42+
memoryUsage uint64
43+
cpuUsage time.Duration
44+
}
45+
46+
type Stats struct {
47+
MemoryUsage uint64
48+
CpuUsage time.Duration
49+
Script string
50+
ScriptFilename string
4151
}
4252

4353
type contextHolder struct {

frankenphp.c

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -456,6 +456,9 @@ PHP_FUNCTION(frankenphp_handle_request) {
456456
fci.params = result.r1;
457457
fci.param_count = result.r1 == NULL ? 0 : 1;
458458

459+
// Reset memory peak usage at the start of the request
460+
zend_memory_reset_peak_usage();
461+
459462
if (zend_call_function(&fci, &fcc) == SUCCESS && Z_TYPE(retval) != IS_UNDEF) {
460463
callback_ret = &retval;
461464
}
@@ -609,6 +612,8 @@ static zend_module_entry frankenphp_module = {
609612
STANDARD_MODULE_PROPERTIES};
610613

611614
static void frankenphp_request_shutdown() {
615+
go_frankenphp_set_memory_peak_usage(thread_index, zend_memory_peak_usage(1));
616+
612617
frankenphp_free_request_context();
613618
php_request_shutdown((void *)0);
614619
}

frankenphp.go

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -382,6 +382,29 @@ func Shutdown() {
382382
resetGlobals()
383383
}
384384

385+
// Stats returns FrankenPHP-specific execution stats from the given context.
386+
func StatusFromContext(ctx context.Context) (Stats, bool) {
387+
fc, ok := fromContext(ctx)
388+
if !ok {
389+
return Stats{}, false
390+
}
391+
if fc.worker != nil {
392+
return Stats{
393+
CpuUsage: fc.cpuUsage,
394+
MemoryUsage: fc.memoryUsage,
395+
Script: fc.worker.fileName,
396+
ScriptFilename: fc.worker.fileName,
397+
}, true
398+
} else {
399+
return Stats{
400+
CpuUsage: fc.cpuUsage,
401+
MemoryUsage: fc.memoryUsage,
402+
Script: fc.scriptName,
403+
ScriptFilename: fc.scriptFilename,
404+
}, true
405+
}
406+
}
407+
385408
// ServeHTTP executes a PHP script according to the given context.
386409
func ServeHTTP(responseWriter http.ResponseWriter, request *http.Request) error {
387410
h := responseWriter.Header()

phpthread.go

Lines changed: 27 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import (
77
"context"
88
"runtime"
99
"sync"
10+
"time"
1011
"unsafe"
1112

1213
"github.com/dunglas/frankenphp/internal/state"
@@ -16,13 +17,16 @@ import (
1617
// identified by the index in the phpThreads slice
1718
type phpThread struct {
1819
runtime.Pinner
19-
threadIndex int
20-
requestChan chan contextHolder
21-
drainChan chan struct{}
22-
handlerMu sync.Mutex
23-
handler threadHandler
24-
state *state.ThreadState
25-
sandboxedEnv map[string]*C.zend_string
20+
threadIndex int
21+
requestChan chan contextHolder
22+
drainChan chan struct{}
23+
handlerMu sync.Mutex
24+
handler threadHandler
25+
state *state.ThreadState
26+
sandboxedEnv map[string]*C.zend_string
27+
cpuRequestStartTime C.struct_timespec
28+
lastRequestCpuUsage time.Duration
29+
lastRequestMemoryUsage uint64
2630
}
2731

2832
// interface that defines how the callbacks from the C thread should be handled
@@ -147,6 +151,12 @@ func (*phpThread) updateContext(isWorker bool) {
147151
C.frankenphp_update_local_thread_context(C.bool(isWorker))
148152
}
149153

154+
func (thread *phpThread) requestCpuUsage() time.Duration {
155+
var cpuEndTime C.struct_timespec
156+
C.clock_gettime(C.CLOCK_THREAD_CPUTIME_ID, &cpuEndTime)
157+
return time.Duration(float64(cpuEndTime.tv_sec-thread.cpuRequestStartTime.tv_sec)*1e9 + float64(cpuEndTime.tv_nsec-thread.cpuRequestStartTime.tv_nsec))
158+
}
159+
150160
//export go_frankenphp_before_script_execution
151161
func go_frankenphp_before_script_execution(threadIndex C.uintptr_t) *C.char {
152162
thread := phpThreads[threadIndex]
@@ -167,12 +177,22 @@ func go_frankenphp_after_script_execution(threadIndex C.uintptr_t, exitStatus C.
167177
if exitStatus < 0 {
168178
panic(ErrScriptExecution)
169179
}
180+
181+
// Calculate CPU usage
182+
thread.lastRequestCpuUsage = thread.requestCpuUsage()
183+
170184
thread.handler.afterScriptExecution(int(exitStatus))
171185

172186
// unpin all memory used during script execution
173187
thread.Unpin()
174188
}
175189

190+
//export go_frankenphp_set_memory_peak_usage
191+
func go_frankenphp_set_memory_peak_usage(threadIndex C.uintptr_t, memoryPeakUsage C.size_t) {
192+
thread := phpThreads[threadIndex]
193+
thread.lastRequestMemoryUsage = uint64(memoryPeakUsage)
194+
}
195+
176196
//export go_frankenphp_on_thread_shutdown
177197
func go_frankenphp_on_thread_shutdown(threadIndex C.uintptr_t) {
178198
thread := phpThreads[threadIndex]

threadregular.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -100,6 +100,8 @@ func (handler *regularThread) waitForRequest() string {
100100
}
101101

102102
func (handler *regularThread) afterRequest() {
103+
handler.contextHolder.frankenPHPContext.cpuUsage = handler.thread.lastRequestCpuUsage
104+
handler.contextHolder.frankenPHPContext.memoryUsage = handler.thread.lastRequestMemoryUsage
103105
handler.contextHolder.frankenPHPContext.closeContext()
104106
handler.contextHolder.frankenPHPContext = nil
105107
handler.ctx = nil

threadworker.go

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -285,6 +285,12 @@ func go_frankenphp_finish_worker_request(threadIndex C.uintptr_t, retval *C.zval
285285
ctx := thread.context()
286286
fc := ctx.Value(contextKey).(*frankenPHPContext)
287287

288+
// Stats
289+
thread.lastRequestCpuUsage = thread.requestCpuUsage()
290+
thread.lastRequestMemoryUsage = uint64(C.zend_memory_peak_usage(C.bool(true)))
291+
fc.cpuUsage = thread.lastRequestCpuUsage
292+
fc.memoryUsage = thread.lastRequestMemoryUsage
293+
288294
if retval != nil {
289295
r, err := GoValue[any](unsafe.Pointer(retval))
290296
if err != nil && globalLogger.Enabled(ctx, slog.LevelError) {

0 commit comments

Comments
 (0)