fix: log and count opcache restarts

docs/metrics.md

@@ -23,6 +23,7 @@ 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]"}`: The number of times opcache restarted its shared memory on its own, by reason (`out of memory`, `hash overflow`, `user`). Each restart is also logged. Under ZTS, running PHP threads may hold stale references to the rewound memory, so raise `opcache.memory_consumption` and `opcache.max_accelerated_files` when this counter grows.
 
 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.
 

frankenphp.c

@@ -1017,6 +1017,18 @@ PHP_FUNCTION(frankenphp_log) {
   }
 }
 
+/* Called by opcache right before it schedules a restart of its shared memory,
+ * on exhaustion or hash overflow. FrankenPHP does not act on it, the restart
+ * is only logged and counted so a crash or a sudden slowdown can be traced
+ * back to it.
+ * Guarded like its only assignment in php_main(), so builds without the hook
+ * do not trip -Werror=unused-function. */
+#if defined(ZTS) && PHP_VERSION_ID >= 80400
+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());
@@ -1705,6 +1717,11 @@ static void *php_main(void *arg) {
 
   frankenphp_sapi_module.startup(&frankenphp_sapi_module);
 
+#if defined(ZTS) && PHP_VERSION_ID >= 80400
+  /* 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

@@ -780,6 +780,37 @@ func go_schedule_opcache_reset(threadIndex C.uintptr_t) {
 	}
 }
 
+// Restart reasons opcache reports to the hook, in the order of
+// zend_accel_restart_reason (ext/opcache/ZendAccelerator.h).
+var opcacheRestartReasons = [...]string{"out of memory", "hash overflow", "user"}
+
+// go_opcache_restart_scheduled reports the restarts opcache schedules on its
+// own, as a log line and as a counter. Under ZTS they rewind shared memory
+// that running threads still point into, which surfaces as an unexplained
+// crash or slowdown, so make the event visible. Both are done inline even
+// though opcache can be holding its shared memory lock: that costs far less
+// than the restart it precedes, and work deferred to a goroutine would be
+// lost when the restart takes the process down.
+//
+//export go_opcache_restart_scheduled
+func go_opcache_restart_scheduled(reason C.int) {
+	reasonText := "unknown"
+	if i := int(reason); i >= 0 && i < len(opcacheRestartReasons) {
+		reasonText = opcacheRestartReasons[i]
+	}
+
+	metrics.OpcacheRestart(reasonText)
+
+	if !globalLogger.Enabled(globalCtx, slog.LevelWarn) {
+		return
+	}
+
+	globalLogger.LogAttrs(globalCtx, slog.LevelWarn,
+		"opcache restart scheduled, running PHP threads may hold stale references to its shared memory: raise opcache.memory_consumption and opcache.max_accelerated_files to make restarts less likely",
+		slog.String("reason", reasonText),
+	)
+}
+
 func convertArgs(args []string) (C.int, []*C.char) {
 	argc := C.int(len(args))
 	argv := make([]*C.char, argc)

metrics.go

@@ -40,6 +40,8 @@ type Metrics interface {
 	DequeuedWorkerRequest(name string)
 	QueuedRequest()
 	DequeuedRequest()
+	// OpcacheRestart collects the restarts of opcache's shared memory, by reason
+	OpcacheRestart(reason string)
 }
 
 type nullMetrics struct{}
@@ -81,6 +83,8 @@ func (n nullMetrics) DequeuedWorkerRequest(string) {}
 func (n nullMetrics) QueuedRequest()   {}
 func (n nullMetrics) DequeuedRequest() {}
 
+func (n nullMetrics) OpcacheRestart(string) {}
+
 type PrometheusMetrics struct {
 	registry           prometheus.Registerer
 	totalThreads       prometheus.Gauge
@@ -94,6 +98,7 @@ type PrometheusMetrics struct {
 	workerRequestCount *prometheus.CounterVec
 	workerQueueDepth   *prometheus.GaugeVec
 	queueDepth         prometheus.Gauge
+	opcacheRestarts    *prometheus.CounterVec
 	mu                 sync.RWMutex
 }
 
@@ -332,13 +337,21 @@ func (m *PrometheusMetrics) DequeuedRequest() {
 	m.queueDepth.Dec()
 }
 
+func (m *PrometheusMetrics) OpcacheRestart(reason string) {
+	m.mu.RLock()
+	defer m.mu.RUnlock()
+
+	m.opcacheRestarts.WithLabelValues(reason).Inc()
+}
+
 func (m *PrometheusMetrics) Shutdown() {
 	m.mu.Lock()
 	defer m.mu.Unlock()
 
 	m.registry.Unregister(m.totalThreads)
 	m.registry.Unregister(m.busyThreads)
 	m.registry.Unregister(m.queueDepth)
+	m.registry.Unregister(m.opcacheRestarts)
 
 	if m.totalWorkers != nil {
 		m.registry.Unregister(m.totalWorkers)
@@ -392,6 +405,10 @@ func NewPrometheusMetrics(registry prometheus.Registerer) *PrometheusMetrics {
 			Name: "frankenphp_queue_depth",
 			Help: "Number of regular queued requests",
 		}),
+		opcacheRestarts: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "frankenphp_opcache_restarts",
+			Help: "Number of restarts of opcache's shared memory, by reason",
+		}, []string{"reason"}),
 		totalWorkers:       nil,
 		busyWorkers:        nil,
 		workerRequestTime:  nil,
@@ -417,5 +434,16 @@ func NewPrometheusMetrics(registry prometheus.Registerer) *PrometheusMetrics {
 		panic(err)
 	}
 
+	if err := m.registry.Register(m.opcacheRestarts); err != nil &&
+		!errors.As(err, &prometheus.AlreadyRegisteredError{}) {
+		panic(err)
+	}
+
+	// expose the series at zero so a rate or an alert on them 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

@@ -212,3 +212,30 @@ func TestPrometheusMetrics_TestStopReasonCrash(t *testing.T) {
 
 	}
 }
+
+func TestPrometheusMetrics_OpcacheRestart(t *testing.T) {
+	m := NewPrometheusMetrics(prometheus.NewRegistry())
+	m.OpcacheRestart("hash overflow")
+	m.OpcacheRestart("hash overflow")
+	m.OpcacheRestart("out of memory")
+
+	// known reasons are exposed from the start, unknown ones only once seen
+	require.NoError(t, testutil.CollectAndCompare(m.opcacheRestarts, strings.NewReader(`
+		# HELP frankenphp_opcache_restarts Number of restarts of opcache's shared memory, by reason
+		# TYPE frankenphp_opcache_restarts counter
+		frankenphp_opcache_restarts{reason="hash overflow"} 2
+		frankenphp_opcache_restarts{reason="out of memory"} 1
+		frankenphp_opcache_restarts{reason="user"} 0
+	`)))
+
+	m.OpcacheRestart("unknown")
+
+	require.NoError(t, testutil.CollectAndCompare(m.opcacheRestarts, strings.NewReader(`
+		# HELP frankenphp_opcache_restarts Number of restarts of opcache's shared memory, by reason
+		# TYPE frankenphp_opcache_restarts counter
+		frankenphp_opcache_restarts{reason="hash overflow"} 2
+		frankenphp_opcache_restarts{reason="out of memory"} 1
+		frankenphp_opcache_restarts{reason="unknown"} 1
+		frankenphp_opcache_restarts{reason="user"} 0
+	`)))
+}