feat(debug): add more metrics in ThreadDebugState

Author: alexandre-daubois

caddy/admin_test.go

@@ -82,6 +82,46 @@ func TestShowTheCorrectThreadDebugStatus(t *testing.T) {
 	assert.Len(t, debugState.ThreadDebugStates, 3)
 }
 
+func TestThreadDebugStateMetricsAfterRequests(t *testing.T) {
+	tester := caddytest.NewTester(t)
+	tester.InitServer(`
+		{
+			skip_install_trust
+			admin localhost:2999
+			http_port `+testPort+`
+
+			frankenphp {
+				num_threads 2
+				worker ../testdata/worker-with-counter.php 1
+			}
+		}
+
+		localhost:`+testPort+` {
+			route {
+				root ../testdata
+				rewrite worker-with-counter.php
+				php
+			}
+		}
+		`, "caddyfile")
+
+	// make a few requests so counters are populated
+	tester.AssertGetResponse("http://localhost:"+testPort+"/", http.StatusOK, "requests:1")
+	tester.AssertGetResponse("http://localhost:"+testPort+"/", http.StatusOK, "requests:2")
+	tester.AssertGetResponse("http://localhost:"+testPort+"/", http.StatusOK, "requests:3")
+
+	debugState := getDebugState(t, tester)
+
+	hasRequestCount := false
+	for _, ts := range debugState.ThreadDebugStates {
+		if ts.RequestCount > 0 {
+			hasRequestCount = true
+			assert.Greater(t, ts.MemoryUsage, int64(0), "thread %d (%s) should report memory usage", ts.Index, ts.Name)
+		}
+	}
+	assert.True(t, hasRequestCount, "at least one thread should have RequestCount > 0 after serving requests")
+}
+
 func TestAutoScaleWorkerThreads(t *testing.T) {
 	wg := sync.WaitGroup{}
 	maxTries := 10

debugstate.go

@@ -12,6 +12,11 @@ type ThreadDebugState struct {
 	IsWaiting                bool
 	IsBusy                   bool
 	WaitingSinceMilliseconds int64
+	CurrentURI               string
+	CurrentMethod            string
+	RequestStartedAt         int64
+	RequestCount             int64
+	MemoryUsage              int64
 }
 
 // EXPERIMENTAL: FrankenPHPDebugState prints the state of all PHP threads - debugging purposes only
@@ -39,12 +44,38 @@ func DebugState() FrankenPHPDebugState {
 
 // threadDebugState creates a small jsonable status message for debugging purposes
 func threadDebugState(thread *phpThread) ThreadDebugState {
-	return ThreadDebugState{
+	isBusy := !thread.state.IsInWaitingState()
+
+	s := ThreadDebugState{
 		Index:                    thread.threadIndex,
 		Name:                     thread.name(),
 		State:                    thread.state.Name(),
 		IsWaiting:                thread.state.IsInWaitingState(),
-		IsBusy:                   !thread.state.IsInWaitingState(),
+		IsBusy:                   isBusy,
 		WaitingSinceMilliseconds: thread.state.WaitTime(),
 	}
+
+	s.RequestCount = thread.requestCount.Load()
+	s.MemoryUsage = thread.lastMemoryUsage.Load()
+
+	if isBusy {
+		thread.handlerMu.RLock()
+		fc := thread.handler.frankenPHPContext()
+		thread.handlerMu.RUnlock()
+
+		if fc != nil && fc.request != nil && fc.responseWriter != nil {
+			if fc.originalRequest != nil {
+				s.CurrentURI = fc.originalRequest.URL.RequestURI()
+				s.CurrentMethod = fc.originalRequest.Method
+			} else {
+				s.CurrentURI = fc.requestURI
+				s.CurrentMethod = fc.request.Method
+			}
+			if !fc.startedAt.IsZero() {
+				s.RequestStartedAt = fc.startedAt.UnixMilli()
+			}
+		}
+	}
+
+	return s
 }

frankenphp.c

@@ -244,8 +244,12 @@ static void frankenphp_reset_session_state(void) {
 }
 #endif
 
+static __thread size_t thread_last_memory_usage = 0;
+
 /* Adapted from php_request_shutdown */
 static void frankenphp_worker_request_shutdown() {
+  thread_last_memory_usage = zend_memory_usage(0);
+
   /* Flush all output buffers */
   zend_try { php_output_end_all(); }
   zend_end_try();
@@ -1232,6 +1236,7 @@ int frankenphp_execute_script(char *file_name) {
     sandboxed_env = NULL;
   }
 
+  thread_last_memory_usage = zend_memory_usage(0);
   php_request_shutdown((void *)0);
   frankenphp_free_request_context();
 
@@ -1404,6 +1409,10 @@ int frankenphp_reset_opcache(void) {
 
 int frankenphp_get_current_memory_limit() { return PG(memory_limit); }
 
+size_t frankenphp_get_current_memory_usage() {
+  return thread_last_memory_usage;
+}
+
 static zend_module_entry **modules = NULL;
 static int modules_len = 0;
 static int (*original_php_register_internal_extensions_func)(void) = NULL;

frankenphp.h

@@ -185,6 +185,7 @@ void frankenphp_register_server_vars(zval *track_vars_array,
 zend_string *frankenphp_init_persistent_string(const char *string, size_t len);
 int frankenphp_reset_opcache(void);
 int frankenphp_get_current_memory_limit();
+size_t frankenphp_get_current_memory_usage();
 
 void register_extensions(zend_module_entry **m, int len);
 

phpthread.go

@@ -7,6 +7,7 @@ import (
 	"context"
 	"runtime"
 	"sync"
+	"sync/atomic"
 	"unsafe"
 
 	"github.com/dunglas/frankenphp/internal/state"
@@ -16,12 +17,14 @@ import (
 // identified by the index in the phpThreads slice
 type phpThread struct {
 	runtime.Pinner
-	threadIndex int
-	requestChan chan contextHolder
-	drainChan   chan struct{}
-	handlerMu   sync.RWMutex
-	handler     threadHandler
-	state       *state.ThreadState
+	threadIndex     int
+	requestChan     chan contextHolder
+	drainChan       chan struct{}
+	handlerMu       sync.RWMutex
+	handler         threadHandler
+	state           *state.ThreadState
+	requestCount    atomic.Int64
+	lastMemoryUsage atomic.Int64
 }
 
 // threadHandler defines how the callbacks from the C thread should be handled
@@ -173,6 +176,10 @@ func go_frankenphp_after_script_execution(threadIndex C.uintptr_t, exitStatus C.
 	if exitStatus < 0 {
 		panic(ErrScriptExecution)
 	}
+
+	thread.requestCount.Add(1)
+	thread.lastMemoryUsage.Store(int64(C.frankenphp_get_current_memory_usage()))
+
 	thread.handler.afterScriptExecution(int(exitStatus))
 
 	// unpin all memory used during script execution

threadworker.go

@@ -292,6 +292,9 @@ func go_frankenphp_finish_worker_request(threadIndex C.uintptr_t, retval *C.zval
 		fc.handlerReturn = r
 	}
 
+	thread.requestCount.Add(1)
+	thread.lastMemoryUsage.Store(int64(C.frankenphp_get_current_memory_usage()))
+
 	fc.closeContext()
 	thread.handler.(*workerThread).workerFrankenPHPContext = nil
 	thread.handler.(*workerThread).workerContext = nil