frankenphp icon indicating copy to clipboard operation
frankenphp copied to clipboard

Pontential memory leak in worker mode

Open dunglas opened this issue 3 years ago • 3 comments

When PHP is compiled with the --enable-debug flag, a potential memory leak is reported in worker mode when running the tests:

go test -v

[Fri Oct 21 08:21:09 2022]  Script:  '-'
/Users/dunglas/workspace/php-src/Zend/zend_hash.c(279) :  Freeing 0x000000012aa5e000 (56 bytes), script=-
Last leak repeated 3 times
=== Total 4 memory leaks detected ===

I tried to track the potential leak with Valgrind but didn't find anything obvious yet.

dunglas avatar Oct 21 '22 13:10 dunglas

The leak looks caused by https://github.com/dunglas/frankenphp/blob/main/frankenphp.c#L122

dunglas avatar Oct 21 '22 15:10 dunglas

That's amazing that you can detect these memory leaks. In my experience, a few PHP functions leak and have leaked for over a decade when used in specific contexts (fgetcsv comes to mind).

withinboredom avatar Oct 23 '22 08:10 withinboredom

Here is a useful Valgrind stack trace:

==1695== 4,080 (560 direct, 3,520 indirect) bytes in 10 blocks are definitely lost in loss record 33 of 35
==1695==    at 0x4849E4C: malloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==1695==    by 0x761F17: __zend_malloc (zend_alloc.c:3089)
==1695==    by 0x76057F: _malloc_custom (zend_alloc.c:2439)
==1695==    by 0x7607B7: _emalloc (zend_alloc.c:2558)
==1695==    by 0x7C36D7: _zend_new_array (zend_hash.c:279)
==1695==    by 0xA048A7: php_sapi_filter (filter.c:312)
==1695==    by 0x729D8F: php_default_treat_data (php_variables.c:562)
==1695==    by 0x72AD0B: php_auto_globals_create_get (php_variables.c:783)
==1695==    by 0x7699E7: zend_activate_auto_globals (zend_compile.c:1789)
==1695==    by 0x72ABAB: php_hash_environment (php_variables.c:772)
==1695==    by 0x706F23: frankenphp_worker_request_startup (frankenphp.c:140)
==1695==    by 0x707A17: zif_frankenphp_handle_request (frankenphp.c:191)
==1695== 
==1695== 8,192 bytes in 1 blocks are definitely lost in loss record 34 of 35
==1695==    at 0x484C164: calloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==1695==    by 0x31285C0B: zend_jit_trace_reset_caches (zend_jit_trace.c:8355)
==1695==    by 0x312889E3: zend_jit_activate (zend_jit.c:5079)
==1695==    by 0x31066117: accel_activate (ZendAccelerator.c:2748)
==1695==    by 0x7B93A7: zend_activate_modules (zend_API.c:3091)
==1695==    by 0x710C23: php_request_startup (main.c:1780)
==1695==    by 0x707E0B: frankenphp_request_startup (frankenphp.c:539)
==1695==    by 0x7065FF: _cgo_d13821a62ab4_Cfunc_frankenphp_request_startup (cgo-gcc-prolog:161)
==1695==    by 0x49823B: runtime.asmcgocall.abi0 (asm_arm64.s:973)
==1695==    by 0x400020233F: ???
==1695== 
==1695== 8,192 bytes in 1 blocks are definitely lost in loss record 35 of 35
==1695==    at 0x484C164: calloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==1695==    by 0x31285C0B: zend_jit_trace_reset_caches (zend_jit_trace.c:8355)
==1695==    by 0x312889E3: zend_jit_activate (zend_jit.c:5079)
==1695==    by 0x31066117: accel_activate (ZendAccelerator.c:2748)
==1695==    by 0x7B93A7: zend_activate_modules (zend_API.c:3091)
==1695==    by 0x710C23: php_request_startup (main.c:1780)
==1695==    by 0x707E0B: frankenphp_request_startup (frankenphp.c:539)
==1695==    by 0x7065FF: _cgo_d13821a62ab4_Cfunc_frankenphp_request_startup (cgo-gcc-prolog:161)
==1695==    by 0x49823B: runtime.asmcgocall.abi0 (asm_arm64.s:973)
==1695==    by 0x400020281F: ???

To produce a similar trace:

go test -c
ZEND_DONT_UNLOAD_MODULES=1 USE_ZEND_ALLOC=0 valgrind --leak-check=full --show-reachable=yes --track-origins=yes ./frankenphp.test -test.run ^TestHelloWorld_worker$

dunglas avatar Oct 23 '22 20:10 dunglas

Stack trace updated with the latest fixes:

==4137== 5,904 (112 direct, 5,792 indirect) bytes in 2 blocks are definitely lost in loss record 42 of 44
==4137==    at 0x4849E4C: malloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==4137==    by 0x75EEDF: __zend_malloc (zend_alloc.c:3089)
==4137==    by 0x75D547: _malloc_custom (zend_alloc.c:2439)
==4137==    by 0x75D77F: _emalloc (zend_alloc.c:2558)
==4137==    by 0x7C069F: _zend_new_array (zend_hash.c:279)
==4137==    by 0x72850B: php_register_server_variables (php_variables.c:707)
==4137==    by 0x7294F3: php_auto_globals_create_server (php_variables.c:860)
==4137==    by 0x7667F7: zend_is_auto_global (zend_compile.c:1758)
==4137==    by 0x706E3B: frankenphp_worker_request_startup (frankenphp.c:149)
==4137==    by 0x707A5F: zif_frankenphp_handle_request (frankenphp.c:191)
==4137==    by 0x7F2497: ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER (zend_vm_execute.h:1312)
==4137==    by 0x88323F: execute_ex (zend_vm_execute.h:56015)
==4137== 
==4137== 8,192 bytes in 1 blocks are definitely lost in loss record 43 of 44
==4137==    at 0x484C164: calloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==4137==    by 0x31AC6C0B: zend_jit_trace_reset_caches (zend_jit_trace.c:8355)
==4137==    by 0x31AC99E3: zend_jit_activate (zend_jit.c:5079)
==4137==    by 0x318A7117: accel_activate (ZendAccelerator.c:2748)
==4137==    by 0x7B636F: zend_activate_modules (zend_API.c:3091)
==4137==    by 0x70FBEF: php_request_startup (main.c:1780)
==4137==    by 0x707DFB: frankenphp_request_startup (frankenphp.c:532)
==4137==    by 0x7065CF: _cgo_d13821a62ab4_Cfunc_frankenphp_request_startup (cgo-gcc-prolog:161)
==4137==    by 0x49820B: runtime.asmcgocall.abi0 (asm_arm64.s:973)
==4137==    by 0x400008A67F: ???
==4137== 
==4137== 8,192 bytes in 1 blocks are definitely lost in loss record 44 of 44
==4137==    at 0x484C164: calloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==4137==    by 0x31AC6C0B: zend_jit_trace_reset_caches (zend_jit_trace.c:8355)
==4137==    by 0x31AC99E3: zend_jit_activate (zend_jit.c:5079)
==4137==    by 0x318A7117: accel_activate (ZendAccelerator.c:2748)
==4137==    by 0x7B636F: zend_activate_modules (zend_API.c:3091)
==4137==    by 0x70FBEF: php_request_startup (main.c:1780)
==4137==    by 0x707DFB: frankenphp_request_startup (frankenphp.c:532)
==4137==    by 0x7065CF: _cgo_d13821a62ab4_Cfunc_frankenphp_request_startup (cgo-gcc-prolog:161)
==4137==    by 0x49820B: runtime.asmcgocall.abi0 (asm_arm64.s:973)
==4137==    by 0x400019833F: ???
==4137== 

dunglas avatar Oct 24 '22 21:10 dunglas

This leak:

==4137== 5,904 (112 direct, 5,792 indirect) bytes in 2 blocks are definitely lost in loss record 42 of 44
==4137==    at 0x4849E4C: malloc (in /usr/lib/aarch64-linux-gnu/valgrind/vgpreload_memcheck-arm64-linux.so)
==4137==    by 0x75EEDF: __zend_malloc (zend_alloc.c:3089)
==4137==    by 0x75D547: _malloc_custom (zend_alloc.c:2439)
==4137==    by 0x75D77F: _emalloc (zend_alloc.c:2558)
==4137==    by 0x7C069F: _zend_new_array (zend_hash.c:279)
==4137==    by 0x72850B: php_register_server_variables (php_variables.c:707)
==4137==    by 0x7294F3: php_auto_globals_create_server (php_variables.c:860)
==4137==    by 0x7667F7: zend_is_auto_global (zend_compile.c:1758)
==4137==    by 0x706E3B: frankenphp_worker_request_startup (frankenphp.c:149)
==4137==    by 0x707A5F: zif_frankenphp_handle_request (frankenphp.c:191)
==4137==    by 0x7F2497: ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER (zend_vm_execute.h:1312)
==4137==    by 0x88323F: execute_ex (zend_vm_execute.h:56015)

is caused by this line: https://github.com/dunglas/frankenphp/blob/main/frankenphp.c#L149

Without this call to zend_is_auto_global(), $_SERVER is not updated with the new values.

I don't understand why this leaks because the previous value should be released here: https://github.com/php/php-src/blob/PHP-8.2/main/php_variables.c#L706 And the latest created array should be released here: https://github.com/php/php-src/blob/PHP-8.2/main/main.c#L1848-L1855

dunglas avatar Oct 25 '22 07:10 dunglas