Core dumped with opentelemetry extension in symfony app in php 8.4

[trigrab]

Describe your environment We have an older symfony application where we want to introduce opentelemetry. We are in the middle of testing phase during which we upgraded production from php 8.3.15 to php 8.4.3. After the upgrade, our opentelemetry branch app breaks on every web request enabled: child 24 exited on signal 11 (SIGSEGV) after 64.931337 seconds from start.

Steps to reproduce
I created a minimal Dockerfile which reproduces the behavior:

ARG PHP_VERSION=8.4.3

FROM php:${PHP_VERSION}-fpm-bookworm

RUN pecl install opentelemetry-1.1.2 && docker-php-ext-enable opentelemetry

RUN docker-php-ext-enable opcache --ini-name 10-opcache.ini

RUN echo "opcache.enable=1" >> /usr/local/etc/php/conf.d/10-opcache.ini \
  && echo "opcache.preload=/app/config/preload.php" >> /usr/local/etc/php/conf.d/10-opcache.ini \
  && echo "opcache.preload_user=root" >> /usr/local/etc/php/conf.d/10-opcache.ini

COPY --from=composer/composer:2-bin /composer /usr/local/bin/composer

RUN curl -sS https://get.symfony.com/cli/installer | bash; \
  echo 'export PATH="$HOME/.symfony5/bin:$PATH"' >> $HOME/.profile

RUN apt-get update && apt-get install -y git && apt-get clean
RUN git config --global user.email "[email protected]" \
  && git config --global user.name "Example User"

RUN /root/.symfony5/bin/symfony new /app --version="6.4.x" --webapp --no-interaction

RUN echo "    cache.adapter.null:" >> /app/config/services.yaml \
 && echo "        class: Symfony\Component\Cache\Adapter\NullAdapter" >> /app/config/services.yaml \
 && echo "        arguments: [~] " >> /app/config/services.yaml

WORKDIR /app

RUN bin/console cache:warmup --env=prod
CMD ["/root/.symfony5/bin/symfony", "server:start", "--allow-all-ip"]

It does not break if:

• PHP_VERSION=8.3.15
• opcache.preload is disabled
• I don't modify the default symfony app, that's why I added the dummy service with Cache NullAdapter which is probably not the root cause
• opentelemetry extension OR opcache disabled

What is the expected behavior?
A web request results in the default page as no routes are configured

What is the actual behavior?
A web request results in an error page, stating: # unable to fetch the response from the backend: unexpected EOF
Container logs:

symfony-otel-1  | [PHP-FPM    ] 8:39:09] NOTICE: [pool www] child 24 started
symfony-otel-1  | [Web Server ] Feb  6 08:39:10 |ERROR  | SERVER GET  (502) /favicon.ico ip="172.39.0.1"
symfony-otel-1  | [PHP-FPM    ] Feb  6 08:39:10 |WARNING| FPM    [pool www] child 23 exited on signal 11 (SIGSEGV - core dumped) after 54.759915 seconds from start 
symfony-otel-1  | [PHP-FPM    ] Feb  6 08:39:10 |NOTICE | FPM    [pool www] child 27 started 

Additional context

The application does not break immediately or on cache preloading. It just breaks on every web request which fpm recovers from.

[brettmc]

Can you check if you have JIT enabled? Opcache being a condition for failure makes me think it could be this bug: php/php-src#14841

[trigrab]

Hi,
thank you for your fast reply.
Unfortunately we did not change any settings for JIT.

Here our php settings ouput for any JIT settings:

$ php -i | grep -i jit
auto_globals_jit => On => On
PCRE JIT Support => enabled
PCRE JIT Target => x86 64bit (little endian + unaligned)
pcre.jit => On => On
JIT => Disabled
opcache.jit => disable => disable
opcache.jit_bisect_limit => 0 => 0
opcache.jit_blacklist_root_trace => 16 => 16
opcache.jit_blacklist_side_trace => 8 => 8
opcache.jit_buffer_size => 64M => 64M
opcache.jit_debug => 0 => 0
opcache.jit_hot_func => 127 => 127
opcache.jit_hot_loop => 64 => 64
opcache.jit_hot_return => 8 => 8
opcache.jit_hot_side_exit => 8 => 8
opcache.jit_max_exit_counters => 8192 => 8192
opcache.jit_max_loop_unrolls => 8 => 8
opcache.jit_max_polymorphic_calls => 2 => 2
opcache.jit_max_recursive_calls => 2 => 2
opcache.jit_max_recursive_returns => 2 => 2
opcache.jit_max_root_traces => 1024 => 1024
opcache.jit_max_side_traces => 128 => 128
opcache.jit_max_trace_length => 1024 => 1024
opcache.jit_prof_threshold => 0.005 => 0.005

I understand, that in php 8.4 the default settings were changed: https://php.watch/versions/8.4/opcache-jit-ini-default-changes
But as far as I understand, it is still disabled as before.

After your message, I tried setting it to the default settings from before 8.4, but without success.

opcache.jit=tracing
opcache.jit_buffer_size=0

[intuibase]

Hey
I've reproduced crash with your Dockerfile and made very basic analysis as I didn't get all debug symbols yet.
From my observation it doesn't look like crash from opentelemetry extension - but backtrace might be misleading because of unresolved debug symbols. There is no OTEL frames on PHP side.

Program received signal SIGSEGV, Segmentation fault.
0x0000605917045d29 in ?? ()
(gdb) bt
#0  0x0000605917045d29 in ?? ()
#1  0x00006059170466f7 in ?? ()
#2  0x000060591747b343 in zend_execute ()
#3  0x00006059174e28e0 in zend_execute_script ()
#4  0x0000605917380c65 in php_execute_script_ex ()
#5  0x000060591704d92a in ?? ()
#6  0x00007485aac7424a in __libc_start_call_main (main=main@entry=0x60591704cbe0, argc=argc@entry=5, argv=argv@entry=0x7ffcaa296618) at ../sysdeps/nptl/libc_start_call_main.h:58
#7  0x00007485aac74305 in __libc_start_main_impl (main=0x60591704cbe0, argc=5, argv=0x7ffcaa296618, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffcaa296608) at ../csu/libc-start.c:360
#8  0x000060591704f8e1 in _start ()
(gdb) PHP_PrintStackFromExecData executor_globals.current_execute_data
0x7485a7c14ba0 Monolog\Level->tryFrom(100) ZEND_INTERNAL_FUNCTION Called from: tryFrom(0:0) args(C:1 R:1) in  ----- UNKNOWN ----- : ---- ERROR GETTING CALLER DATA ---- 
0x7485a7c14ad0 Monolog\Logger->toMonologLevel(100) ZEND_USER_FUNCTION Called from: toMonologLevel(480:512) args(C:1 R:1) in /app/vendor/monolog/monolog/src/Monolog/Logger.php:506
0x7485a7c14a50 Monolog\Handler\AbstractHandler->setLevel(100) ZEND_USER_FUNCTION Called from: setLevel(58:63) args(C:1 R:1) in /app/vendor/monolog/monolog/src/Monolog/Handler/AbstractHandler.php:60
0x7485a7c149d0 Monolog\Handler\AbstractHandler->__construct(100, false) ZEND_USER_FUNCTION Called from: __construct(36:40) args(C:2 R:0) in /app/vendor/monolog/monolog/src/Monolog/Handler/AbstractHandler.php:38
0x7485a7c14930 Symfony\Bridge\Monolog\Handler\ConsoleHandler->__construct(NULL, false, array(elements: 0, zval: 0x7485a7c149a0 ), array(elements: 0, zval: 0x7485a7c149b0 )) ZEND_USER_FUNCTION Called from: __construct(106:116) args(C:4 R:0) in /app/vendor/symfony/monolog-bridge/Handler/ConsoleHandler.php:108
0x7485a7c14890 ContainerCx5FcDq\App_KernelDevDebugContainer->getMonolog_Handler_ConsoleService(object[ContainerCx5FcDq\App_KernelDevDebugContainer refc:1 obj:0x7485a7ced580 zval:0x7485a7c148e0]) ZEND_USER_FUNCTION Called from: getMonolog_Handler_ConsoleService(1458:1461) args(C:1 R:1) in /app/var/cache/dev/ContainerCx5FcDq/App_KernelDevDebugContainer.php:1460
0x7485a7c14750 ContainerCx5FcDq\getDebug_ErrorHandlerConfiguratorService->do(object[ContainerCx5FcDq\App_KernelDevDebugContainer refc:1 obj:0x7485a7ced580 zval:0x7485a7c147a0], false) ZEND_USER_FUNCTION Called from: do(19:29) args(C:2 R:1) in /app/var/cache/dev/ContainerCx5FcDq/getDebug_ErrorHandlerConfiguratorService.php:24
0x7485a7c14680 ContainerCx5FcDq\App_KernelDevDebugContainer->load("getDebug_ErrorHandlerConfiguratorService.php") ZEND_USER_FUNCTION Called from: load(489:504) args(C:2 R:1) in /app/var/cache/dev/ContainerCx5FcDq/App_KernelDevDebugContainer.php:503
0x7485a7c14560 Symfony\Component\DependencyInjection\Container->make(object[ContainerCx5FcDq\App_KernelDevDebugContainer refc:1 obj:0x7485a7ced580 zval:0x7485a7c145b0], "debug.error_handler_configurator", 1) ZEND_USER_FUNCTION Called from: make(219:267) args(C:3 R:3) in /app/vendor/symfony/dependency-injection/Container.php:229
0x7485a7c14480 Symfony\Component\DependencyInjection\Container->get("debug.error_handler_configurator") ZEND_USER_FUNCTION Called from: get(207:212) args(C:2 R:1) in /app/vendor/symfony/dependency-injection/Container.php:211
0x7485a7c143f0 Symfony\Bundle\FrameworkBundle\FrameworkBundle->boot() ZEND_USER_FUNCTION Called from: boot(100:126) args(C:0 R:0) in /app/vendor/symfony/framework-bundle/FrameworkBundle.php:116
0x7485a7c14360 Symfony\Component\HttpKernel\Kernel->boot() ZEND_USER_FUNCTION Called from: boot(109:135) args(C:0 R:0) in /app/vendor/symfony/http-kernel/Kernel.php:131
0x7485a7c14290 Symfony\Component\HttpKernel\Kernel->handle(object[Symfony\Component\HttpFoundation\Request refc:1 obj:0x7485a7c91000 zval:0x7485a7c142e0]) ZEND_USER_FUNCTION Called from: handle(182:201) args(C:3 R:1) in /app/vendor/symfony/http-kernel/Kernel.php:192
0x7485a7c14200 Symfony\Component\Runtime\Runner\Symfony\HttpKernelRunner->run() ZEND_USER_FUNCTION Called from: run(33:57) args(C:0 R:0) in /app/vendor/symfony/runtime/Runner/Symfony/HttpKernelRunner.php:35
0x7485a7c140a0 UNKNOWN TYPE(/app/vendor/autoload_runtime.php)() ZEND_USER_FUNCTION Called from:  ----- UNKNOWN ----- (1:31) args(C:0 R:0) in /app/vendor/autoload_runtime.php:29
0x7485a7c14020 ZEND_REQUIRE_ONCE(/app/public/index.php)() ZEND_USER_FUNCTION Called from:  ----- UNKNOWN ----- (1:10) args(C:0 R:0) in /app/public/index.php:5
Stack end (17 frames)

I'll try to get debug symbols and will continue investigation.

I was trying with opcache.jit=disable - it crashes too

[trigrab]

Hi,

thank you for your analysis. I managed to get similar results by building the upstream php container myself with debug symbols.

I don't see anything from opentelemetry as well:

(gdb) thread apply all bt full

Thread 1 (Thread 0x702397e5eac0 (LWP 177) "php-fpm"):
#0  0x0000617e32d66563 in zend_observer_handler_is_unobserved (handler=0x8) at /usr/src/php/Zend/zend_observer.h:92
No locals.
#1  0x0000617e32d66658 in zend_observer_fcall_has_no_observers (execute_data=0x702397815ba0, allow_generator=false, handler=0x7ffd19985420) at /usr/src/php/Zend/zend_observer.h:109
        function = 0x41355f70
        runtime_cache__ptr = 0x44f9
#2  0x0000617e32d66690 in zend_observer_fcall_begin_specialized (execute_data=0x702397815ba0, allow_generator=false) at /usr/src/php/Zend/zend_observer.h:115
        handler = 0x8
#3  0x0000617e32d7bcce in ZEND_DO_FCALL_SPEC_OBSERVER_HANDLER () at /usr/src/php/Zend/zend_vm_execute.h:2141
        should_throw = false
        call = 0x702397815ba0
        fbc = 0x41355f70
        ret = 0x702397815b50
        retval = zval of type 240 = {value = 0x702397815bf0, u1 = {type_info = 2541837296, v = {type = 240 '\360', type_flags = 91 '[', u = {extra = 38785}}}, u2 = 28707}
        __PRETTY_FUNCTION__ = "ZEND_DO_FCALL_SPEC_OBSERVER_HANDLER"
#4  0x0000617e32e03ab4 in execute_ex (ex=0x702397815020) at /usr/src/php/Zend/zend_vm_execute.h:58859
        vm_stack_data = {hybrid_jit_red_zone = "\240V\230\031\375\177\000\000\307b\3512~a\000\000\000\000\000\000\001\000\000\000 P\201\227#p\000\000\3500\200\227#p\000\000\000!\313\367\360\377\235\362", orig_opline = 0x70239b4a1020 <_rtld_global>, orig_execute_data = 0x617e33f39798}
        __PRETTY_FUNCTION__ = "execute_ex"
#5  0x0000617e32e084d0 in zend_execute (op_array=0x702397870000, return_value=0x0) at /usr/src/php/Zend/zend_vm_execute.h:64236
        execute_data = 0x702397815020
        object_or_called_scope = 0x0
        call_info = 1245184
#6  0x0000617e32ec5fc6 in zend_execute_script (type=8, retval=0x0, file_handle=0x7ffd19986b50) at /usr/src/php/Zend/zend.c:1934
        op_array = 0x702397870000
        ret = SUCCESS
#7  0x0000617e32c3ebb3 in php_execute_script_ex (primary_file=0x7ffd19986b50, retval=0x0) at /usr/src/php/main/main.c:2575
        realfile = "\000\000\000\000\375\177\000\000\020[\230\031\375\177\000\000\320Z\230\031.\000\000\000DD\3113~a\000\000\320h\230\031\375\177\000\000\003}\3432~a\000\000P\251\032e", '\000' <repeats 12 times>, " \251\032e~a\000\000,\341B2~a\000\000h&J\233#p\000\000\244|G\233#p\000\000\020z\r\233#p\000\000P\265\250\020\000\000\000\0000'x\232#p\000\000P*x\232#p\000\0004[\230\031\375\177\000\000\312\200G\233#p\000\000\034\v\000\000\000\000\000\000\260Gy\232#p\000\000\020z\r\233#p\000\0008[\230\031\375\177\000\0004[\230\031\375\177\000\000\000[\230\031\375\177\000\000h&J\233#p\000\000"...
        __orig_bailout = 0x7ffd19986c70
        __bailout = {{__jmpbuf = {140725032873976, -53917973461781262, 0, 140725032873992, 107194665375640, 123298231488544, -53917971695979278, -4447824337898883854}, __mask_was_saved = 0, __saved_mask = {__val = {0, 140725032873992, 107194665375640, 123298231488544, 123298218323743, 140725032873992, 107194665375640, 123298231488544, 140725032873976, 140725032868112, 107194647532203, 4294967296, 107195490019664, 140725032868144, 140725032868384, 197997910496}}}}
        prepend_file_p = 0x0
        append_file_p = 0x0
        prepend_file = {handle = {fp = 0x0, stream = {handle = 0x0, isatty = 0, reader = 0x0, fsizer = 0x0, closer = 0x0}}, filename = 0x0, opened_path = 0x0, type = 0 '\000', primary_script = false, in_list = false, buf = 0x0, len = 0}
        append_file = {handle = {fp = 0x0, stream = {handle = 0x0, isatty = 0, reader = 0x0, fsizer = 0x0, closer = 0x6275702f7070612f}}, filename = 0x6573752e2f63696c, opened_path = 0x696e692e72, type = 90 'Z', primary_script = 196, in_list = 236, buf = 0x7ffd199858b8 "\230\227\3633~a", len = 32}
        old_cwd = 0x70239786e000 "/app"
        result = true
#8  0x0000617e32c3eddd in php_execute_script (primary_file=0x7ffd19986b50) at /usr/src/php/main/main.c:2615
No locals.
#9  0x0000617e32edb096 in main (argc=1, argv=0x7ffd19986ff8) at /usr/src/php/sapi/fpm/fpm/fpm_main.c:1930
        primary_script = 0x7023978030a8 "/app/public/index.php"
        __orig_bailout = 0x0
        __bailout = {{__jmpbuf = {140725032873976, -53917973589707534, 0, 140725032873992, 107194665375640, 123298231488544, -53917973468072718, -4447824666495601422}, __mask_was_saved = 0, __saved_mask = {__val = {18374686479671623680, 0, 0, 0, 0, 123298219365500, 123298219365500, 123298219254976, 123298219256512, 123298219365500, 123298219365500, 123298219365500, 123298219365500, 123298211815424, 123298211817056, 0}}}}
        exit_status = 0
        cgi = 0
        c = -1
        use_extended_info = 0
        file_handle = {handle = {fp = 0x0, stream = {handle = 0x0, isatty = 0, reader = 0x0, fsizer = 0x0, closer = 0x0}}, filename = 0x70239786d730, opened_path = 0x40c320a0, type = 0 '\000', primary_script = true, in_list = false, buf = 0x0, len = 0}
        orig_optind = 1
        orig_optarg = 0x0
        ini_builder = {value = 0x0, length = 0}
        max_requests = 0
        requests = 0
        fcgi_fd = 12
        request = 0x617e65494720
        fpm_config = 0x0
        fpm_prefix = 0x0
        fpm_pid = 0x0
        test_conf = 0
        force_daemon = -1
        force_stderr = 0
        php_information = 0
        php_allow_to_run_as_root = 0
        __func__ = "main"
        ret = FPM_INIT_CONTINUE
(gdb) zbacktrace 
[0x702397815ba0] Monolog\Level->tryFrom(100) [internal function]
[0x702397815ad0] Monolog\Logger->toMonologLevel(100) /app/vendor/monolog/monolog/src/Monolog/Logger.php:506 
[0x702397815a50] Monolog\Handler\AbstractHandler->setLevel(100) /app/vendor/monolog/monolog/src/Monolog/Handler/AbstractHandler.php:60 
[0x7023978159d0] Monolog\Handler\AbstractHandler->__construct(100, true) /app/vendor/monolog/monolog/src/Monolog/Handler/AbstractHandler.php:38 
[0x702397815930] Symfony\Bridge\Monolog\Handler\ConsoleHandler->__construct(NULL, true, array(0)[0x7023978159a0], array(0)[0x7023978159b0]) /app/vendor/symfony/monolog-bridge/Handler/ConsoleHandler.php:108 
[0x702397815890] ContainerDJ8ptfM\App_KernelDevDebugContainer->getMonolog_Handler_ConsoleService(object[0x7023978158e0]) /app/var/cache/dev/ContainerDJ8ptfM/App_KernelDevDebugContainer.php:1462 
[0x702397815750] ContainerDJ8ptfM\getDebug_ErrorHandlerConfiguratorService->do(object[0x7023978157a0], true) /app/var/cache/dev/ContainerDJ8ptfM/getDebug_ErrorHandlerConfiguratorService.php:24 
[0x702397815680] ContainerDJ8ptfM\App_KernelDevDebugContainer->load("getDebug_ErrorHandlerConfiguratorService.php") /app/var/cache/dev/ContainerDJ8ptfM/App_KernelDevDebugContainer.php:504 
[0x702397815560] Symfony\Component\DependencyInjection\Container->make(object[0x7023978155b0], "debug.error_handler_configurator", 1) /app/vendor/symfony/dependency-injection/Container.php:229 
[0x702397815480] Symfony\Component\DependencyInjection\Container->get("debug.error_handler_configurator") /app/vendor/symfony/dependency-injection/Container.php:211 
[0x7023978153f0] Symfony\Bundle\FrameworkBundle\FrameworkBundle->boot() /app/vendor/symfony/framework-bundle/FrameworkBundle.php:116 
[0x702397815360] Symfony\Component\HttpKernel\Kernel->boot() /app/vendor/symfony/http-kernel/Kernel.php:131 
[0x702397815290] Symfony\Component\HttpKernel\Kernel->handle(object[0x7023978152e0]) /app/vendor/symfony/http-kernel/Kernel.php:192 
[0x702397815200] Symfony\Component\Runtime\Runner\Symfony\HttpKernelRunner->run() /app/vendor/symfony/runtime/Runner/Symfony/HttpKernelRunner.php:35 
[0x7023978150a0] (main) /app/vendor/autoload_runtime.php:29 
[0x702397815020] (main) /app/public/index.php:5 

It would be really great if someone can assist me in understanding the information we have here. That would help me create an issue in the right project and hopefully find the root cause to this incompatibility between opentelemetry and said project.

[julien-maurel]

Hi,
I've notice same behavior today.
Jit disabled, opcache preloading enabled, php8.4 fpm.
I can add :

• some http requests pass, some not (with child XX exited on signal 11 (SIGSEGV) after ... seconds from start)
• I do some tests on opcache preload file, if I kept some classes only, it's ok, so it's not preloading itself but certainly some cases during preloading

Very difficult to give you more information without give you the app, but if I can help, don't hesitate to ping me
For the moment, I disabled preloading, but it's not a good solution on the long term :)