Segfault with observer API on max execution time during php -r

[rioderelfte]

Description

The following command:

sapi/cli/php -n \
    -d 'max_execution_time=1' \
    -d 'zend_test.observer.enabled=1' \
    -d 'zend_test.observer.observe_all=1' \
    -r 'echo "test\n"; crc32("test"); for (;;) {}'

Resulted in this output:

<!-- init 'Command line code' -->
<file 'Command line code'>
test

Fatal error: Maximum execution time of 1 second exceeded in Command line code on line 1
zsh: bus error  sapi/cli/php -n -d 'max_execution_time=1' -d 'zend_test.observer.enabled=1' -

The execution results in a bus error instead of a segmentation fault, since the address which is jumped to is not properly aligned. While debugging this I also saw segmentation faults from time to time.

I expect neither a bus error nor a segmentation fault to occur, when executing that command.

Here is the output of lldb:

(lldb) run
Process 92890 launched: '/Users/florian/projects/php/php-src/sapi/cli/php' (arm64)
<!-- init 'Command line code' -->
<file 'Command line code'>
test

Fatal error: Maximum execution time of 1 second exceeded in Command line code on line 1
Process 92890 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=257, address=0x800000017c9e6865)
    frame #0: 0xffff80017c9e6865
error: memory read failed for 0xffff80017c9e6800
Target 0: (php) stopped.
(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=257, address=0x800000017c9e6865)
  * frame #0: 0xffff80017c9e6865
    frame #1: 0x00000001002a9ee0 php`zend_observer_fcall_end(execute_data=0x0000000101212020, return_value=0x0000000000000000) at zend_observer.c:220:3 [opt]
    frame #2: 0x00000001002a9fdc php`zend_observer_fcall_end_all at zend_observer.c:240:4 [opt]
    frame #3: 0x0000000100192a54 php`php_request_shutdown(dummy=0x0000000000000000) at main.c:1798:3 [opt]
    frame #4: 0x00000001002f1a54 php`do_cli(argc=10, argv=0x0000600002600120) at php_cli.c:1135:3 [opt]
    frame #5: 0x00000001002f0114 php`main(argc=<unavailable>, argv=<unavailable>) at php_cli.c:1367:18 [opt]
    frame #6: 0x00000001005ad088 dyld`start + 516
(lldb) frame select 1
php was compiled with optimization - stepping may behave oddly; variables may not be available.
frame #1: 0x00000001002a9ee0 php`zend_observer_fcall_end(execute_data=0x0000000101212020, return_value=0x0000000000000000) at zend_observer.c:220:3 [opt]
   217
   218          zend_observer_fcall_end_handler *possible_handlers_end = handler + zend_observers_fcall_list.count;
   219          do {
-> 220                  (*handler)(execute_data, return_value);
   221          } while (++handler != possible_handlers_end && *handler != NULL);
   222
   223          if (first_observed_frame == execute_data) {

The output was generated on the current PHP-8.1 branch (commit dd89aca).

So far I only was able to reproduce the problem with php -r – not by executing a PHP file.

PHP Version

PHP 8.1.7

Operating System

Mac OS X 12.3.1 (ARM)

[rioderelfte]

And here is the lldb output with debug symbols:

(lldb) run
Process 38508 launched: '/Users/florian/projects/php/php-src/sapi/cli/php' (arm64)
<!-- init 'Command line code' -->
<file 'Command line code'>
test

Fatal error: Maximum execution time of 1 second exceeded in Command line code on line 1
Process 38508 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=257, address=0x800000017c9e6865)
    frame #0: 0xffff80017c9e6865
error: memory read failed for 0xffff80017c9e6800
Target 0: (php) stopped.
(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=257, address=0x800000017c9e6865)
  * frame #0: 0xffff80017c9e6865
    frame #1: 0x00000001004c0f9c php`zend_observer_fcall_end(execute_data=0x0000000102013020, return_value=0x0000000000000000) at zend_observer.c:220:3
    frame #2: 0x00000001004c1204 php`zend_observer_fcall_end_all at zend_observer.c:240:4
    frame #3: 0x00000001002df510 php`php_request_shutdown(dummy=0x0000000000000000) at main.c:1798:3
    frame #4: 0x0000000100542834 php`do_cli(argc=10, argv=0x00006000026080c0) at php_cli.c:1135:3
    frame #5: 0x0000000100541238 php`main(argc=10, argv=0x00006000026080c0) at php_cli.c:1367:18
    frame #6: 0x0000000100899088 dyld`start + 516
(lldb) frame select 1
frame #1: 0x00000001004c0f9c php`zend_observer_fcall_end(execute_data=0x0000000102013020, return_value=0x0000000000000000) at zend_observer.c:220:3
   217
   218          zend_observer_fcall_end_handler *possible_handlers_end = handler + zend_observers_fcall_list.count;
   219          do {
-> 220                  (*handler)(execute_data, return_value);
   221          } while (++handler != possible_handlers_end && *handler != NULL);
   222
   223          if (first_observed_frame == execute_data) {
(lldb) print *handler
(zend_observer_fcall_end_handler) $0 = 0x800000017c9e6865

[iluuu1994]

Can't reproduce this on Linux (Fedora), might be a MacOS issue.

Edit: Actually I can reproduce it. I forgot to enable zend_test.

[jjones-smug]

For what it's worth, we were also seeing the same issue, but running PHP 7.4.20 on Ubuntu Bionic.

[bwoebi]

I had an idea about that today: we could allocate currently stack allocated execute_data on an arena and checkpoint that, and swap that arena and vm_stack on bailout, so that we never invalidate that memory.

[devnexen]

I can reproduce the error on my mac M1 with this release but not on master.

[bwoebi]

@devnexen It's a "chance" thing. Sometimes your stack memory happens to be overwritten, sometimes not, depending on where exactly on the stack things were pointing to etc.. If you tweak things enough, you'll be able to trigger such a crash on all versions.