Reproducible crash in PHP 8.4 with JIT and Excimer

[tstarling]

Description

• Download MediaWiki e.g. from https://releases.wikimedia.org/mediawiki/1.42/mediawiki-core-1.42.1.tar.gz
• cd mediawiki-1.42.1
• Install PHP 8.4 or git master with excimer and the extensions listed in composer.json
• Install MediaWiki e.g. with

php8.4 maintenance/run.php install --dbname=mw_installtest --dbserver=localhost --dbuser=user --dbpass=pass --pass=$(md5sum README.md) installtest Admin

Create the file phptest.php:

<?php
$excimer = new ExcimerProfiler;
$excimer->setPeriod( 0.001 );
$excimer->setEventType( EXCIMER_REAL );
$excimer->start();

require 'index.php';

Run the script repeatedly with the tracing JIT:

SCRIPT_NAME=index.php REMOTE_ADDR=1.2.3.4 /usr/lib/cgi-bin/php8.4 -T1000 -dextension=excimer.so -dopcache.jit=on phptest.php > /dev/null

It crashes with:

zend_mm_heap corrupted
Aborted (core dumped)

Building with AddressSanitizer, it always crashes in AutoLoader::find() due to an incorrect reference count on $prefix leading to it being freed while still in use.

In gdb, use set print thread-events off since Excimer is creating 1000 threads per second.

This is not an excimer bug. I'm pretty sure. Excimer is just a way to randomly set EG(vm_interrupt), which exercises some otherwise unusual exits in the JITed code of this function. It still crashes with the whole interrupt handler disabled:

diff --git a/excimer_timer.c b/excimer_timer.c
index 83bf42a..36e4289 100644
--- a/excimer_timer.c
+++ b/excimer_timer.c
@@ -239,6 +239,7 @@ static void excimer_timer_handle(union sigval sv)
 
 static void excimer_timer_interrupt(zend_execute_data *execute_data)
 {
+       return;
        zend_long id;
        zval *zp_count;
        HashTable *event_counts;

I mean, it is Excimer-related, and I as an Excimer maintainer am trying to fix it. But I'm getting deep into the JIT internals and that's probably where the bug is.

The bug is new in 8.4, I could not reproduce it in 8.3.

PHP Version

8.4.0alpha4

Operating System

Ubuntu 22.04

[cmb69]

The bug is new in 8.4, I could not reproduce it in 8.3.

Might be caused by the new IR JIT implementation.

[tstarling]

In slightly different conditions to the reproduction procedure above, the error always occurs with return address 0x48000d29, which is the zif_strrpos() call in TRACE-1$AutoLoader::find$181. Always that first trace out of hundreds.

The string's refcount is not off by one, it's garbage, like a billion, and yet the string has the right value in it.

AddressSanitizer shows a use after free, but the backtrace for the allocation is distant and random. Often it fails with an assertion while trying to print the backtrace.

[iluuu1994]

/cc @dstogov

[tstarling]

I think I've got it pretty well isolated.

I reduced the test code by making a tight loop of Autoloader::find() calls instead of running the whole of MediaWiki.

The bug does not seem to happen when opcache.jit_max_side_traces=0.

There are three relevant traces:

• TRACE-1: the root trace representing the while() at line 181
• TRACE-111: the if( isset() ) body at line 185
• TRACE-125: the if( is_file() ) at line 191

Code with line numbers for reference:

181:			while ( ( $pos = strrpos( $prefix, '\\' ) ) !== false ) {
182:				// Check to see if this namespace prefix is in the map
183:				$prefix = substr( $className, 0, $pos + 1 );
184:				if ( isset( self::$psr4Namespaces[$prefix] ) ) {
185:					$relativeClass = substr( $className, $pos + 1 );
186:					// Build the expected filename, and see if it exists
187:					$file = self::$psr4Namespaces[$prefix] .
188:						'/' .
189:						strtr( $relativeClass, '\\', '/' ) .
190:						'.php';
191:					if ( is_file( $file ) ) {
192:						$filename = $file;
193:						break;
194:					}
195:				}
196:
197:				// Remove trailing separator for next iteration
198:				$prefix = rtrim( $prefix, '\\' );
199:			}

The bug occurs when EG(vm_interrupt) is set leading to TRACE-125 exit 3. A debug message is not emitted in that case, but I fixed that so that we see:

     TRACE 125 exit 3 AutoLoader::find() /srv/mw/core/includes/AutoLoader.php:198

The interrupt handler stub is then called, but the opline is wrong. It returns to the VM, but execution resumes at the ZEND_ASSIGN op on line 198, not at the rtrim() call. Both operands of the ZEND_ASSIGN at this point refer to the same string ($prefix). The ZEND_ASSIGN handler decrements the reference count of $prefix, causing it to be freed. Then the loop continues, re-entering TRACE-1 and crashing in strrpos().

[tstarling]

I think the zend_jit_check_timeout() call in zend_jit_trace_link_to_root() is at fault. Commenting it out seems to fix the issue. It passes NULL for opline but presumably should pass whatever the right answer is.

[dstogov]

@tstarling Can you please check, if the following patch fixes the problem.

diff --git a/ext/opcache/jit/zend_jit_ir.c b/ext/opcache/jit/zend_jit_ir.c
index bb0caf477e5..b31c66016dd 100644
--- a/ext/opcache/jit/zend_jit_ir.c
+++ b/ext/opcache/jit/zend_jit_ir.c
@@ -16729,7 +16729,7 @@ static int zend_jit_trace_link_to_root(zend_jit_ctx *jit, zend_jit_trace_info *t
 	link_addr = (const void*)((const char*)t->code_start + zend_jit_trace_prologue_size);
 
 	if (timeout_exit_addr) {
-		zend_jit_check_timeout(jit, NULL, timeout_exit_addr);
+		zend_jit_check_timeout(jit, t->opline, timeout_exit_addr);
 	}
 	ir_IJMP(ir_CONST_ADDR(link_addr));

[dstogov]

No, my patch is wrong. The opline passed to zend_jit_check_timeout() doesn't matter when exit_addr is passed.

The target opline should be set by deoptimization process.
The corresponding deoptimization info is created here https://github.com/php/php-src/blob/master/ext/opcache/jit/zend_jit_trace.c#L7162 and these lines exactly the same in PHP_8_3.

[dstogov]

TRACE 125 exit 3 AutoLoader::find() /srv/mw/core/includes/AutoLoader.php:198

The interrupt handler stub is then called, but the opline is wrong. It returns to the VM, but execution resumes at the ZEND_ASSIGN op on line 198, not at the rtrim() call. Both operands of the ZEND_ASSIGN at this point refer to the same string ($prefix). The ZEND_ASSIGN handler decrements the reference count of $prefix, causing it to be freed. Then the loop continues, re-entering TRACE-1 and crashing in strrpos().

Can you check the deoptimization info for TRACE-125 exit 3 is correct? (it should be printed after TRACE-125 disassemble with opcache.jit_debug=0x1ff001) e.g exit_3: XXXX/... where XXX is the target opline number. It should be the same as the first opline of the root trace.

[dstogov]

@bwoebi @morrisonlevi may be you have any ideas about the reason of failure.