fix: log and count opcache restarts

docs/metrics.md

@@ -23,9 +23,12 @@ When [Caddy metrics](https://caddyserver.com/docs/metrics) are enabled, FrankenP
 - `frankenphp_worker_crashes{worker="[worker_name]"}`: The number of times a worker has unexpectedly terminated.
 - `frankenphp_worker_restarts{worker="[worker_name]"}`: The number of times a worker has been deliberately restarted.
 - `frankenphp_worker_queue_depth{worker="[worker_name]"}`: The number of queued requests.
+- `frankenphp_opcache_restarts{reason="[reason]"}`: (experimental) The number of restarts of opcache's shared memory scheduled, by reason (`oom`, `hash`, `manual`). PHP 8.4 and up.
 
 For worker metrics, the `[worker_name]` placeholder is replaced by the worker name in the Caddyfile, otherwise the absolute path of the worker file will be used.
 
+opcache schedules a restart when its cache is full and more than `opcache.max_wasted_percentage` of it was wasted by invalidations. The restart runs at the next request start; caching is off until then, and running PHP threads may still reference the old memory, which can crash the process. The counter should stay at zero: raise `opcache.memory_consumption`, `opcache.max_accelerated_files` or `opcache.max_wasted_percentage`. `manual` should never appear, FrankenPHP overrides `opcache_reset()`. Each restart is also logged. This metric will be removed once opcache handles restarts safely under ZTS.
+
 ## Threads State Endpoint
 
 FrankenPHP exposes a `/frankenphp/threads` endpoint through the [Caddy admin API](https://caddyserver.com/docs/api).

frankenphp.c

@@ -1007,6 +1007,12 @@ PHP_FUNCTION(frankenphp_log) {
   }
 }
 
+#if FRANKENPHP_OPCACHE_RESTART_HOOK
+static void frankenphp_opcache_restart_hook(int reason) {
+  go_opcache_restart_scheduled(reason);
+}
+#endif
+
 /* {{{ thread-safe opcache reset */
 PHP_FUNCTION(frankenphp_opcache_reset) {
   go_schedule_opcache_reset(frankenphp_thread_index());
@@ -1709,6 +1715,11 @@ static void *php_main(void *arg) {
 
   frankenphp_sapi_module.startup(&frankenphp_sapi_module);
 
+#if FRANKENPHP_OPCACHE_RESTART_HOOK
+  /* Report the opcache restarts that opcache schedules on its own */
+  zend_accel_schedule_restart_hook = frankenphp_opcache_restart_hook;
+#endif
+
   /* check if a default filter is set in php.ini and only filter if
    * it is, this is deprecated and will be removed in PHP 9 */
   char *default_filter;

frankenphp.go

@@ -845,6 +845,43 @@ func go_schedule_opcache_reset(threadIndex C.uintptr_t) {
 	}
 }
 
+// opcacheRestartHook tells whether this build reports the restarts opcache
+// schedules on its own: PHP 8.4 brought the hook, and only ZTS builds are
+// exposed to them
+var opcacheRestartHook = C.FRANKENPHP_OPCACHE_RESTART_HOOK != 0
+
+// Restart reasons opcache reports to the hook, in the order of
+// zend_accel_restart_reason (ext/opcache/ZendAccelerator.h), named like the
+// counters of opcache_get_status()
+var opcacheRestartReasons = [...]string{"oom", "hash", "manual"}
+
+//export go_opcache_restart_scheduled
+func go_opcache_restart_scheduled(reason C.int) {
+	opcacheRestartScheduled(int(reason))
+}
+
+func opcacheRestartScheduled(reason int) {
+	reasonText := "unknown"
+	if reason >= 0 && reason < len(opcacheRestartReasons) {
+		reasonText = opcacheRestartReasons[reason]
+	}
+
+	if m, ok := metrics.(OpcacheMetrics); ok {
+		m.OpcacheRestart(reasonText)
+	}
+
+	if !globalLogger.Enabled(globalCtx, slog.LevelWarn) {
+		return
+	}
+
+	// written synchronously, under opcache's lock: a line deferred to a
+	// goroutine is lost if the restart crashes the process
+	globalLogger.LogAttrs(globalCtx, slog.LevelWarn,
+		"opcache restart scheduled, caching stops until the next request start carries it out while other threads may still reference the old memory: raise opcache.memory_consumption, opcache.max_accelerated_files or opcache.max_wasted_percentage",
+		slog.String("reason", reasonText),
+	)
+}
+
 func convertArgs(args []string) (C.int, []*C.char) {
 	argc := C.int(len(args))
 	argv := make([]*C.char, argc)

frankenphp.h

@@ -16,6 +16,7 @@
 
 #include <Zend/zend_modules.h>
 #include <Zend/zend_types.h>
+#include <php_version.h>
 #include <stdbool.h>
 #include <stdint.h>
 
@@ -41,6 +42,12 @@ typedef struct {
 #endif
 } force_kill_slot;
 
+#if defined(ZTS) && PHP_VERSION_ID >= 80400
+#define FRANKENPHP_OPCACHE_RESTART_HOOK 1
+#else
+#define FRANKENPHP_OPCACHE_RESTART_HOOK 0
+#endif
+
 #ifndef FRANKENPHP_VERSION
 #define FRANKENPHP_VERSION dev
 #endif

metrics.go

@@ -16,6 +16,9 @@ const (
 
 type StopReason int
 
+// Metrics reports what the workers and the threads of a FrankenPHP instance
+// are doing. An implementation that also satisfies OpcacheMetrics is told
+// about opcache restarts as well.
 type Metrics interface {
 	// StartWorker collects started workers
 	StartWorker(name string)
@@ -42,6 +45,14 @@ type Metrics interface {
 	DequeuedRequest()
 }
 
+// OpcacheMetrics is the optional part of a Metrics implementation that counts
+// the restarts of opcache's shared memory, by reason, where the build reports
+// them (ZTS, PHP 8.4 and up). An implementation passed to WithMetrics() that
+// lacks it only misses the counter, the restart is logged either way.
+type OpcacheMetrics interface {
+	OpcacheRestart(reason string)
+}
+
 type nullMetrics struct{}
 
 func (n nullMetrics) StartWorker(string) {
@@ -94,6 +105,7 @@ type PrometheusMetrics struct {
 	workerRequestCount *prometheus.CounterVec
 	workerQueueDepth   *prometheus.GaugeVec
 	queueDepth         prometheus.Gauge
+	opcacheRestarts    *prometheus.CounterVec
 	mu                 sync.RWMutex
 }
 
@@ -106,6 +118,11 @@ func (m *PrometheusMetrics) mustRegister(c prometheus.Collector) {
 	}
 }
 
+var (
+	_ Metrics        = (*PrometheusMetrics)(nil)
+	_ OpcacheMetrics = (*PrometheusMetrics)(nil)
+)
+
 func (m *PrometheusMetrics) StartWorker(name string) {
 	m.mu.RLock()
 	defer m.mu.RUnlock()
@@ -317,6 +334,15 @@ func (m *PrometheusMetrics) DequeuedRequest() {
 	m.queueDepth.Dec()
 }
 
+func (m *PrometheusMetrics) OpcacheRestart(reason string) {
+	m.mu.RLock()
+	defer m.mu.RUnlock()
+
+	if m.opcacheRestarts != nil {
+		m.opcacheRestarts.WithLabelValues(reason).Inc()
+	}
+}
+
 func (m *PrometheusMetrics) Shutdown() {
 	m.mu.Lock()
 	defer m.mu.Unlock()
@@ -325,6 +351,10 @@ func (m *PrometheusMetrics) Shutdown() {
 	m.registry.Unregister(m.busyThreads)
 	m.registry.Unregister(m.queueDepth)
 
+	if m.opcacheRestarts != nil {
+		m.registry.Unregister(m.opcacheRestarts)
+	}
+
 	if m.totalWorkers != nil {
 		m.registry.Unregister(m.totalWorkers)
 	}
@@ -377,6 +407,11 @@ func NewPrometheusMetrics(registry prometheus.Registerer) *PrometheusMetrics {
 			Name: "frankenphp_queue_depth",
 			Help: "Number of regular queued requests",
 		}),
+		// experimental: to be removed once opcache handles restarts safely under ZTS
+		opcacheRestarts: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "frankenphp_opcache_restarts",
+			Help: "Number of restarts of opcache's shared memory scheduled, by reason (experimental, should stay at zero)",
+		}, []string{"reason"}),
 		totalWorkers:       nil,
 		busyWorkers:        nil,
 		workerRequestTime:  nil,
@@ -393,5 +428,17 @@ func NewPrometheusMetrics(registry prometheus.Registerer) *PrometheusMetrics {
 
 	m.mustRegister(m.queueDepth)
 
+	// only where the hook exists: a series stuck at zero would read as "no
+	// restart" on a build that cannot report one
+	if opcacheRestartHook {
+		m.mustRegister(m.opcacheRestarts)
+
+		// expose the series at zero so a rate or an alert on it works from the
+		// first restart on, instead of missing it for lack of a previous sample
+		for _, reason := range opcacheRestartReasons {
+			m.opcacheRestarts.WithLabelValues(reason)
+		}
+	}
+
 	return m
 }

metrics_test.go

@@ -1,12 +1,15 @@
 package frankenphp
 
 import (
+	"bytes"
+	"log/slog"
 	"strings"
 	"testing"
 	"time"
 
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/testutil"
+	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 )
 
@@ -212,3 +215,71 @@ func TestPrometheusMetrics_TestStopReasonCrash(t *testing.T) {
 
 	}
 }
+
+func TestPrometheusMetrics_OpcacheRestart(t *testing.T) {
+	if !opcacheRestartHook {
+		t.Skip("this build has no opcache restart hook")
+	}
+
+	registry := prometheus.NewRegistry()
+	m := NewPrometheusMetrics(registry)
+	m.OpcacheRestart("hash")
+	m.OpcacheRestart("hash")
+	m.OpcacheRestart("oom")
+
+	// known reasons are exposed from the start, unknown ones only once seen
+	require.NoError(t, testutil.GatherAndCompare(registry, strings.NewReader(`
+		# HELP frankenphp_opcache_restarts Number of restarts of opcache's shared memory scheduled, by reason (experimental, should stay at zero)
+		# TYPE frankenphp_opcache_restarts counter
+		frankenphp_opcache_restarts{reason="hash"} 2
+		frankenphp_opcache_restarts{reason="manual"} 0
+		frankenphp_opcache_restarts{reason="oom"} 1
+	`), "frankenphp_opcache_restarts"))
+
+	m.OpcacheRestart("unknown")
+
+	require.NoError(t, testutil.CollectAndCompare(m.opcacheRestarts, strings.NewReader(`
+		# HELP frankenphp_opcache_restarts Number of restarts of opcache's shared memory scheduled, by reason (experimental, should stay at zero)
+		# TYPE frankenphp_opcache_restarts counter
+		frankenphp_opcache_restarts{reason="hash"} 2
+		frankenphp_opcache_restarts{reason="manual"} 0
+		frankenphp_opcache_restarts{reason="oom"} 1
+		frankenphp_opcache_restarts{reason="unknown"} 1
+	`)))
+}
+
+func TestOpcacheRestartScheduledLogsAndCounts(t *testing.T) {
+	if !opcacheRestartHook {
+		t.Skip("this build has no opcache restart hook")
+	}
+
+	var buf bytes.Buffer
+	m := NewPrometheusMetrics(prometheus.NewRegistry())
+	prevLogger, prevMetrics := globalLogger, metrics
+	globalLogger, metrics = slog.New(slog.NewTextHandler(&buf, nil)), m
+	t.Cleanup(func() { globalLogger, metrics = prevLogger, prevMetrics })
+
+	opcacheRestartScheduled(1)
+	opcacheRestartScheduled(7)
+
+	assert.Contains(t, buf.String(), `level=WARN msg="opcache restart scheduled`)
+	assert.Contains(t, buf.String(), "reason=hash")
+	assert.Contains(t, buf.String(), "reason=unknown")
+	assert.Equal(t, float64(1), testutil.ToFloat64(m.opcacheRestarts.WithLabelValues("hash")))
+	assert.Equal(t, float64(1), testutil.ToFloat64(m.opcacheRestarts.WithLabelValues("unknown")))
+}
+
+func TestOpcacheRestartScheduledWithoutOpcacheMetrics(t *testing.T) {
+	// nullMetrics is a Metrics without the optional part, like an
+	// implementation from before OpcacheMetrics existed
+	_, ok := Metrics(nullMetrics{}).(OpcacheMetrics)
+	require.False(t, ok)
+
+	var buf bytes.Buffer
+	prevLogger, prevMetrics := globalLogger, metrics
+	globalLogger, metrics = slog.New(slog.NewTextHandler(&buf, nil)), nullMetrics{}
+	t.Cleanup(func() { globalLogger, metrics = prevLogger, prevMetrics })
+
+	assert.NotPanics(t, func() { opcacheRestartScheduled(0) })
+	assert.Contains(t, buf.String(), "reason=oom")
+}