User stream filter segfault in uopz_find_return during request shutdown

[rlerdorf]

#0  0x00007f2539573387 in raise () at /lib64/libc.so.6
#1  0x00007f2539574bb8 in abort () at /lib64/libc.so.6
#2  0x00007f252a17b8a8 in  () at /lib64/libGraphicsMagick-Q8.so.3
#3  0x00007f2539573400 in <signal handler called> () at /lib64/libc.so.6
#4  0x000000000088e552 in zend_hash_index_find (h=0, ht=0x7f253566f5a8 <uopz_globals+8>) at /usr/src/debug/php-src-php-8.0.9/Zend/zend_hash.c:715
#5  0x000000000088e552 in zend_hash_index_find (ht=ht@entry=0x7f253566f5a8 <uopz_globals+8>, h=h@entry=0) at /usr/src/debug/php-src-php-8.0.9/Zend/zend_hash.c:2288
#6  0x00007f25354689ba in uopz_find_return (h=0, ht=<optimized out>) at /usr/include/php8/Zend/zend_hash.h:880
#7  0x00007f25354689ba in uopz_find_return (function=<optimized out>) at /builddir/build/BUILD/uopz-7.1.0/src/return.c:138
#8  0x00007f253546b96a in uopz_vm_do_call_common (execute_data=0x7f2535c14020) at /builddir/build/BUILD/uopz-7.1.0/src/handlers.c:418
#9  0x00000000008db7e9 in ZEND_USER_OPCODE_SPEC_HANDLER () at /usr/src/debug/php-src-php-8.0.9/Zend/zend_vm_execute.h:2984
#10 0x00000000008dc415 in execute_ex (ex=0x7f253566f5a8 <uopz_globals+8>) at /usr/src/debug/php-src-php-8.0.9/Zend/zend_vm_execute.h:54636
#11 0x000000000086d2b0 in zend_call_function (fci=fci@entry=0x7ffcee17ac60, fci_cache=0x7ffcee17aba0, fci_cache@entry=0x0)
    at /usr/src/debug/php-src-php-8.0.9/Zend/zend_execute_API.c:895
#12 0x000000000086d902 in _call_user_function_impl (object=object@entry=0x7f24f1ab15a8, function_name=function_name@entry=0x7ffcee17ace0, retval_ptr=retval_ptr@entry=0x7ffcee17acf0, param_count=param_count@entry=4, params=params@entry=0x7ffcee17ad00, named_params=named_params@entry=0x0) at /usr/src/debug/php-src-php-8.0.9/Zend/zend_execute_API.c:659
#13 0x00000000007ca1e2 in userfilter_filter (stream=<optimized out>, thisfilter=0x7f24f1ab15a0, buckets_in=0x7ffcee17adb0, buckets_out=0x7ffcee17adc0, bytes_consumed=0x7ffcee17ada0, flags=<optimized out>) at /usr/src/debug/php-src-php-8.0.9/ext/standard/user_filters.c:198
#14 0x000000000082a614 in _php_stream_write_filtered (stream=stream@entry=0x7f24f12099a0, buf=buf@entry=0x0, count=count@entry=0, flags=2)
    at /usr/src/debug/php-src-php-8.0.9/main/streams/streams.c:1180
#15 0x000000000082bf44 in _php_stream_flush (stream=0x7f24f12099a0, closing=<optimized out>) at /usr/src/debug/php-src-php-8.0.9/main/streams/streams.c:1232
#16 0x000000000082c098 in _php_stream_free (stream=<optimized out>, close_options=11) at /usr/src/debug/php-src-php-8.0.9/main/streams/streams.c:448
#17 0x000000000082c3b2 in stream_resource_regular_dtor (rsrc=<optimized out>) at /usr/src/debug/php-src-php-8.0.9/main/streams/streams.c:1662
#18 0x000000000088f2ee in zend_resource_dtor (res=<optimized out>) at /usr/src/debug/php-src-php-8.0.9/Zend/zend_list.c:72
#19 0x000000000088f8a9 in zend_close_rsrc_list (ht=<optimized out>) at /usr/src/debug/php-src-php-8.0.9/Zend/zend_list.c:220
#20 0x000000000086bab9 in shutdown_executor () at /usr/src/debug/php-src-php-8.0.9/Zend/zend_execute_API.c:272
#21 0x000000000087afa5 in zend_deactivate () at /usr/src/debug/php-src-php-8.0.9/Zend/zend.c:1225
#22 0x0000000000813abb in php_request_shutdown (dummy=dummy@entry=0x0) at /usr/src/debug/php-src-php-8.0.9/main/main.c:1838
#23 0x000000000090b299 in do_cli (argc=12, argv=0x2ad4ac0) at /usr/src/debug/php-src-php-8.0.9/sapi/cli/php_cli.c:1111
#24 0x00000000004754da in main (argc=12, argv=0x2ad4ac0) at /usr/src/debug/php-src-php-8.0.9/sapi/cli/php_cli.c:1337

Here is an interesting backtrace. Ignore the top 4 frames. It is the annoying signal handler in libGraphicsMagick, but it isn't affecting the outcome here.

I don't have a small reproduce case yet, but looking at the backtrace, could this be a shutdown order thing? On request shutdown it is trying to close and flush a stream with a userspace filter function. In userspace the crash happens on the stream_bucket_make_writeable() call in this:

<?php
declare(strict_types=1);

/**
 * The OpenCensus\Trace\Exporter\StackdriverExporter internally captures all exceptions,
 * and only provides debug output via a writeable stream. Additionally, it registers its own
 * shutdown functions, so we cannot simply provide it with a temp stream and dump the contents
 * later (because it will always register a shutdown function *after* our own shutdown
 * function is registered).
 *
 * To get around this, we can use this custom stream filter to capture all data written to
 * the debug stream and handle it with a custom callback.
 */
class OpenCensusDebugFilter extends php_user_filter {

    /**
     * @var callable $handler
     */
    private static $handler;

    /**
     * Set the handler function for consuming debug messages.
     *
     * @param callable $handler Callable accepting a single string parameter
     */
    public static function setHandler(callable $handler) : void {
        self::$handler = $handler;
    }

    /**
     * @param resource $in       Unfiltered bucket brigade
     * @param resource $out      Filtered bucket brigade
     * @param int      $consumed Length of data that has been read
     * @param bool     $closing  Whether the stream is closing and this is the final invocation
     */
    public function filter($in, $out, &$consumed, $closing) {
        try {
            // Black-hole inbound data and invoke the handler if it has been set
            while ($bucket = stream_bucket_make_writeable($in)) {
                $consumed += $bucket->datalen;

                if (is_string($bucket->data) && is_callable(self::$handler)) {
                    (self::$handler)($bucket->data);
                }
            }

            return PSFS_PASS_ON;
        } catch (Throwable $e) {
            return PSFS_ERR_FATAL;
        }
    }
}

[cmb69]

This might be related to https://bugs.php.net/bug.php?id=75931.

[rlerdorf]

That does seem related, although this doesn't crash under PHP 7.3 + uopz.

[rlerdorf]

This obvious and rather crude fix prevents the segfault:

diff --git a/src/return.c b/src/return.c
index baf59ed..16bd2c2 100644
--- a/src/return.c
+++ b/src/return.c
@@ -132,6 +132,10 @@ uopz_return_t* uopz_find_return(zend_function *function) { /* {{{ */
                return NULL;
        }
 
+       if ((EG(flags) & EG_FLAGS_IN_SHUTDOWN)) {
+               return NULL;
+       }
+
        if (function->common.scope) {
                returns = zend_hash_find_ptr(&UOPZ(returns), function->common.scope->name);
        } else {

Is there a better way? That hashtable is no longer around at the point we hit this user filter callback, so trying to look up return overrides at that point won't work.

[krakjoe]

I think that's the best we can do, committed to both hook and return code, thanks.