From 53f5947d85b824687fb1a18503299596c6dbb374 Mon Sep 17 00:00:00 2001 From: Raphael Coeffic Date: Sun, 16 Nov 2025 11:27:33 +0100 Subject: [PATCH 01/14] feat: add frankenphp_log_attrs() as a PHP function The CGO method allow to log a php message while binding an array of random type as slog.Attr. --- frankenphp.c | 22 ++++++++++++ frankenphp.go | 75 ++++++++++++++++++++++++++++++++++++++++ frankenphp.stub.php | 6 ++++ frankenphp_arginfo.h | 18 ++++++---- frankenphp_test.go | 29 +++++++++++++++- testdata/log_to_slog.php | 23 ++++++++++++ 6 files changed, 166 insertions(+), 7 deletions(-) create mode 100644 testdata/log_to_slog.php diff --git a/frankenphp.c b/frankenphp.c index 04782a9b6..04be93eec 100644 --- a/frankenphp.c +++ b/frankenphp.c @@ -549,6 +549,28 @@ PHP_FUNCTION(mercure_publish) { RETURN_THROWS(); } +PHP_FUNCTION(frankenphp_log) { + char *message = NULL; + size_t message_len = 0; + zend_long level = 0; + zval *context = NULL; + + ZEND_PARSE_PARAMETERS_START(2, 3) + Z_PARAM_STRING(message, message_len) + Z_PARAM_LONG(level) + Z_PARAM_OPTIONAL + Z_PARAM_ARRAY(context) + ZEND_PARSE_PARAMETERS_END(); + + char * ret = NULL; + ret = go_log_attrs(thread_index, message, message_len, (int)level, context); + if (ret != NULL) { + zend_throw_exception(spl_ce_RuntimeException, ret, 0); + // free(ret); // NOTE: is the string copied by zend_throw ?? + RETURN_THROWS(); + } +} + PHP_MINIT_FUNCTION(frankenphp) { zend_function *func; diff --git a/frankenphp.go b/frankenphp.go index da0bdead3..f7d10e1fa 100644 --- a/frankenphp.go +++ b/frankenphp.go @@ -693,6 +693,81 @@ func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { } } +// go_log_attrs is a cgo-exported bridge between PHP and the Go slog logger. +// +// It is called from C/PHP and must not panic. All errors are reported by +// returning a C-allocated error string; on success it returns NULL. +// +// Parameters: +// +// threadIndex: +// - Index into the phpThreads table, used to retrieve the Go context for +// the current PHP request/thread. +// +// message: +// - Pointer to a C string containing the log message bytes. The memory +// is owned by the caller and must NOT be freed by Go. +// +// len: +// - Length of the message, in bytes, as seen from C (not including the +// terminating NUL). This is passed to C.GoStringN to build the Go string. +// +// level: +// - Numeric log level compatible with slog.Level values. It is cast to +// slog.Level inside this function. +// +// cattrs: +// - Pointer to a PHP zval representing an associative array of attributes, +// or NULL. When non-NULL, it is converted to map[string]any via GoMap[any] +// and then mapped to slog.Attr values (using slog.Any under the hood). +// +// Return value: +// +// On success: +// - Returns NULL and the message is logged (if the logger is enabled at +// the given level). +// +// On error: +// - Returns a non-NULL *C.char pointing to a NUL-terminated error message +// allocated with C.CString. The caller is responsible for releasing +// this memory. +// +//export go_log_attrs +func go_log_attrs(threadIndex C.uintptr_t, message *C.char, len C.int, level C.int, cattrs *C.zval) *C.char { + var attrs map[string]any + + if cattrs == nil { + attrs = nil + } else { + var err error + if attrs, err = GoMap[any](unsafe.Pointer(cattrs)); err != nil { + // NOTE: return value is already formatted for a PHP exception message. + return C.CString("Failed to log message: converting attrs: " + err.Error()) + } + } + + m := C.GoStringN(message, len) + lvl := slog.Level(level) + + ctx := phpThreads[threadIndex].context() + + if globalLogger.Enabled(ctx, lvl) { + globalLogger.LogAttrs(ctx, lvl, m, mapToAttr(attrs)...) + } + + return nil +} + +func mapToAttr(input map[string]any) []slog.Attr { + out := make([]slog.Attr, 0, len(input)) + + for key, val := range input { + out = append(out, slog.Any(key, val)) + } + + return out +} + //export go_is_context_done func go_is_context_done(threadIndex C.uintptr_t) C.bool { return C.bool(phpThreads[threadIndex].frankenPHPContext().isDone) diff --git a/frankenphp.stub.php b/frankenphp.stub.php index 60ac5d588..9b19160f7 100644 --- a/frankenphp.stub.php +++ b/frankenphp.stub.php @@ -36,3 +36,9 @@ function apache_response_headers(): array|bool {} * @param string|string[] $topics */ function mercure_publish(string|array $topics, string $data = '', bool $private = false, ?string $id = null, ?string $type = null, ?int $retry = null): string {} + +/** + * @param int $level The importance or severity of a log event. The higher the level, the more important or severe the event. Common levels are -4 for debug, 0 for info, 4 for warn, and 8 for error. For more details, see: https://pkg.go.dev/log/slog#Level + * array $context Values of the array will be converted to the corresponding Go type (if supported by FrankenPHP) and added to the context of the structured logs using https://pkg.go.dev/log/slog#Attr + */ +function frankenphp_log(string $message, int $level = 0, array $context = []): void {} diff --git a/frankenphp_arginfo.h b/frankenphp_arginfo.h index 558c6e3cf..24b4f5152 100644 --- a/frankenphp_arginfo.h +++ b/frankenphp_arginfo.h @@ -1,5 +1,5 @@ /* This is a generated file, edit the .stub.php file instead. - * Stub hash: cd534a8394f535a600bf45a333955d23b5154756 */ + * Stub hash: 28aa97e2c6102b3e51059dbd001ac65679f0bfda */ ZEND_BEGIN_ARG_WITH_RETURN_TYPE_INFO_EX(arginfo_frankenphp_handle_request, 0, 1, _IS_BOOL, 0) ZEND_ARG_TYPE_INFO(0, callback, IS_CALLABLE, 0) @@ -35,6 +35,11 @@ ZEND_BEGIN_ARG_WITH_RETURN_TYPE_INFO_EX(arginfo_mercure_publish, 0, 1, IS_STRING ZEND_ARG_TYPE_INFO_WITH_DEFAULT_VALUE(0, retry, IS_LONG, 1, "null") ZEND_END_ARG_INFO() +ZEND_BEGIN_ARG_WITH_RETURN_TYPE_INFO_EX(arginfo_frankenphp_log, 0, 1, IS_VOID, 0) + ZEND_ARG_TYPE_INFO(0, message, IS_STRING, 0) + ZEND_ARG_TYPE_INFO_WITH_DEFAULT_VALUE(0, level, IS_LONG, 0, "0") + ZEND_ARG_TYPE_INFO_WITH_DEFAULT_VALUE(0, context, IS_ARRAY, 0, "[]") +ZEND_END_ARG_INFO() ZEND_FUNCTION(frankenphp_handle_request); ZEND_FUNCTION(headers_send); @@ -42,18 +47,19 @@ ZEND_FUNCTION(frankenphp_finish_request); ZEND_FUNCTION(frankenphp_request_headers); ZEND_FUNCTION(frankenphp_response_headers); ZEND_FUNCTION(mercure_publish); - +ZEND_FUNCTION(frankenphp_log); static const zend_function_entry ext_functions[] = { ZEND_FE(frankenphp_handle_request, arginfo_frankenphp_handle_request) ZEND_FE(headers_send, arginfo_headers_send) ZEND_FE(frankenphp_finish_request, arginfo_frankenphp_finish_request) - ZEND_FALIAS(fastcgi_finish_request, frankenphp_finish_request, arginfo_fastcgi_finish_request) + ZEND_RAW_FENTRY("fastcgi_finish_request", zif_frankenphp_finish_request, arginfo_fastcgi_finish_request, 0, NULL, NULL) ZEND_FE(frankenphp_request_headers, arginfo_frankenphp_request_headers) - ZEND_FALIAS(apache_request_headers, frankenphp_request_headers, arginfo_apache_request_headers) - ZEND_FALIAS(getallheaders, frankenphp_request_headers, arginfo_getallheaders) + ZEND_RAW_FENTRY("apache_request_headers", zif_frankenphp_request_headers, arginfo_apache_request_headers, 0, NULL, NULL) + ZEND_RAW_FENTRY("getallheaders", zif_frankenphp_request_headers, arginfo_getallheaders, 0, NULL, NULL) ZEND_FE(frankenphp_response_headers, arginfo_frankenphp_response_headers) - ZEND_FALIAS(apache_response_headers, frankenphp_response_headers, arginfo_apache_response_headers) + ZEND_RAW_FENTRY("apache_response_headers", zif_frankenphp_response_headers, arginfo_apache_response_headers, 0, NULL, NULL) ZEND_FE(mercure_publish, arginfo_mercure_publish) + ZEND_FE(frankenphp_log, arginfo_frankenphp_log) ZEND_FE_END }; diff --git a/frankenphp_test.go b/frankenphp_test.go index f8f175a92..e3879138c 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -1058,7 +1058,34 @@ func FuzzRequest(f *testing.F) { // Headers should always be present even if empty assert.Contains(t, body, fmt.Sprintf("[CONTENT_TYPE] => %s", fuzzedString)) assert.Contains(t, body, fmt.Sprintf("[HTTP_FUZZED] => %s", fuzzedString)) - }, &testOptions{workerScript: "request-headers.php"}) }) } + +func TestFrankenPHPLog(t *testing.T) { + var buf bytes.Buffer + handler := slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug}) + logger := slog.New(handler) + + runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, _ int) { + body, _ := testGet("http://example.com/log_to_slog.php", handler, t) + assert.Empty(t, body) + }, &testOptions{ + logger: logger, + nbParallelRequests: 1, + nbWorkers: 1, + }) + + logOutput := buf.String() + + t.Logf("captured log output: %s", logOutput) + + for level, needle := range map[string]string{ + "debug attrs": `level=DEBUG msg="some debug message" "key int"=1`, + "info attrs": `level=INFO msg="some info message" "key string"=string`, + "warn attrs": `level=WARN msg="some warn message"`, + "error attrs": `level=ERROR msg="some error message" err="[a v]"`, + } { + assert.Containsf(t, logOutput, needle, "should contains %q log", level) + } +} diff --git a/testdata/log_to_slog.php b/testdata/log_to_slog.php new file mode 100644 index 000000000..b8e831229 --- /dev/null +++ b/testdata/log_to_slog.php @@ -0,0 +1,23 @@ + 1, +]); + +frankenphp_log("some info message", 0, [ + "key string" => "string", +]); + +frankenphp_log("some warn message", 4); + +frankenphp_log("some error message", 8, [ + "err" => ["a", "v"], +]); From d9d3ff309752391346879498db185b6fe6a1efab Mon Sep 17 00:00:00 2001 From: Raphael Coeffic Date: Wed, 19 Nov 2025 22:48:14 +0100 Subject: [PATCH 02/14] fix: do not touch alias entries --- frankenphp_arginfo.h | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/frankenphp_arginfo.h b/frankenphp_arginfo.h index 24b4f5152..6417cfb70 100644 --- a/frankenphp_arginfo.h +++ b/frankenphp_arginfo.h @@ -53,12 +53,12 @@ static const zend_function_entry ext_functions[] = { ZEND_FE(frankenphp_handle_request, arginfo_frankenphp_handle_request) ZEND_FE(headers_send, arginfo_headers_send) ZEND_FE(frankenphp_finish_request, arginfo_frankenphp_finish_request) - ZEND_RAW_FENTRY("fastcgi_finish_request", zif_frankenphp_finish_request, arginfo_fastcgi_finish_request, 0, NULL, NULL) + ZEND_FALIAS(fastcgi_finish_request, frankenphp_finish_request, arginfo_fastcgi_finish_request) ZEND_FE(frankenphp_request_headers, arginfo_frankenphp_request_headers) - ZEND_RAW_FENTRY("apache_request_headers", zif_frankenphp_request_headers, arginfo_apache_request_headers, 0, NULL, NULL) - ZEND_RAW_FENTRY("getallheaders", zif_frankenphp_request_headers, arginfo_getallheaders, 0, NULL, NULL) + ZEND_FALIAS(apache_request_headers, frankenphp_request_headers, arginfo_apache_request_headers) + ZEND_FALIAS(getallheaders, frankenphp_request_headers, arginfo_getallheaders) ZEND_FE(frankenphp_response_headers, arginfo_frankenphp_response_headers) - ZEND_RAW_FENTRY("apache_response_headers", zif_frankenphp_response_headers, arginfo_apache_response_headers, 0, NULL, NULL) + ZEND_FALIAS(apache_response_headers, frankenphp_response_headers, arginfo_apache_response_headers) ZEND_FE(mercure_publish, arginfo_mercure_publish) ZEND_FE(frankenphp_log, arginfo_frankenphp_log) ZEND_FE_END From ba1191717549740f7992d09e99e57c79c28add8f Mon Sep 17 00:00:00 2001 From: Quentin Burgess Date: Sun, 23 Nov 2025 10:59:04 +0100 Subject: [PATCH 03/14] misc(logging): clean up --- frankenphp.c | 2 +- frankenphp.go | 39 --------------------------------------- 2 files changed, 1 insertion(+), 40 deletions(-) diff --git a/frankenphp.c b/frankenphp.c index 04be93eec..a6fa2bebe 100644 --- a/frankenphp.c +++ b/frankenphp.c @@ -566,7 +566,7 @@ PHP_FUNCTION(frankenphp_log) { ret = go_log_attrs(thread_index, message, message_len, (int)level, context); if (ret != NULL) { zend_throw_exception(spl_ce_RuntimeException, ret, 0); - // free(ret); // NOTE: is the string copied by zend_throw ?? + free(ret); RETURN_THROWS(); } } diff --git a/frankenphp.go b/frankenphp.go index f7d10e1fa..5cfa3df34 100644 --- a/frankenphp.go +++ b/frankenphp.go @@ -693,45 +693,6 @@ func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { } } -// go_log_attrs is a cgo-exported bridge between PHP and the Go slog logger. -// -// It is called from C/PHP and must not panic. All errors are reported by -// returning a C-allocated error string; on success it returns NULL. -// -// Parameters: -// -// threadIndex: -// - Index into the phpThreads table, used to retrieve the Go context for -// the current PHP request/thread. -// -// message: -// - Pointer to a C string containing the log message bytes. The memory -// is owned by the caller and must NOT be freed by Go. -// -// len: -// - Length of the message, in bytes, as seen from C (not including the -// terminating NUL). This is passed to C.GoStringN to build the Go string. -// -// level: -// - Numeric log level compatible with slog.Level values. It is cast to -// slog.Level inside this function. -// -// cattrs: -// - Pointer to a PHP zval representing an associative array of attributes, -// or NULL. When non-NULL, it is converted to map[string]any via GoMap[any] -// and then mapped to slog.Attr values (using slog.Any under the hood). -// -// Return value: -// -// On success: -// - Returns NULL and the message is logged (if the logger is enabled at -// the given level). -// -// On error: -// - Returns a non-NULL *C.char pointing to a NUL-terminated error message -// allocated with C.CString. The caller is responsible for releasing -// this memory. -// //export go_log_attrs func go_log_attrs(threadIndex C.uintptr_t, message *C.char, len C.int, level C.int, cattrs *C.zval) *C.char { var attrs map[string]any From 32c0e037318da27183a88110efb146bd114935ac Mon Sep 17 00:00:00 2001 From: Quentin Burgess Date: Sun, 23 Nov 2025 11:05:23 +0100 Subject: [PATCH 04/14] misc(c): apply clang-format --- frankenphp.c | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/frankenphp.c b/frankenphp.c index a6fa2bebe..c5ad24651 100644 --- a/frankenphp.c +++ b/frankenphp.c @@ -556,13 +556,13 @@ PHP_FUNCTION(frankenphp_log) { zval *context = NULL; ZEND_PARSE_PARAMETERS_START(2, 3) - Z_PARAM_STRING(message, message_len) - Z_PARAM_LONG(level) - Z_PARAM_OPTIONAL - Z_PARAM_ARRAY(context) + Z_PARAM_STRING(message, message_len) + Z_PARAM_LONG(level) + Z_PARAM_OPTIONAL + Z_PARAM_ARRAY(context) ZEND_PARSE_PARAMETERS_END(); - char * ret = NULL; + char *ret = NULL; ret = go_log_attrs(thread_index, message, message_len, (int)level, context); if (ret != NULL) { zend_throw_exception(spl_ce_RuntimeException, ret, 0); From 775144e3bacd636a70c1c37a35f59ba56d51c995 Mon Sep 17 00:00:00 2001 From: Quentin Burgess Date: Mon, 24 Nov 2025 09:30:31 +0100 Subject: [PATCH 05/14] refactor(frankenlog): rework func params type Currently, franken.gp:705 won't compile --- frankenphp.c | 7 +++---- frankenphp.go | 12 ++++++------ 2 files changed, 9 insertions(+), 10 deletions(-) diff --git a/frankenphp.c b/frankenphp.c index c5ad24651..1a750dff4 100644 --- a/frankenphp.c +++ b/frankenphp.c @@ -550,20 +550,19 @@ PHP_FUNCTION(mercure_publish) { } PHP_FUNCTION(frankenphp_log) { - char *message = NULL; - size_t message_len = 0; + zend_string *message = NULL; zend_long level = 0; zval *context = NULL; ZEND_PARSE_PARAMETERS_START(2, 3) - Z_PARAM_STRING(message, message_len) + Z_PARAM_STR(message) Z_PARAM_LONG(level) Z_PARAM_OPTIONAL Z_PARAM_ARRAY(context) ZEND_PARSE_PARAMETERS_END(); char *ret = NULL; - ret = go_log_attrs(thread_index, message, message_len, (int)level, context); + ret = go_log_attrs(thread_index, message, level, context); if (ret != NULL) { zend_throw_exception(spl_ce_RuntimeException, ret, 0); free(ret); diff --git a/frankenphp.go b/frankenphp.go index 5cfa3df34..0fbce66d6 100644 --- a/frankenphp.go +++ b/frankenphp.go @@ -694,7 +694,7 @@ func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { } //export go_log_attrs -func go_log_attrs(threadIndex C.uintptr_t, message *C.char, len C.int, level C.int, cattrs *C.zval) *C.char { +func go_log_attrs(threadIndex C.uintptr_t, message *C.zend_string, level C.zend_long, cattrs *C.zval) *C.char { var attrs map[string]any if cattrs == nil { @@ -707,13 +707,13 @@ func go_log_attrs(threadIndex C.uintptr_t, message *C.char, len C.int, level C.i } } - m := C.GoStringN(message, len) - lvl := slog.Level(level) - ctx := phpThreads[threadIndex].context() - if globalLogger.Enabled(ctx, lvl) { - globalLogger.LogAttrs(ctx, lvl, m, mapToAttr(attrs)...) + if globalLogger.Enabled(ctx, slog.Level(level)) { + globalLogger.LogAttrs(ctx, + slog.Level(level), + GoString(unsafe.Pointer(message)), + mapToAttr(attrs)...) } return nil From fa0c0569fb46eeac6d52339d5cd6f2a548779ce4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Fri, 12 Dec 2025 14:47:35 +0100 Subject: [PATCH 06/14] simplify --- frankenphp.go | 27 ++++++++++++------------- frankenphp_test.go | 10 +++------ testdata/{log.php => log-error_log.php} | 0 testdata/log-frankenphp_log.php | 15 ++++++++++++++ testdata/log_to_slog.php | 23 --------------------- 5 files changed, 31 insertions(+), 44 deletions(-) rename testdata/{log.php => log-error_log.php} (100%) create mode 100644 testdata/log-frankenphp_log.php delete mode 100644 testdata/log_to_slog.php diff --git a/frankenphp.go b/frankenphp.go index 0fbce66d6..828f157ae 100644 --- a/frankenphp.go +++ b/frankenphp.go @@ -694,27 +694,26 @@ func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { } //export go_log_attrs -func go_log_attrs(threadIndex C.uintptr_t, message *C.zend_string, level C.zend_long, cattrs *C.zval) *C.char { +func go_log_attrs(threadIndex C.uintptr_t, message *C.zend_string, cLevel C.zend_long, cAttrs *C.zval) *C.char { + ctx := phpThreads[threadIndex].context() + + level := slog.Level(cLevel) + + if !globalLogger.Enabled(ctx, level) { + return nil + } + var attrs map[string]any - if cattrs == nil { - attrs = nil - } else { + if cAttrs != nil { var err error - if attrs, err = GoMap[any](unsafe.Pointer(cattrs)); err != nil { - // NOTE: return value is already formatted for a PHP exception message. + if attrs, err = GoMap[any](unsafe.Pointer(cAttrs)); err != nil { + // PHP exception message. return C.CString("Failed to log message: converting attrs: " + err.Error()) } } - ctx := phpThreads[threadIndex].context() - - if globalLogger.Enabled(ctx, slog.Level(level)) { - globalLogger.LogAttrs(ctx, - slog.Level(level), - GoString(unsafe.Pointer(message)), - mapToAttr(attrs)...) - } + globalLogger.LogAttrs(ctx, level, GoString(unsafe.Pointer(message)), mapToAttr(attrs)...) return nil } diff --git a/frankenphp_test.go b/frankenphp_test.go index e3879138c..3b056f5dd 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -425,7 +425,7 @@ my_autoloader`, i), body) func TestLog_module(t *testing.T) { testLog(t, &testOptions{}) } func TestLog_worker(t *testing.T) { - testLog(t, &testOptions{workerScript: "log.php"}) + testLog(t, &testOptions{workerScript: "log-error_log.php"}) } func testLog(t *testing.T, opts *testOptions) { logger, logs := observer.New(zapcore.InfoLevel) @@ -1064,22 +1064,18 @@ func FuzzRequest(f *testing.F) { func TestFrankenPHPLog(t *testing.T) { var buf bytes.Buffer - handler := slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug}) - logger := slog.New(handler) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, _ int) { - body, _ := testGet("http://example.com/log_to_slog.php", handler, t) + body, _ := testGet("http://example.com/log-frankenphp_log.php", handler, t) assert.Empty(t, body) }, &testOptions{ - logger: logger, + logger: slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})), nbParallelRequests: 1, nbWorkers: 1, }) logOutput := buf.String() - t.Logf("captured log output: %s", logOutput) - for level, needle := range map[string]string{ "debug attrs": `level=DEBUG msg="some debug message" "key int"=1`, "info attrs": `level=INFO msg="some info message" "key string"=string`, diff --git a/testdata/log.php b/testdata/log-error_log.php similarity index 100% rename from testdata/log.php rename to testdata/log-error_log.php diff --git a/testdata/log-frankenphp_log.php b/testdata/log-frankenphp_log.php new file mode 100644 index 000000000..eead8ff03 --- /dev/null +++ b/testdata/log-frankenphp_log.php @@ -0,0 +1,15 @@ + 1, +]); + +frankenphp_log("some info message", 0, [ + "key string" => "string", +]); + +frankenphp_log("some warn message", 4); + +frankenphp_log("some error message", 8, [ + "err" => ["a", "v"], +]); diff --git a/testdata/log_to_slog.php b/testdata/log_to_slog.php deleted file mode 100644 index b8e831229..000000000 --- a/testdata/log_to_slog.php +++ /dev/null @@ -1,23 +0,0 @@ - 1, -]); - -frankenphp_log("some info message", 0, [ - "key string" => "string", -]); - -frankenphp_log("some warn message", 4); - -frankenphp_log("some error message", 8, [ - "err" => ["a", "v"], -]); From 70ee0f2e77991dbe66703a4e0226913a1325a645 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Sat, 13 Dec 2025 18:26:32 +0100 Subject: [PATCH 07/14] add constants --- frankenphp.c | 2 ++ frankenphp.stub.php | 14 +++++++++++++- frankenphp_arginfo.h | 12 +++++++++++- 3 files changed, 26 insertions(+), 2 deletions(-) diff --git a/frankenphp.c b/frankenphp.c index 1a750dff4..a6772a86e 100644 --- a/frankenphp.c +++ b/frankenphp.c @@ -571,6 +571,8 @@ PHP_FUNCTION(frankenphp_log) { } PHP_MINIT_FUNCTION(frankenphp) { + register_frankenphp_symbols(module_number); + zend_function *func; // Override putenv diff --git a/frankenphp.stub.php b/frankenphp.stub.php index 9b19160f7..d6c85aa05 100644 --- a/frankenphp.stub.php +++ b/frankenphp.stub.php @@ -2,6 +2,18 @@ /** @generate-class-entries */ +/** @var int */ +const FRANKENPHP_LOG_LEVEL_DEBUG = -4; + +/** @var int */ +const FRANKENPHP_LOG_LEVEL_INFO = 0; + +/** @var int */ +const FRANKENPHP_LOG_LEVEL_WARN = 4; + +/** @var int */ +const FRANKENPHP_LOG_LEVEL_ERROR = 8; + function frankenphp_handle_request(callable $callback): bool {} function headers_send(int $status = 200): int {} @@ -38,7 +50,7 @@ function apache_response_headers(): array|bool {} function mercure_publish(string|array $topics, string $data = '', bool $private = false, ?string $id = null, ?string $type = null, ?int $retry = null): string {} /** - * @param int $level The importance or severity of a log event. The higher the level, the more important or severe the event. Common levels are -4 for debug, 0 for info, 4 for warn, and 8 for error. For more details, see: https://pkg.go.dev/log/slog#Level + * @param int $level The importance or severity of a log event. The higher the level, the more important or severe the event. For more details, see: https://pkg.go.dev/log/slog#Level * array $context Values of the array will be converted to the corresponding Go type (if supported by FrankenPHP) and added to the context of the structured logs using https://pkg.go.dev/log/slog#Attr */ function frankenphp_log(string $message, int $level = 0, array $context = []): void {} diff --git a/frankenphp_arginfo.h b/frankenphp_arginfo.h index 6417cfb70..4f2707cbc 100644 --- a/frankenphp_arginfo.h +++ b/frankenphp_arginfo.h @@ -1,5 +1,5 @@ /* This is a generated file, edit the .stub.php file instead. - * Stub hash: 28aa97e2c6102b3e51059dbd001ac65679f0bfda */ + * Stub hash: 60f0d27c04f94d7b24c052e91ef294595a2bc421 */ ZEND_BEGIN_ARG_WITH_RETURN_TYPE_INFO_EX(arginfo_frankenphp_handle_request, 0, 1, _IS_BOOL, 0) ZEND_ARG_TYPE_INFO(0, callback, IS_CALLABLE, 0) @@ -41,6 +41,7 @@ ZEND_BEGIN_ARG_WITH_RETURN_TYPE_INFO_EX(arginfo_frankenphp_log, 0, 1, IS_VOID, 0 ZEND_ARG_TYPE_INFO_WITH_DEFAULT_VALUE(0, context, IS_ARRAY, 0, "[]") ZEND_END_ARG_INFO() + ZEND_FUNCTION(frankenphp_handle_request); ZEND_FUNCTION(headers_send); ZEND_FUNCTION(frankenphp_finish_request); @@ -49,6 +50,7 @@ ZEND_FUNCTION(frankenphp_response_headers); ZEND_FUNCTION(mercure_publish); ZEND_FUNCTION(frankenphp_log); + static const zend_function_entry ext_functions[] = { ZEND_FE(frankenphp_handle_request, arginfo_frankenphp_handle_request) ZEND_FE(headers_send, arginfo_headers_send) @@ -63,3 +65,11 @@ static const zend_function_entry ext_functions[] = { ZEND_FE(frankenphp_log, arginfo_frankenphp_log) ZEND_FE_END }; + +static void register_frankenphp_symbols(int module_number) +{ + REGISTER_LONG_CONSTANT("FRANKENPHP_LOG_LEVEL_DEBUG", -4, CONST_PERSISTENT); + REGISTER_LONG_CONSTANT("FRANKENPHP_LOG_LEVEL_INFO", 0, CONST_PERSISTENT); + REGISTER_LONG_CONSTANT("FRANKENPHP_LOG_LEVEL_WARN", 4, CONST_PERSISTENT); + REGISTER_LONG_CONSTANT("FRANKENPHP_LOG_LEVEL_ERROR", 8, CONST_PERSISTENT); +} From 51be4f1afe461c2ca5506ee4fdef00f7b66cf5f5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Sat, 13 Dec 2025 19:05:29 +0100 Subject: [PATCH 08/14] improve tests --- frankenphp_test.go | 65 +++++++++++++++++---------------- testdata/log-frankenphp_log.php | 24 +++++++----- 2 files changed, 47 insertions(+), 42 deletions(-) diff --git a/frankenphp_test.go b/frankenphp_test.go index 3b056f5dd..042efef12 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -423,20 +423,45 @@ my_autoloader`, i), body) }, opts) } -func TestLog_module(t *testing.T) { testLog(t, &testOptions{}) } -func TestLog_worker(t *testing.T) { - testLog(t, &testOptions{workerScript: "log-error_log.php"}) +func TestLog_error_log_module(t *testing.T) { testLog_error_log(t, &testOptions{}) } +func TestLog_error_log_worker(t *testing.T) { + testLog_error_log(t, &testOptions{workerScript: "log-error_log.php"}) } -func testLog(t *testing.T, opts *testOptions) { - logger, logs := observer.New(zapcore.InfoLevel) - opts.logger = slog.New(zapslog.NewHandler(logger)) +func testLog_error_log(t *testing.T, opts *testOptions) { + var buf bytes.Buffer + opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) + + runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { + req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log-error_log.php?i=%d", i), nil) + w := httptest.NewRecorder() + handler(w, req) + + assert.Contains(t, buf.String(), fmt.Sprintf("request %d", i)) + }, opts) +} + +func TestLog_frankenphp_log_module(t *testing.T) { testLog_frankenphp_log(t, &testOptions{}) } +func TestLog_frankenphp_log_worker(t *testing.T) { + testLog_frankenphp_log(t, &testOptions{workerScript: "log-frankenphp_log.php"}) +} +func testLog_frankenphp_log(t *testing.T, opts *testOptions) { + var buf bytes.Buffer + + opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { - req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log.php?i=%d", i), nil) + req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log-frankenphp_log.php?i=%d", i), nil) w := httptest.NewRecorder() handler(w, req) - for logs.FilterMessage(fmt.Sprintf("request %d", i)).Len() <= 0 { + logs := buf.String() + for _, message := range []string{ + fmt.Sprintf(`level=DEBUG msg="some debug message %d" "key int"=1`, i), + fmt.Sprintf(`level=INFO msg="some info message %d" "key string"=string`, i), + fmt.Sprintf(`level=WARN msg="some warn message %d"`, i), + fmt.Sprintf(`level=ERROR msg="some error message %d" err="[a v]"`, i), + } { + assert.Contains(t, logs, message) } }, opts) } @@ -1061,27 +1086,3 @@ func FuzzRequest(f *testing.F) { }, &testOptions{workerScript: "request-headers.php"}) }) } - -func TestFrankenPHPLog(t *testing.T) { - var buf bytes.Buffer - - runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, _ int) { - body, _ := testGet("http://example.com/log-frankenphp_log.php", handler, t) - assert.Empty(t, body) - }, &testOptions{ - logger: slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})), - nbParallelRequests: 1, - nbWorkers: 1, - }) - - logOutput := buf.String() - - for level, needle := range map[string]string{ - "debug attrs": `level=DEBUG msg="some debug message" "key int"=1`, - "info attrs": `level=INFO msg="some info message" "key string"=string`, - "warn attrs": `level=WARN msg="some warn message"`, - "error attrs": `level=ERROR msg="some error message" err="[a v]"`, - } { - assert.Containsf(t, logOutput, needle, "should contains %q log", level) - } -} diff --git a/testdata/log-frankenphp_log.php b/testdata/log-frankenphp_log.php index eead8ff03..ab587f6e6 100644 --- a/testdata/log-frankenphp_log.php +++ b/testdata/log-frankenphp_log.php @@ -1,15 +1,19 @@ 1, -]); +require_once __DIR__.'/_executor.php'; -frankenphp_log("some info message", 0, [ - "key string" => "string", -]); +return function () { + frankenphp_log("some debug message {$_GET['i']}", FRANKENPHP_LOG_LEVEL_DEBUG, [ + "key int" => 1, + ]); -frankenphp_log("some warn message", 4); + frankenphp_log("some info message {$_GET['i']}", FRANKENPHP_LOG_LEVEL_INFO, [ + "key string" => "string", + ]); -frankenphp_log("some error message", 8, [ - "err" => ["a", "v"], -]); + frankenphp_log("some warn message {$_GET['i']}", FRANKENPHP_LOG_LEVEL_WARN); + + frankenphp_log("some error message {$_GET['i']}", FRANKENPHP_LOG_LEVEL_ERROR, [ + "err" => ["a", "v"], + ]); +}; From 5579fb3a9b3aa51af06ff3bd521f50ee55b040cf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Sat, 13 Dec 2025 19:42:28 +0100 Subject: [PATCH 09/14] fix tests and use the appropriate logger --- frankenphp.go | 25 ++++++++++++++----------- 1 file changed, 14 insertions(+), 11 deletions(-) diff --git a/frankenphp.go b/frankenphp.go index 828f157ae..744439138 100644 --- a/frankenphp.go +++ b/frankenphp.go @@ -663,6 +663,7 @@ func go_read_cookies(threadIndex C.uintptr_t) *C.char { //export go_log func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { ctx := phpThreads[threadIndex].context() + logger := phpThreads[threadIndex].frankenPHPContext().logger m := C.GoString(message) le := syslogLevelInfo @@ -673,22 +674,23 @@ func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { switch le { case syslogLevelEmerg, syslogLevelAlert, syslogLevelCrit, syslogLevelErr: - if globalLogger.Enabled(ctx, slog.LevelError) { - globalLogger.LogAttrs(ctx, slog.LevelError, m, slog.String("syslog_level", syslogLevel(level).String())) + if logger.Enabled(ctx, slog.LevelError) { + logger.LogAttrs(ctx, slog.LevelError, m, slog.String("syslog_level", le.String())) } case syslogLevelWarn: - if globalLogger.Enabled(ctx, slog.LevelWarn) { - globalLogger.LogAttrs(ctx, slog.LevelWarn, m, slog.String("syslog_level", syslogLevel(level).String())) + if logger.Enabled(ctx, slog.LevelWarn) { + logger.LogAttrs(ctx, slog.LevelWarn, m, slog.String("syslog_level", le.String())) } + case syslogLevelDebug: - if globalLogger.Enabled(ctx, slog.LevelDebug) { - globalLogger.LogAttrs(ctx, slog.LevelDebug, m, slog.String("syslog_level", syslogLevel(level).String())) + if logger.Enabled(ctx, slog.LevelDebug) { + logger.LogAttrs(ctx, slog.LevelDebug, m, slog.String("syslog_level", le.String())) } default: - if globalLogger.Enabled(ctx, slog.LevelInfo) { - globalLogger.LogAttrs(ctx, slog.LevelInfo, m, slog.String("syslog_level", syslogLevel(level).String())) + if logger.Enabled(ctx, slog.LevelInfo) { + logger.LogAttrs(ctx, slog.LevelInfo, m, slog.String("syslog_level", le.String())) } } } @@ -696,10 +698,11 @@ func go_log(threadIndex C.uintptr_t, message *C.char, level C.int) { //export go_log_attrs func go_log_attrs(threadIndex C.uintptr_t, message *C.zend_string, cLevel C.zend_long, cAttrs *C.zval) *C.char { ctx := phpThreads[threadIndex].context() + logger := phpThreads[threadIndex].frankenPHPContext().logger level := slog.Level(cLevel) - if !globalLogger.Enabled(ctx, level) { + if !logger.Enabled(ctx, level) { return nil } @@ -707,13 +710,13 @@ func go_log_attrs(threadIndex C.uintptr_t, message *C.zend_string, cLevel C.zend if cAttrs != nil { var err error - if attrs, err = GoMap[any](unsafe.Pointer(cAttrs)); err != nil { + if attrs, err = GoMap[any](unsafe.Pointer(*(**C.zend_array)(unsafe.Pointer(&cAttrs.value[0])))); err != nil { // PHP exception message. return C.CString("Failed to log message: converting attrs: " + err.Error()) } } - globalLogger.LogAttrs(ctx, level, GoString(unsafe.Pointer(message)), mapToAttr(attrs)...) + logger.LogAttrs(ctx, level, GoString(unsafe.Pointer(message)), mapToAttr(attrs)...) return nil } From 176b4a407ad8a7a5d599dc4b4a427a6830c84051 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Mon, 15 Dec 2025 09:15:41 +0100 Subject: [PATCH 10/14] get rid of zapslog --- frankenphp_test.go | 18 +++++------------- ...tionStatusLog.php => connection_status.php} | 0 worker_test.go | 12 ++++-------- 3 files changed, 9 insertions(+), 21 deletions(-) rename testdata/{connectionStatusLog.php => connection_status.php} (100%) diff --git a/frankenphp_test.go b/frankenphp_test.go index 042efef12..16cd96940 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -32,10 +32,6 @@ import ( "github.com/dunglas/frankenphp/internal/fastabs" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" - "go.uber.org/zap/exp/zapslog" - "go.uber.org/zap/zapcore" - "go.uber.org/zap/zaptest" - "go.uber.org/zap/zaptest/observer" ) type testOptions struct { @@ -62,10 +58,6 @@ func runTest(t *testing.T, test func(func(http.ResponseWriter, *http.Request), * cwd, _ := os.Getwd() testDataDir := cwd + "/testdata/" - if opts.logger == nil { - opts.logger = slog.New(zapslog.NewHandler(zaptest.NewLogger(t).Core())) - } - initOpts := []frankenphp.Option{frankenphp.WithLogger(opts.logger)} if opts.workerScript != "" { workerOpts := []frankenphp.WorkerOption{ @@ -468,16 +460,16 @@ func testLog_frankenphp_log(t *testing.T, opts *testOptions) { func TestConnectionAbort_module(t *testing.T) { testConnectionAbort(t, &testOptions{}) } func TestConnectionAbort_worker(t *testing.T) { - testConnectionAbort(t, &testOptions{workerScript: "connectionStatusLog.php"}) + testConnectionAbort(t, &testOptions{workerScript: "connection_status.php"}) } 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(zapcore.InfoLevel) - opts.logger = slog.New(zapslog.NewHandler(logger)) + var buf bytes.Buffer + opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { - req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/connectionStatusLog.php?i=%d&finish=%s", i, finish), nil) + req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/connection_status.php?i=%d&finish=%s", i, finish), nil) w := httptest.NewRecorder() ctx, cancel := context.WithCancel(req.Context()) @@ -485,7 +477,7 @@ func testConnectionAbort(t *testing.T, opts *testOptions) { cancel() handler(w, req) - for logs.FilterMessage(fmt.Sprintf("request %d: 1", i)).Len() <= 0 { + for !strings.Contains(buf.String(), fmt.Sprintf("request %d: 1", i)) { } }, opts) }) diff --git a/testdata/connectionStatusLog.php b/testdata/connection_status.php similarity index 100% rename from testdata/connectionStatusLog.php rename to testdata/connection_status.php diff --git a/worker_test.go b/worker_test.go index c6b4245d4..077a370ae 100644 --- a/worker_test.go +++ b/worker_test.go @@ -1,6 +1,7 @@ package frankenphp_test import ( + "bytes" "fmt" "io" "log" @@ -17,9 +18,6 @@ import ( "github.com/dunglas/frankenphp" "github.com/stretchr/testify/assert" - "go.uber.org/zap/exp/zapslog" - "go.uber.org/zap/zapcore" - "go.uber.org/zap/zaptest/observer" ) func TestWorker(t *testing.T) { @@ -97,8 +95,8 @@ func TestWorkerEnv(t *testing.T) { } func TestWorkerGetOpt(t *testing.T) { - obs, logs := observer.New(zapcore.InfoLevel) - logger := slog.New(zapslog.NewHandler(obs)) + var buf bytes.Buffer + logger := slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/worker-getopt.php?i=%d", i), nil) @@ -114,9 +112,7 @@ func TestWorkerGetOpt(t *testing.T) { assert.Contains(t, string(body), fmt.Sprintf("[REQUEST_URI] => /worker-getopt.php?i=%d", i)) }, &testOptions{logger: logger, workerScript: "worker-getopt.php", env: map[string]string{"FOO": "bar"}}) - for _, l := range logs.FilterFieldKey("exit_status").All() { - assert.Failf(t, "unexpected exit status", "exit status: %d", l.ContextMap()["exit_status"]) - } + assert.NotContains(t, buf.String(), "exit_status") } func ExampleServeHTTP_workers() { From a65cee18c6467b524bada6e6b62efd5639fb1743 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Mon, 15 Dec 2025 09:47:39 +0100 Subject: [PATCH 11/14] fix tests --- frankenphp_test.go | 26 +++++++++++++++++++++++--- 1 file changed, 23 insertions(+), 3 deletions(-) diff --git a/frankenphp_test.go b/frankenphp_test.go index 16cd96940..bdc684d28 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -420,7 +420,7 @@ func TestLog_error_log_worker(t *testing.T) { testLog_error_log(t, &testOptions{workerScript: "log-error_log.php"}) } func testLog_error_log(t *testing.T, opts *testOptions) { - var buf bytes.Buffer + var buf syncBuffer opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { @@ -437,7 +437,7 @@ func TestLog_frankenphp_log_worker(t *testing.T) { testLog_frankenphp_log(t, &testOptions{workerScript: "log-frankenphp_log.php"}) } func testLog_frankenphp_log(t *testing.T, opts *testOptions) { - var buf bytes.Buffer + var buf syncBuffer opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) @@ -465,7 +465,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) { - var buf bytes.Buffer + var buf syncBuffer opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { @@ -1078,3 +1078,23 @@ func FuzzRequest(f *testing.F) { }, &testOptions{workerScript: "request-headers.php"}) }) } + +// SyncBuffer is a thread-safe buffer for capturing logs in tests. +type syncBuffer struct { + b bytes.Buffer + mu sync.RWMutex +} + +func (s *syncBuffer) Write(p []byte) (n int, err error) { + s.mu.Lock() + defer s.mu.Unlock() + + return s.b.Write(p) +} + +func (s *syncBuffer) String() string { + s.mu.RLock() + defer s.mu.RUnlock() + + return s.b.String() +} From c2ea8a0e9d218a8f91bf6122ce2d919577fb7b30 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Mon, 15 Dec 2025 11:43:00 +0100 Subject: [PATCH 12/14] tidy --- go.mod | 3 --- go.sum | 6 ------ 2 files changed, 9 deletions(-) diff --git a/go.mod b/go.mod index 4210b0f44..35c89f37d 100644 --- a/go.mod +++ b/go.mod @@ -11,8 +11,6 @@ require ( github.com/maypok86/otter/v2 v2.2.1 github.com/prometheus/client_golang v1.23.2 github.com/stretchr/testify v1.11.1 - go.uber.org/zap v1.27.1 - go.uber.org/zap/exp v0.3.0 golang.org/x/net v0.47.0 ) @@ -58,7 +56,6 @@ require ( github.com/unrolled/secure v1.17.0 // indirect github.com/yosida95/uritemplate/v3 v3.0.2 // indirect go.etcd.io/bbolt v1.4.3 // indirect - go.uber.org/multierr v1.11.0 // indirect go.yaml.in/yaml/v2 v2.4.3 // indirect go.yaml.in/yaml/v3 v3.0.4 // indirect golang.org/x/crypto v0.45.0 // indirect diff --git a/go.sum b/go.sum index 822ca3b39..bea3f847b 100644 --- a/go.sum +++ b/go.sum @@ -104,12 +104,6 @@ go.etcd.io/bbolt v1.4.3 h1:dEadXpI6G79deX5prL3QRNP6JB8UxVkqo4UPnHaNXJo= go.etcd.io/bbolt v1.4.3/go.mod h1:tKQlpPaYCVFctUIgFKFnAlvbmB3tpy1vkTnDWohtc0E= go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= -go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0= -go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= -go.uber.org/zap v1.27.1 h1:08RqriUEv8+ArZRYSTXy1LeBScaMpVSTBhCeaZYfMYc= -go.uber.org/zap v1.27.1/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= -go.uber.org/zap/exp v0.3.0 h1:6JYzdifzYkGmTdRR59oYH+Ng7k49H9qVpWwNSsGJj3U= -go.uber.org/zap/exp v0.3.0/go.mod h1:5I384qq7XGxYyByIhHm6jg5CHkGY0nsTfbDLgDDlgJQ= go.yaml.in/yaml/v2 v2.4.3 h1:6gvOSjQoTB3vt1l+CU+tSyi/HOjfOjRLJ4YwYZGwRO0= go.yaml.in/yaml/v2 v2.4.3/go.mod h1:zSxWcmIDjOzPXpjlTTbAsKokqkDNAVtZO0WOMiT90s8= go.yaml.in/yaml/v3 v3.0.4 h1:tfq32ie2Jv2UxXFdLJdh3jXuOzWiL1fo0bu/FbuKpbc= From d61665479f4d2029f57ebc9ed4fe8633392ca447 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Mon, 15 Dec 2025 13:33:19 +0100 Subject: [PATCH 13/14] cleanup --- frankenphp_test.go | 29 ++++------------------------- phpmainthread_test.go | 2 -- scaling_test.go | 4 ---- types_test.go | 4 ++-- worker_test.go | 4 +--- 5 files changed, 7 insertions(+), 36 deletions(-) diff --git a/frankenphp_test.go b/frankenphp_test.go index bdc684d28..9b9e22a3d 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -420,8 +420,8 @@ func TestLog_error_log_worker(t *testing.T) { testLog_error_log(t, &testOptions{workerScript: "log-error_log.php"}) } func testLog_error_log(t *testing.T, opts *testOptions) { - var buf syncBuffer - opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) + var buf fmt.Stringer + opts.logger, buf = newTestLogger(t, slog.LevelDebug) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log-error_log.php?i=%d", i), nil) @@ -437,9 +437,8 @@ func TestLog_frankenphp_log_worker(t *testing.T) { testLog_frankenphp_log(t, &testOptions{workerScript: "log-frankenphp_log.php"}) } func testLog_frankenphp_log(t *testing.T, opts *testOptions) { - var buf syncBuffer - - opts.logger = slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})) + var buf fmt.Stringer + opts.logger, buf = newTestLogger(t, slog.LevelDebug) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log-frankenphp_log.php?i=%d", i), nil) @@ -1078,23 +1077,3 @@ func FuzzRequest(f *testing.F) { }, &testOptions{workerScript: "request-headers.php"}) }) } - -// SyncBuffer is a thread-safe buffer for capturing logs in tests. -type syncBuffer struct { - b bytes.Buffer - mu sync.RWMutex -} - -func (s *syncBuffer) Write(p []byte) (n int, err error) { - s.mu.Lock() - defer s.mu.Unlock() - - return s.b.Write(p) -} - -func (s *syncBuffer) String() string { - s.mu.RLock() - defer s.mu.RUnlock() - - return s.b.String() -} diff --git a/phpmainthread_test.go b/phpmainthread_test.go index b777c3394..7e6bf32c1 100644 --- a/phpmainthread_test.go +++ b/phpmainthread_test.go @@ -2,7 +2,6 @@ package frankenphp import ( "io" - "log/slog" "math/rand/v2" "net/http/httptest" "path/filepath" @@ -119,7 +118,6 @@ func TestTransitionThreadsWhileDoingRequests(t *testing.T) { WithWorkerWatchMode([]string{}), WithWorkerMaxFailures(0), ), - WithLogger(slog.New(slog.NewTextHandler(io.Discard, nil))), )) // try all possible permutations of transition, transition every ms diff --git a/scaling_test.go b/scaling_test.go index c0f848c44..f7ecc05e0 100644 --- a/scaling_test.go +++ b/scaling_test.go @@ -1,8 +1,6 @@ package frankenphp import ( - "io" - "log/slog" "testing" "time" @@ -16,7 +14,6 @@ func TestScaleARegularThreadUpAndDown(t *testing.T) { assert.NoError(t, Init( WithNumThreads(1), WithMaxThreads(2), - WithLogger(slog.New(slog.NewTextHandler(io.Discard, nil))), )) autoScaledThread := phpThreads[1] @@ -45,7 +42,6 @@ func TestScaleAWorkerThreadUpAndDown(t *testing.T) { WithWorkerWatchMode([]string{}), WithWorkerMaxFailures(0), ), - WithLogger(slog.New(slog.NewTextHandler(io.Discard, nil))), )) autoScaledThread := phpThreads[2] diff --git a/types_test.go b/types_test.go index c6b81f710..a08f90725 100644 --- a/types_test.go +++ b/types_test.go @@ -1,7 +1,6 @@ package frankenphp import ( - "io" "log/slog" "testing" @@ -13,7 +12,8 @@ import ( // this is necessary if tests make use of PHP's internal allocation func testOnDummyPHPThread(t *testing.T, test func()) { t.Helper() - globalLogger = slog.New(slog.NewTextHandler(io.Discard, nil)) + + globalLogger = slog.Default() _, err := initPHPThreads(1, 1, nil) // boot 1 thread assert.NoError(t, err) handler := convertToTaskThread(phpThreads[0]) diff --git a/worker_test.go b/worker_test.go index 077a370ae..51d5a3417 100644 --- a/worker_test.go +++ b/worker_test.go @@ -1,7 +1,6 @@ package frankenphp_test import ( - "bytes" "fmt" "io" "log" @@ -95,8 +94,7 @@ func TestWorkerEnv(t *testing.T) { } func TestWorkerGetOpt(t *testing.T) { - var buf bytes.Buffer - logger := slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo})) + logger, buf := newTestLogger(t, slog.LevelInfo) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/worker-getopt.php?i=%d", i), nil) From 655ef65f57396f6579eb23ad11479e1cc010ce41 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Mon, 15 Dec 2025 13:44:27 +0100 Subject: [PATCH 14/14] fix getopt() test --- frankenphp_test.go | 4 ++-- log_test.go | 37 +++++++++++++++++++++++++++++++++++++ testdata/worker-getopt.php | 20 ++++++++++---------- worker_test.go | 5 ++--- 4 files changed, 51 insertions(+), 15 deletions(-) create mode 100644 log_test.go diff --git a/frankenphp_test.go b/frankenphp_test.go index 9b9e22a3d..d5368d145 100644 --- a/frankenphp_test.go +++ b/frankenphp_test.go @@ -421,7 +421,7 @@ func TestLog_error_log_worker(t *testing.T) { } func testLog_error_log(t *testing.T, opts *testOptions) { var buf fmt.Stringer - opts.logger, buf = newTestLogger(t, slog.LevelDebug) + opts.logger, buf = newTestLogger(t) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log-error_log.php?i=%d", i), nil) @@ -438,7 +438,7 @@ func TestLog_frankenphp_log_worker(t *testing.T) { } func testLog_frankenphp_log(t *testing.T, opts *testOptions) { var buf fmt.Stringer - opts.logger, buf = newTestLogger(t, slog.LevelDebug) + opts.logger, buf = newTestLogger(t) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/log-frankenphp_log.php?i=%d", i), nil) diff --git a/log_test.go b/log_test.go new file mode 100644 index 000000000..607da6fb9 --- /dev/null +++ b/log_test.go @@ -0,0 +1,37 @@ +package frankenphp_test + +import ( + "bytes" + "fmt" + "log/slog" + "sync" + "testing" +) + +func newTestLogger(t *testing.T) (*slog.Logger, fmt.Stringer) { + t.Helper() + + var buf syncBuffer + + return slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})), &buf +} + +// SyncBuffer is a thread-safe buffer for capturing logs in tests. +type syncBuffer struct { + b bytes.Buffer + mu sync.RWMutex +} + +func (s *syncBuffer) Write(p []byte) (n int, err error) { + s.mu.Lock() + defer s.mu.Unlock() + + return s.b.Write(p) +} + +func (s *syncBuffer) String() string { + s.mu.RLock() + defer s.mu.RUnlock() + + return s.b.String() +} diff --git a/testdata/worker-getopt.php b/testdata/worker-getopt.php index 0d714eb9f..df22c2693 100644 --- a/testdata/worker-getopt.php +++ b/testdata/worker-getopt.php @@ -3,17 +3,17 @@ do { $ok = frankenphp_handle_request(function (): void { print_r($_SERVER); + + if (!isset($_SERVER['HTTP_REQUEST'])) { + exit(1); + } + if (isset($_SERVER['FRANKENPHP_WORKER'])) { + exit(2); + } + if (isset($_SERVER['FOO'])) { + exit(3); + } }); getopt('abc'); - - if (!isset($_SERVER['HTTP_REQUEST'])) { - exit(1); - } - if (isset($_SERVER['FRANKENPHP_WORKER'])) { - exit(2); - } - if (isset($_SERVER['FOO'])) { - exit(3); - } } while ($ok); diff --git a/worker_test.go b/worker_test.go index 51d5a3417..37ba19206 100644 --- a/worker_test.go +++ b/worker_test.go @@ -4,7 +4,6 @@ import ( "fmt" "io" "log" - "log/slog" "net/http" "net/http/httptest" "net/url" @@ -94,7 +93,7 @@ func TestWorkerEnv(t *testing.T) { } func TestWorkerGetOpt(t *testing.T) { - logger, buf := newTestLogger(t, slog.LevelInfo) + logger, buf := newTestLogger(t) runTest(t, func(handler func(http.ResponseWriter, *http.Request), _ *httptest.Server, i int) { req := httptest.NewRequest("GET", fmt.Sprintf("http://example.com/worker-getopt.php?i=%d", i), nil) @@ -110,7 +109,7 @@ func TestWorkerGetOpt(t *testing.T) { assert.Contains(t, string(body), fmt.Sprintf("[REQUEST_URI] => /worker-getopt.php?i=%d", i)) }, &testOptions{logger: logger, workerScript: "worker-getopt.php", env: map[string]string{"FOO": "bar"}}) - assert.NotContains(t, buf.String(), "exit_status") + assert.NotRegexp(t, buf.String(), "exit_status=[1-9]") } func ExampleServeHTTP_workers() {