Changes to when OPcache initialises

php.internals

Derick Rethans

7 years ago
Hi! I am working on making Xdebug work properly with PHP 7.3, and over the last week I have been tearing my hair out as to why Xdebug's view of opcodes was no longer showing the opcodes that OPcache had modified/optimised. In PHP 7.2, the order in which you load Xdebug and OPcache made a difference. OPcache optimises out line 6, which has dead code: 1 <?php 2 3 try 4 { 5 throw new Exception(); 6 echo strlen( "Revenge is a dish best served cold.\n" ); 7 } 8 catch(Exception $e) 9 { 10 } 11 12 echo strlen( "The fire is always hotter on someone elses face." ), "\n"; 13 ?> derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.2.13/bin/php -n -dzend_extension=opcache.so -d "zend_extension=xdebug.so" -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(4) { [5] => int(1) [8] => int(1) [12] => int(1) [14] => int(1) } [GIT: issue1598-no-code-coverage-with-opcache][PHP: 7.2.13 ] derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.2.13/bin/php -n -d "zend_extension=xdebug.so" -dzend_extension=opcache.so -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(5) { [5] => int(1) [6] => int(-2) [8] => int(1) [12] => int(1) [14] => int(1) } Where as with PHP 7.3.0, they both show the *unoptimised* version: derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.3.0/bin/php -n -dzend_extension=opcache.so -d "zend_extension=xdebug.so" -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(5) { [5] => int(1) [6] => int(-2) [8] => int(1) [12] => int(1) [14] => int(1) } [GIT: issue1598-no-code-coverage-with-opcache][PHP: 7.2.13 ] derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.3.0/bin/php -n -d "zend_extension=xdebug.so" -dzend_extension=opcache.so -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(5) { [5] => int(1) [6] => int(-2) [8] => int(1) [12] => int(1) [14] => int(1) } Curiously, vld, would always show the right (optimised) opcodes: filename: /home/derick/dev/php/derickr-xdebug/tests/bug00213.inc function name: (null) number of ops: 12 compiled vars: !0 = $e line #* E I O op fetch ext return operands ------------------------------------------------------------------------------------- 5 0 E > EXT_STMT 1 NEW $1 :-5 2 EXT_FCALL_BEGIN 3 DO_FCALL 0 4 EXT_FCALL_END 5 > THROW 0 $1 8 6 E > > CATCH 'Exception', !0 12 7 > EXT_STMT 8 ECHO 48 9 EXT_STMT 10 ECHO '%0A' 14 11 > RETURN 1 branch: # 0; line: 5- 5; sop: 0; eop: 5; out0: -2 branch: # 6; line: 8- 8; sop: 6; eop: 6; out0: 7; out1: -2 branch: # 7; line: 12- 14; sop: 7; eop: 11; out0: -2 path #1: 0, path #2: 6, 7, So I did some digging and found out that OPcache in PHP 7.3 has had a change to the loading order. This was done in: https://github.com/php/php-src/commit/b4903aef16ec215f2095ff0a3615524656401660: commit b4903aef16ec215f2095ff0a3615524656401660 Author: Dmitry Stogov <dmitry@zend.com> Date: Wed Oct 18 17:18:54 2017 +0300 Move a part of opcache initialization into post_startup phase (when all extensions already loaded). Both Xdebug and OPcache hook into zend_compile. In PHP 7.2, when as per documentation, OPcache was loaded after Xdebug, OPcache's zend_compile (accel_startup) was run *first*, so that Xdebug sees the optimised opcodes. In PHP 7.3, after the above commit, Xdebug's zend_compile hook (xdebug_compile_file) is run before OPcache's — *no matter which extension is loaded first*. Due to this, Xdebug can not properly do code coverage anymore when OPcache is also present, as it can only see *unoptimised* oparrays during its zend_compile hook. Because opcodes may now differ between when Xdebug analyses oparrays (zend_compile stage) and when it uses it (zend_execute stage) the results can be inconsistent in OPcache has optimised things away, and/or rearranged branches. Right now, I don't think I have a choice but to disallow code coverage analysis when OPcache is present, but I would prefer finding a solution to this so that OPcache and Xdebug work together again, as it did for PHP versions before 7.3. cheers, Derick
-- https://derickrethans.nl | https://xdebug.org | https://dram.io Like Xdebug? Consider a donation: https://xdebug.org/donate.php, or become my Patron: https://www.patreon.com/derickr twitter: @derickr and @xdebug

Dmitry Stogov

7 years ago
Hi Derick, First, check why VLD works out of the box. At second, you may plug into post_startup hook to reassign zend_compile after opcache. Thanks. Dmitry. ________________________________ From: Derick Rethans <derick@php.net> Sent: Saturday, December 15, 2018 10:01:37 PM To: Dmitry Stogov Cc: Nikita Popov; PHP Developers Mailing List Subject: Changes to when OPcache initialises Hi! I am working on making Xdebug work properly with PHP 7.3, and over the last week I have been tearing my hair out as to why Xdebug's view of opcodes was no longer showing the opcodes that OPcache had modified/optimised. In PHP 7.2, the order in which you load Xdebug and OPcache made a difference. OPcache optimises out line 6, which has dead code: 1 <?php 2 3 try 4 { 5 throw new Exception(); 6 echo strlen( "Revenge is a dish best served cold.\n" ); 7 } 8 catch(Exception $e) 9 { 10 } 11 12 echo strlen( "The fire is always hotter on someone elses face." ), "\n"; 13 ?> derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.2.13/bin/php -n -dzend_extension=opcache.so -d "zend_extension=xdebug.so" -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(4) { [5] => int(1) [8] => int(1) [12] => int(1) [14] => int(1) } [GIT: issue1598-no-code-coverage-with-opcache][PHP: 7.2.13 ] derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.2.13/bin/php -n -d "zend_extension=xdebug.so" -dzend_extension=opcache.so -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(5) { [5] => int(1) [6] => int(-2) [8] => int(1) [12] => int(1) [14] => int(1) } Where as with PHP 7.3.0, they both show the *unoptimised* version: derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.3.0/bin/php -n -dzend_extension=opcache.so -d "zend_extension=xdebug.so" -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(5) { [5] => int(1) [6] => int(-2) [8] => int(1) [12] => int(1) [14] => int(1) } [GIT: issue1598-no-code-coverage-with-opcache][PHP: 7.2.13 ] derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.3.0/bin/php -n -d "zend_extension=xdebug.so" -dzend_extension=opcache.so -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" 48 /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: array(5) { [5] => int(1) [6] => int(-2) [8] => int(1) [12] => int(1) [14] => int(1) } Curiously, vld, would always show the right (optimised) opcodes: filename: /home/derick/dev/php/derickr-xdebug/tests/bug00213.inc function name: (null) number of ops: 12 compiled vars: !0 = $e line #* E I O op fetch ext return operands ------------------------------------------------------------------------------------- 5 0 E > EXT_STMT 1 NEW $1 :-5 2 EXT_FCALL_BEGIN 3 DO_FCALL 0 4 EXT_FCALL_END 5 > THROW 0 $1 8 6 E > > CATCH 'Exception', !0 12 7 > EXT_STMT 8 ECHO 48 9 EXT_STMT 10 ECHO '%0A' 14 11 > RETURN 1 branch: # 0; line: 5- 5; sop: 0; eop: 5; out0: -2 branch: # 6; line: 8- 8; sop: 6; eop: 6; out0: 7; out1: -2 branch: # 7; line: 12- 14; sop: 7; eop: 11; out0: -2 path #1: 0, path #2: 6, 7, So I did some digging and found out that OPcache in PHP 7.3 has had a change to the loading order. This was done in: https://github.com/php/php-src/commit/b4903aef16ec215f2095ff0a3615524656401660: commit b4903aef16ec215f2095ff0a3615524656401660 Author: Dmitry Stogov <dmitry@zend.com> Date: Wed Oct 18 17:18:54 2017 +0300 Move a part of opcache initialization into post_startup phase (when all extensions already loaded). Both Xdebug and OPcache hook into zend_compile. In PHP 7.2, when as per documentation, OPcache was loaded after Xdebug, OPcache's zend_compile (accel_startup) was run *first*, so that Xdebug sees the optimised opcodes. In PHP 7.3, after the above commit, Xdebug's zend_compile hook (xdebug_compile_file) is run before OPcache's — *no matter which extension is loaded first*. Due to this, Xdebug can not properly do code coverage anymore when OPcache is also present, as it can only see *unoptimised* oparrays during its zend_compile hook. Because opcodes may now differ between when Xdebug analyses oparrays (zend_compile stage) and when it uses it (zend_execute stage) the results can be inconsistent in OPcache has optimised things away, and/or rearranged branches. Right now, I don't think I have a choice but to disallow code coverage analysis when OPcache is present, but I would prefer finding a solution to this so that OPcache and Xdebug work together again, as it did for PHP versions before 7.3. cheers, Derick
-- https://derickrethans.nl | https://xdebug.org | https://dram.io Like Xdebug? Consider a donation: https://xdebug.org/donate.php, or become my Patron: https://www.patreon.com/derickr twitter: @derickr and @xdebug

Derick Rethans

7 years ago
Hi, VLD is not a zend extension, so gets loaded/initialised later anyway. And it seems your hint with post_startup works. I'd appreciate if you could have a look at my change though: https://github.com/xdebug/xdebug/commit/3ef3c63ffc831426a45439dbf8b56b998f84d5b1 cheers, Derick On Mon, 17 Dec 2018, Dmitry Stogov wrote:
> Hi Derick, > > > First, check why VLD works out of the box. > > At second, you may plug into post_startup hook to reassign zend_compile after opcache. > > > Thanks. Dmitry. > > ________________________________ > From: Derick Rethans <derick@php.net> > Sent: Saturday, December 15, 2018 10:01:37 PM > To: Dmitry Stogov > Cc: Nikita Popov; PHP Developers Mailing List > Subject: Changes to when OPcache initialises > > Hi! > > I am working on making Xdebug work properly with PHP 7.3, and over the > last week I have been tearing my hair out as to why Xdebug's view of > opcodes was no longer showing the opcodes that OPcache had > modified/optimised. In PHP 7.2, the order in which you load Xdebug and > OPcache made a difference. > > OPcache optimises out line 6, which has dead code: > > 1 <?php > 2 > 3 try > 4 { > 5 throw new Exception(); > 6 echo strlen( "Revenge is a dish best served cold.\n" ); > 7 } > 8 catch(Exception $e) > 9 { > 10 } > 11 > 12 echo strlen( "The fire is always hotter on someone elses face." ), "\n"; > 13 ?> > > > derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.2.13/bin/php -n -dzend_extension=opcache.so -d "zend_extension=xdebug.so" -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" > 48 > /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: > array(4) { > [5] => > int(1) > [8] => > int(1) > [12] => > int(1) > [14] => > int(1) > } > > [GIT: issue1598-no-code-coverage-with-opcache][PHP: 7.2.13 ] > derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.2.13/bin/php -n -d "zend_extension=xdebug.so" -dzend_extension=opcache.so -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" > 48 > /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: > array(5) { > [5] => > int(1) > [6] => > int(-2) > [8] => > int(1) > [12] => > int(1) > [14] => > int(1) > } > > Where as with PHP 7.3.0, they both show the *unoptimised* version: > > derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.3.0/bin/php -n -dzend_extension=opcache.so -d "zend_extension=xdebug.so" -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" > 48 > /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: > array(5) { > [5] => > int(1) > [6] => > int(-2) > [8] => > int(1) > [12] => > int(1) > [14] => > int(1) > } > [GIT: issue1598-no-code-coverage-with-opcache][PHP: 7.2.13 ] > derick@singlemalt:~/dev/php/derickr-xdebug $ /usr/local/php/7.3.0/bin/php -n -d "zend_extension=xdebug.so" -dzend_extension=opcache.so -d "opcache.enable=1" -d "opcache.enable_cli=1" -d "xdebug.extended_info=1" -dvld.active=1 -f "/home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php" > 48 > /home/derick/dev/php/derickr-xdebug/tests/bug00213-php73-opcache.php:7: > array(5) { > [5] => > int(1) > [6] => > int(-2) > [8] => > int(1) > [12] => > int(1) > [14] => > int(1) > } > > Curiously, vld, would always show the right (optimised) opcodes: > > filename: /home/derick/dev/php/derickr-xdebug/tests/bug00213.inc > function name: (null) > number of ops: 12 > compiled vars: !0 = $e > line #* E I O op fetch ext return operands > ------------------------------------------------------------------------------------- > 5 0 E > EXT_STMT > 1 NEW $1 :-5 > 2 EXT_FCALL_BEGIN > 3 DO_FCALL 0 > 4 EXT_FCALL_END > 5 > THROW 0 $1 > 8 6 E > > CATCH 'Exception', !0 > 12 7 > EXT_STMT > 8 ECHO 48 > 9 EXT_STMT > 10 ECHO '%0A' > 14 11 > RETURN 1 > > branch: # 0; line: 5- 5; sop: 0; eop: 5; out0: -2 > branch: # 6; line: 8- 8; sop: 6; eop: 6; out0: 7; out1: -2 > branch: # 7; line: 12- 14; sop: 7; eop: 11; out0: -2 > path #1: 0, > path #2: 6, 7, > > > So I did some digging and found out that OPcache in PHP 7.3 has had a change > to the loading order. This was done in: > https://github.com/php/php-src/commit/b4903aef16ec215f2095ff0a3615524656401660: > > commit b4903aef16ec215f2095ff0a3615524656401660 > Author: Dmitry Stogov <dmitry@zend.com> > Date: Wed Oct 18 17:18:54 2017 +0300 > > Move a part of opcache initialization into post_startup phase (when all extensions already loaded). > > Both Xdebug and OPcache hook into zend_compile. In PHP 7.2, when as per > documentation, OPcache was loaded after Xdebug, OPcache's zend_compile > (accel_startup) was run *first*, so that Xdebug sees the optimised > opcodes. > > In PHP 7.3, after the above commit, Xdebug's zend_compile hook > (xdebug_compile_file) is run before OPcache's — *no matter which > extension is loaded first*. Due to this, Xdebug can not properly do code > coverage anymore when OPcache is also present, as it can only see > *unoptimised* oparrays during its zend_compile hook. > > Because opcodes may now differ between when Xdebug analyses oparrays > (zend_compile stage) and when it uses it (zend_execute stage) the > results can be inconsistent in OPcache has optimised things away, and/or > rearranged branches. > > Right now, I don't think I have a choice but to disallow code coverage > analysis when OPcache is present, but I would prefer finding a solution > to this so that OPcache and Xdebug work together again, as it did for > PHP versions before 7.3. > > cheers, > Derick > > -- > https://derickrethans.nl | https://xdebug.org | https://dram.io > Like Xdebug? Consider a donation: https://xdebug.org/donate.php, > or become my Patron: https://www.patreon.com/derickr > twitter: @derickr and @xdebug >
-- https://derickrethans.nl | https://xdebug.org | https://dram.io Like Xdebug? Consider a donation: https://xdebug.org/donate.php, or become my Patron: https://www.patreon.com/derickr twitter: @derickr and @xdebug

Dmitry Stogov

7 years ago
Looks fine. On 12/24/18 12:17 AM, Derick Rethans wrote: