php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #80307 Segfault in zend_execute when opcache preload enabled
Submitted: 2020-11-02 20:32 UTC Modified: 2020-11-05 15:39 UTC
From: php at shyim dot de Assigned: nikic (profile)
Status: Closed Package: opcache
PHP Version: 8.0.0RC3 OS: Ubuntu 20.04
Private report: No CVE-ID: None
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: php at shyim dot de
New email:
PHP Version: OS:

 

 [2020-11-02 20:32 UTC] php at shyim dot de
Description:
------------
Tried my Symfony 5.1 project on PHP 8.0RC3, working in 7.4. With enabled opcache preload a segmentation fault happens on any request. See backtrace below

Test script:
---------------
Clone https://github.com/symfony/demo
Change .env APP_ENV to prod
composer install
./bin/console cache:clear
Add var/cache/prod/App_KernelProdContainer.preload.php to opcache.preload
Start web server 
/opt/php-7.4/bin/php -S 0.0.0.0:7050 -t .
curl localhost:7050 

=> Segmentation fault...

Expected result:
----------------
Its working like in 7.4

Actual result:
--------------
Program received signal SIGSEGV, Segmentation fault.
0x00005555557973ca in zend_verify_recv_arg_type (cache_slot=0x7ffff4011120, arg=0x7ffff4014c80, arg_num=1, zf=0x4122f6f8) at /home/shyim/src/php-8.0.0RC3/Zend/zend_execute.c:1043
1043            cur_arg_info = &zf->common.arg_info[arg_num-1];
(gdb) bt
#0  0x00005555557973ca in zend_verify_recv_arg_type (cache_slot=0x7ffff4011120, arg=0x7ffff4014c80, arg_num=1, zf=0x4122f6f8) at /home/shyim/src/php-8.0.0RC3/Zend/zend_execute.c:1043
#1  zend_verify_recv_arg_type_helper_SPEC (op_1=0x7ffff4014c80) at /home/shyim/src/php-8.0.0RC3/Zend/zend_vm_execute.h:2450
#2  0x000055555579abb7 in ZEND_RECV_SPEC_UNUSED_HANDLER () at /home/shyim/src/php-8.0.0RC3/Zend/zend_vm_execute.h:3629
#3  execute_ex (ex=0x7ffff4014c80) at /home/shyim/src/php-8.0.0RC3/Zend/zend_vm_execute.h:54626
#4  0x0000555555bac3c4 in zend_execute (op_array=0x7ffff4003000, return_value=0x0) at /home/shyim/src/php-8.0.0RC3/Zend/zend_vm_execute.h:58789
#5  0x0000555555b43c23 in zend_execute_scripts (type=-201241552, type@entry=8, retval=retval@entry=0x0, file_count=file_count@entry=3) at /home/shyim/src/php-8.0.0RC3/Zend/zend.c:1680
#6  0x0000555555ae0712 in php_execute_script (primary_file=primary_file@entry=0x7fffffffcff0) at /home/shyim/src/php-8.0.0RC3/main/main.c:2490
#7  0x0000555555bd8e42 in php_cli_server_dispatch_script (server=server@entry=0x555556b76000 <server>, client=client@entry=0x555556c3d530) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2081
#8  0x0000555555bd93f3 in php_cli_server_dispatch (client=0x555556c3d530, server=0x555556b76000 <server>) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2253
#9  php_cli_server_recv_event_read_request (server=0x555556b76000 <server>, client=0x555556c3d530) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2525
#10 0x0000555555bd9759 in php_cli_server_do_event_for_each_fd_callback (_params=_params@entry=0x7fffffffd290, fd=fd@entry=5, event=event@entry=1) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2611
#11 0x0000555555bda215 in php_cli_server_poller_iter_on_active (poller=0x555556b76008 <server+8>, callback=0x555555bd9700 <php_cli_server_do_event_for_each_fd_callback>, opaque=0x7fffffffd290) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:920
#12 php_cli_server_do_event_for_each_fd (whandler=0x555555bd8070 <php_cli_server_send_event>, rhandler=0x555555bd8e50 <php_cli_server_recv_event_read_request>, server=0x555556b76000 <server>) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2629
#13 php_cli_server_do_event_loop (server=0x555556b76000 <server>) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2639
#14 do_cli_server (argc=<optimized out>, argv=<optimized out>) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli_server.c:2769
#15 0x00005555557a3a53 in main (argc=5, argv=0x555556bafe10) at /home/shyim/src/php-8.0.0RC3/sapi/cli/php_cli.c:1339

Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2020-11-02 20:51 UTC] danack@php.net
Are you able to find a simple reproduce case?

If not, please could you try adding 'echo "got here"; exit(0);' first at the top-level, and then moving it deeper into the app until you find the function that is causing the problem?

kind of looks like a borked opcache optimization, so don't need a full repro case, if you can identify a function that has the borked optimisation applied to it.
 [2020-11-02 21:56 UTC] php at shyim dot de
I have debugged with die some time and got a very smaller repository.
Repository: https://github.com/shyim/php-bug-80307/tree/master

When I remove the logger assignment it works as expected here: 
https://github.com/php-fig/log/blob/master/Psr/Log/LoggerAwareTrait.php#L24
 [2020-11-03 19:20 UTC] php at shyim dot de
Tested again against branch PHP-8.0(commit: 54668a449e2e535f638b6b0bc22c8c3956e534a2) after seeing some preload related stuff committed today.
Now the Webserver even does not start :D

php: /home/shyim/src/php-src/ext/opcache/Optimizer/zend_optimizer.c:1035: zend_revert_pass_two: Assertion `(op_array->fn_flags & (1 << 25)) != 0' failed

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff6ba7859 in __GI_abort () at abort.c:79
#2  0x00007ffff6ba7729 in __assert_fail_base (fmt=0x7ffff6d3d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x7ffff3fb65b8 "(op_array->fn_flags & (1 << 25)) != 0", file=0x7ffff3fb5780 "/home/shyim/src/php-src/ext/opcache/Optimizer/zend_optimizer.c", line=1035, function=<optimized out>) at assert.c:92
#3  0x00007ffff6bb8f36 in __GI___assert_fail (assertion=0x7ffff3fb65b8 "(op_array->fn_flags & (1 << 25)) != 0", file=0x7ffff3fb5780 "/home/shyim/src/php-src/ext/opcache/Optimizer/zend_optimizer.c", line=1035, function=0x7ffff3fb6940 <__PRETTY_FUNCTION__.19583> "zend_revert_pass_two") at assert.c:101
#4  0x00007ffff3e636ad in zend_revert_pass_two (op_array=0x7ffff400e990) at /home/shyim/src/php-src/ext/opcache/Optimizer/zend_optimizer.c:1035
#5  0x00007ffff3e6469b in zend_optimize_script (script=0x7ffff414b600, optimization_level=2147401727, debug_level=0) at /home/shyim/src/php-src/ext/opcache/Optimizer/zend_optimizer.c:1421
#6  0x00007ffff3e33bd3 in preload_optimize (script=0x7ffff414b600) at /home/shyim/src/php-src/ext/opcache/ZendAccelerator.c:4187
#7  0x00007ffff3e3581c in accel_preload (config=0x555556dda3f8 "/home/shyim/bug-80307/preload.php", in_child=false) at /home/shyim/src/php-src/ext/opcache/ZendAccelerator.c:4677
#8  0x00007ffff3e36341 in accel_finish_startup () at /home/shyim/src/php-src/ext/opcache/ZendAccelerator.c:4919
#9  0x00007ffff3e30098 in accel_post_startup () at /home/shyim/src/php-src/ext/opcache/ZendAccelerator.c:3123
#10 0x0000555555db60c2 in zend_post_startup () at /home/shyim/src/php-src/Zend/zend.c:1030
#11 0x0000555555d18e33 in php_module_startup (sf=0x555556d5ce00 <cli_server_sapi_module>, additional_modules=0x555556d5cd20 <cli_server_module_entry>, num_additional_modules=1) at /home/shyim/src/php-src/main/main.c:2240
#12 0x0000555555eac244 in sapi_cli_server_startup (sapi_module=0x555556d5ce00 <cli_server_sapi_module>) at /home/shyim/src/php-src/sapi/cli/php_cli_server.c:503
#13 0x0000555555ea7ada in main (argc=5, argv=0x555556db4270) at /home/shyim/src/php-src/sapi/cli/php_cli.c:1303
 [2020-11-04 15:18 UTC] nikic@php.net
-Status: Open +Status: Verified
 [2020-11-04 15:18 UTC] nikic@php.net
I've fixed a few more preloading bugs today, but it looks like this one is still failing. I get:

php: /home/nikic/php/php-8.0/ext/opcache/zend_persist.c:385: zend_persist_op_array_ex: Assertion `arg_info != ((void *)0)' failed.

Only when using the builtin server though, doesn't happen via cli.
 [2020-11-04 15:20 UTC] nikic@php.net
> Only when using the builtin server though, doesn't happen via cli.

Oh, that's because the preloader explicitly exits in that case ... removing that check, it does reproduce on cli.
 [2020-11-05 10:06 UTC] nikic@php.net
It looks like this is related to trait method fixup in some way. We end up overwriting the op_array for some trait methods with the op_array for a different trait method.
 [2020-11-05 10:33 UTC] nikic@php.net
Okay, I think I see what is happening now. The problem is that trait fixup can be performed multiple times on the same op_array if it is trivially inherited. Fixup looks up the opcodes in the xlat table and determines the primary op_array based on that.

Normally, fixing up the same op_array multiple times will work fine, because the later fixup will see the new opcodes pointer, which will not be in the xlat table. However, it can happen (and what happens in this case) is that the new opcodes pointer has the same address as the *original* opcodes of some other trait method, prior to reallocation, and as such is contained in the xlat table. Then we'll end up overwriting the trait method with a different, unrelated trait method.
 [2020-11-05 11:12 UTC] nikic@php.net
-Status: Verified +Status: Closed -Assigned To: +Assigned To: nikic
 [2020-11-05 14:04 UTC] michael dot zangerle at gmail dot com
To which PHP version as this fix applied? Because in the header and description it says 8.0.0RC ...
> PHP Version:	8.0.0RC3
> Tried my Symfony 5.1 project on PHP 8.0RC3, working in 7.4.

.. but in the example it says 7.4.
> Start web server 
> /opt/php-7.4/bin/php -S 0.0.0.0:7050 -t .
> curl localhost:7050 
> 
> => Segmentation fault...

The reason why I am asking is that I am experiencing the same problem with random trait methods being called (as described by nikic) with Symfony 5.1, preloading and PHP 7.4.12. I do not experience this with PHP 7.4.11.
 [2020-11-05 15:39 UTC] nikic@php.net
@michael: I've cherry-picked the fix to the PHP-7.4 branch with https://github.com/php/php-src/commit/6808968c896a18d2b9f309b2fe63d529058b78b4, as I do think it can occur there as well. This will be part of the PHP 7.4.13 release.
 [2020-11-13 11:42 UTC] php at shyim dot de
With the built from your Commit anything worked on my side. With RC4 now php-fpm even does not start. It stops with Exit Code 70. Is that known? I can share later a GDB Back trace
 [2020-11-13 11:48 UTC] php at shyim dot de
Ups. That happens when the preload file does not exists. I will create a new bug.
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Sun Dec 22 01:01:30 2024 UTC