perf: prevent useless logger allocs

caddy/php-server.go

@@ -11,6 +11,7 @@ import (
 	"time"
 
 	mercureModule "github.com/dunglas/mercure/caddy"
+	"go.uber.org/zap/zapcore"
 
 	"github.com/caddyserver/caddy/v2"
 	"github.com/caddyserver/caddy/v2/caddyconfig"
@@ -21,7 +22,6 @@ import (
 	"github.com/caddyserver/caddy/v2/modules/caddyhttp/rewrite"
 	"github.com/caddyserver/certmagic"
 	"github.com/dunglas/frankenphp"
-	"go.uber.org/zap"
 
 	"github.com/spf13/cobra"
 )
@@ -313,7 +313,7 @@ func cmdPHPServer(fs caddycmd.Flags) (int, error) {
 		cfg.Logging = &caddy.Logging{
 			Logs: map[string]*caddy.CustomLog{
 				"default": {
-					BaseLog: caddy.BaseLog{Level: zap.DebugLevel.CapitalString()},
+					BaseLog: caddy.BaseLog{Level: zapcore.DebugLevel.CapitalString()},
 				},
 			},
 		}

frankenphp.go

@@ -43,6 +43,7 @@ import (
 
 	"github.com/maypok86/otter"
 	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 	// debug on Linux
 	//_ "github.com/ianlancetaylor/cgosymbolizer"
 )
@@ -319,9 +320,13 @@ func Init(options ...Option) error {
 		return err
 	}
 
-	logger.Info("FrankenPHP started 🐘", zap.String("php_version", Version().Version), zap.Int("num_threads", opt.numThreads))
+	if c := logger.Check(zapcore.InfoLevel, "FrankenPHP started 🐘"); c != nil {
+		c.Write(zap.String("php_version", Version().Version), zap.Int("num_threads", opt.numThreads))
+	}
 	if EmbeddedAppPath != "" {
-		logger.Info("embedded PHP app 📦", zap.String("path", EmbeddedAppPath))
+		if c := logger.Check(zapcore.InfoLevel, "embedded PHP app 📦"); c != nil {
+			c.Write(zap.String("path", EmbeddedAppPath))
+		}
 	}
 
 	return nil
@@ -517,7 +522,9 @@ func go_ub_write(rh C.uintptr_t, cBuf *C.char, length C.int) (C.size_t, C.bool)
 
 	i, e := writer.Write(unsafe.Slice((*byte)(unsafe.Pointer(cBuf)), length))
 	if e != nil {
-		fc.logger.Error("write error", zap.Error(e))
+		if c := fc.logger.Check(zapcore.ErrorLevel, "write error"); c != nil {
+			c.Write(zap.Error(e))
+		}
 	}
 
 	if fc.responseWriter == nil {
@@ -613,7 +620,7 @@ func go_apache_request_headers(rh, mrh C.uintptr_t) (*C.go_string, C.size_t, C.u
 		mr := cgo.Handle(mrh).Value().(*http.Request)
 		mfc := mr.Context().Value(contextKey).(*FrankenPHPContext)
 
-		if c := mfc.logger.Check(zap.DebugLevel, "apache_request_headers() called in non-HTTP context"); c != nil {
+		if c := mfc.logger.Check(zapcore.DebugLevel, "apache_request_headers() called in non-HTTP context"); c != nil {
 			c.Write(zap.String("worker", mfc.scriptFilename))
 		}
 
@@ -662,7 +669,9 @@ func go_apache_request_cleanup(rh C.uintptr_t) {
 func addHeader(fc *FrankenPHPContext, cString *C.char, length C.int) {
 	parts := strings.SplitN(C.GoStringN(cString, length), ": ", 2)
 	if len(parts) != 2 {
-		fc.logger.Debug("invalid header", zap.String("header", parts[0]))
+		if c := fc.logger.Check(zapcore.DebugLevel, "invalid header"); c != nil {
+			c.Write(zap.String("header", parts[0]))
+		}
 
 		return
 	}
@@ -708,7 +717,9 @@ func go_sapi_flush(rh C.uintptr_t) bool {
 	}
 
 	if err := http.NewResponseController(fc.responseWriter).Flush(); err != nil {
-		fc.logger.Error("the current responseWriter is not a flusher", zap.Error(err))
+		if c := fc.logger.Check(zapcore.ErrorLevel, "the current responseWriter is not a flusher"); c != nil {
+			c.Write(zap.Error(err))
+		}
 	}
 
 	return false
@@ -760,16 +771,24 @@ func go_log(message *C.char, level C.int) {
 
 	switch le {
 	case emerg, alert, crit, err:
-		l.Error(m, zap.Stringer("syslog_level", syslogLevel(level)))
+		if c := l.Check(zapcore.ErrorLevel, m); c != nil {
+			c.Write(zap.Stringer("syslog_level", syslogLevel(level)))
+		}
 
 	case warning:
-		l.Warn(m, zap.Stringer("syslog_level", syslogLevel(level)))
+		if c := l.Check(zapcore.WarnLevel, m); c != nil {
+			c.Write(zap.Stringer("syslog_level", syslogLevel(level)))
+		}
 
 	case debug:
-		l.Debug(m, zap.Stringer("syslog_level", syslogLevel(level)))
+		if c := l.Check(zapcore.DebugLevel, m); c != nil {
+			c.Write(zap.Stringer("syslog_level", syslogLevel(level)))
+		}
 
 	default:
-		l.Info(m, zap.Stringer("syslog_level", syslogLevel(level)))
+		if c := l.Check(zapcore.InfoLevel, m); c != nil {
+			c.Write(zap.Stringer("syslog_level", syslogLevel(level)))
+		}
 	}
 }
 

frankenphp_test.go

@@ -28,6 +28,7 @@ import (
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 	"go.uber.org/zap/zaptest"
 	"go.uber.org/zap/zaptest/observer"
 )
@@ -410,7 +411,7 @@ func TestLog_worker(t *testing.T) {
 	testLog(t, &testOptions{workerScript: "log.php"})
 }
 func testLog(t *testing.T, opts *testOptions) {
-	logger, logs := observer.New(zap.InfoLevel)
+	logger, logs := observer.New(zapcore.InfoLevel)
 	opts.logger = zap.New(logger)
 
 	runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) {
@@ -430,7 +431,7 @@ func TestConnectionAbort_worker(t *testing.T) {
 func testConnectionAbort(t *testing.T, opts *testOptions) {
 	testFinish := func(finish string) {
 		t.Run(fmt.Sprintf("finish=%s", finish), func(t *testing.T) {
-			logger, logs := observer.New(zap.InfoLevel)
+			logger, logs := observer.New(zapcore.InfoLevel)
 			opts.logger = zap.New(logger)
 
 			runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) {

worker.go

@@ -12,6 +12,7 @@ import (
 	"sync"
 
 	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 )
 
 var (
@@ -74,7 +75,10 @@ func startWorkers(fileName string, nbWorkers int, env PreparedEnv) error {
 					panic(err)
 				}
 
-				l.Debug("starting", zap.String("worker", absFileName), zap.Int("num", nbWorkers))
+				if c := l.Check(zapcore.DebugLevel, "starting"); c != nil {
+					c.Write(zap.String("worker", absFileName), zap.Int("num", nbWorkers))
+				}
+
 				if err := ServeHTTP(nil, r); err != nil {
 					panic(err)
 				}
@@ -91,17 +95,23 @@ func startWorkers(fileName string, nbWorkers int, env PreparedEnv) error {
 				if _, ok := workersRequestChans.Load(absFileName); ok {
 					workersReadyWG.Add(1)
 					if fc.exitStatus == 0 {
-						l.Info("restarting", zap.String("worker", absFileName))
+						if c := l.Check(zapcore.InfoLevel, "restarting"); c != nil {
+							c.Write(zap.String("worker", absFileName))
+						}
 					} else {
-						l.Error("unexpected termination, restarting", zap.String("worker", absFileName), zap.Int("exit_status", int(fc.exitStatus)))
+						if c := l.Check(zapcore.ErrorLevel, "unexpected termination, restarting"); c != nil {
+							c.Write(zap.String("worker", absFileName), zap.Int("exit_status", int(fc.exitStatus)))
+						}
 					}
 				} else {
 					break
 				}
 			}
 
 			// TODO: check if the termination is expected
-			l.Debug("terminated", zap.String("worker", absFileName))
+			if c := l.Check(zapcore.DebugLevel, "terminated"); c != nil {
+				c.Write(zap.String("worker", absFileName))
+			}
 		}()
 	}
 
@@ -141,15 +151,18 @@ func go_frankenphp_worker_handle_request_start(mrh C.uintptr_t) C.uintptr_t {
 	}
 
 	rc := v.(chan *http.Request)
-
 	l := getLogger()
 
-	l.Debug("waiting for request", zap.String("worker", fc.scriptFilename))
+	if c := l.Check(zapcore.DebugLevel, "waiting for request"); c != nil {
+		c.Write(zap.String("worker", fc.scriptFilename))
+	}
 
 	var r *http.Request
 	select {
 	case <-done:
-		l.Debug("shutting down", zap.String("worker", fc.scriptFilename))
+		if c := l.Check(zapcore.DebugLevel, "shutting down"); c != nil {
+			c.Write(zap.String("worker", fc.scriptFilename))
+		}
 
 		return 0
 	case r = <-rc:
@@ -158,10 +171,15 @@ func go_frankenphp_worker_handle_request_start(mrh C.uintptr_t) C.uintptr_t {
 	fc.currentWorkerRequest = cgo.NewHandle(r)
 	r.Context().Value(handleKey).(*handleList).AddHandle(fc.currentWorkerRequest)
 
-	l.Debug("request handling started", zap.String("worker", fc.scriptFilename), zap.String("url", r.RequestURI))
+	if c := l.Check(zapcore.DebugLevel, "request handling started"); c != nil {
+		c.Write(zap.String("worker", fc.scriptFilename), zap.String("url", r.RequestURI))
+	}
+
 	if err := updateServerContext(r, false, mrh); err != nil {
 		// Unexpected error
-		l.Debug("unexpected error", zap.String("worker", fc.scriptFilename), zap.String("url", r.RequestURI), zap.Error(err))
+		if c := l.Check(zapcore.DebugLevel, "unexpected error"); c != nil {
+			c.Write(zap.String("worker", fc.scriptFilename), zap.String("url", r.RequestURI), zap.Error(err))
+		}
 
 		return 0
 	}
@@ -182,12 +200,14 @@ func go_frankenphp_finish_request(mrh, rh C.uintptr_t, deleteHandle bool) {
 
 	maybeCloseContext(fc)
 
-	var fields []zap.Field
-	if mrh == 0 {
-		fields = append(fields, zap.String("worker", fc.scriptFilename), zap.String("url", r.RequestURI))
-	} else {
-		fields = append(fields, zap.String("url", r.RequestURI))
-	}
+	if c := fc.logger.Check(zapcore.DebugLevel, "request handling finished"); c != nil {
+		var fields []zap.Field
+		if mrh == 0 {
+			fields = append(fields, zap.String("worker", fc.scriptFilename), zap.String("url", r.RequestURI))
+		} else {
+			fields = append(fields, zap.String("url", r.RequestURI))
+		}
 
-	fc.logger.Debug("request handling finished", fields...)
+		c.Write(fields...)
+	}
 }

worker_test.go

@@ -14,6 +14,7 @@ import (
 	"github.com/dunglas/frankenphp"
 	"github.com/stretchr/testify/assert"
 	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 	"go.uber.org/zap/zaptest/observer"
 )
 
@@ -92,7 +93,7 @@ func TestWorkerEnv(t *testing.T) {
 }
 
 func TestWorkerGetOpt(t *testing.T) {
-	observer, logs := observer.New(zap.InfoLevel)
+	observer, logs := observer.New(zapcore.InfoLevel)
 	logger := zap.New(observer)
 
 	runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) {