PHP 8.1.16 segfaults on line 597 of sapi/apache2handler/sapi_apache2.c

[ElliotNB]

Description

I apologize in advance for the low quality issue report. I'm hoping that someone can point me in the right direction on next steps for completing a more detailed analysis.

I am running Apache 2.4.54 mpm_event with PHP 8.1.16 on a CentOS 8 Stream machine. When we gradually introduce production traffic load to this server, it begins to segfault every 25-45 minutes. I've been unable to find any correlation between the PHP code being executed and the segmentation faults. There is no particular request or script that reliably triggers a segmentation fault.

I captured core dumps for the segfaults and ran them through gdb. gdb produced the following traces. I also ran valgrind in an attempt to capture debug info on memory problems (see below).

(gdb) bt
#0  0x00007fb84f317161 in php_handler (r=0x7fb7582003b8)
    at /usr/src/debug/php-8.1.16-1.el8.x86_64/sapi/apache2handler/sapi_apache2.c:597
#1  0x0000557a01527f38 in ap_run_handler (r=r@entry=0x7fb7582003b8) at config.c:169
#2  0x0000557a015284f6 in ap_invoke_handler (r=r@entry=0x7fb7582003b8) at config.c:443
#3  0x0000557a0153e1ec in ap_internal_redirect (new_uri=<optimized out>, r=<optimized out>) at http_request.c:790
#4  0x00007fb84fb12a69 in handler_redirect (r=0x7fb7581f8c80) at mod_rewrite.c:5293
#5  0x0000557a01527f38 in ap_run_handler (r=r@entry=0x7fb7581f8c80) at config.c:169
#6  0x0000557a015284f6 in ap_invoke_handler (r=r@entry=0x7fb7581f8c80) at config.c:443
#7  0x0000557a0153eed3 in ap_process_async_request (r=0x7fb7581f8c80) at http_request.c:452
#8  0x0000557a0153f042 in ap_process_request (r=r@entry=0x7fb7581f8c80) at http_request.c:487
#9  0x00007fb85139bb76 in h2_task_process_request (c=0x7fb758194300, task=<optimized out>) at h2_task.c:671
#10 h2_task_process_conn (c=0x7fb758194300) at h2_task.c:713
#11 h2_task_process_conn (c=0x7fb758194300) at h2_task.c:700
#12 0x0000557a01531a08 in ap_run_process_connection (c=c@entry=0x7fb758194300) at connection.c:42
#13 0x00007fb85139ced7 in h2_task_do (task=0x7fb75824d210, thread=thread@entry=0x557a02546cc8, worker_id=<optimized out>) at h2_task.c:631
#14 0x00007fb8513a0c80 in slot_run (thread=0x557a02546cc8, wctx=0x557a02557700) at h2_workers.c:263
#15 0x00007fb85622b1ca in start_thread () from /lib64/libpthread.so.0
#16 0x00007fb855c93e73 in clone () from /lib64/libc.so.6

Thread 703 "httpd" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fb7bc9ff700 (LWP 31768)]
0x00007fb84f317161 in php_handler (r=0x7fb7582003b8)
    at /usr/src/debug/php-8.1.16-1.el8.x86_64/sapi/apache2handler/sapi_apache2.c:597
597             ctx = SG(server_context);
(gdb) bt full
#0  0x00007fb84f317161 in php_handler (r=0x7fb7582003b8)
    at /usr/src/debug/php-8.1.16-1.el8.x86_64/sapi/apache2handler/sapi_apache2.c:597
        ctx = 0x557a02269ef8
        conf = 0x557a0222e230
        brigade = 0x0
        bucket = 0x7fb758201918
        rv = 0
        parent_req = 0x0
#1  0x0000557a01527f38 in ap_run_handler (r=r@entry=0x7fb7582003b8) at config.c:169
        pHook = <optimized out>
        n = 7
        rv = -1
#2  0x0000557a015284f6 in ap_invoke_handler (r=r@entry=0x7fb7582003b8) at config.c:443
        handler = <optimized out>
        p = <optimized out>
        result = 0
        old_handler = 0x0
        ignore = <optimized out>
#3  0x0000557a0153e1ec in ap_internal_redirect (new_uri=<optimized out>, r=<optimized out>) at http_request.c:790
        access_status = <optimized out>
        new = 0x7fb7582003b8
#4  0x00007fb84fb12a69 in handler_redirect (r=0x7fb7581f8c80) at mod_rewrite.c:5293
No locals.
#5  0x0000557a01527f38 in ap_run_handler (r=r@entry=0x7fb7581f8c80) at config.c:169
        pHook = <optimized out>
        n = 6
        rv = -1
#6  0x0000557a015284f6 in ap_invoke_handler (r=r@entry=0x7fb7581f8c80) at config.c:443
        handler = <optimized out>
        p = <optimized out>
        result = 0
        old_handler = 0x7fb84fb1a44a "redirect-handler"
        ignore = <optimized out>
#7  0x0000557a0153eed3 in ap_process_async_request (r=0x7fb7581f8c80) at http_request.c:452
        c = <optimized out>
        access_status = 0
#8  0x0000557a0153f042 in ap_process_request (r=r@entry=0x7fb7581f8c80) at http_request.c:487
        bb = 0x0
        b = <optimized out>
        c = 0x7fb758194300
        rv = <optimized out>
#9  0x00007fb85139bb76 in h2_task_process_request (c=0x7fb758194300, task=<optimized out>) at h2_task.c:671
        req = <optimized out>
        cs = 0x7fb758194998
        r = 0x7fb7581f8c80
        req = <optimized out>
        cs = <optimized out>
        r = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
#10 h2_task_process_conn (c=0x7fb758194300) at h2_task.c:713
        ctx = <optimized out>
        ctx = <optimized out>
#11 h2_task_process_conn (c=0x7fb758194300) at h2_task.c:700
        ctx = <optimized out>
#12 0x0000557a01531a08 in ap_run_process_connection (c=c@entry=0x7fb758194300) at connection.c:42
        pHook = <optimized out>
        n = 1
        rv = -1
#13 0x00007fb85139ced7 in h2_task_do (task=0x7fb75824d210, thread=thread@entry=0x557a02546cc8, worker_id=<optimized out>) at h2_task.c:631
        c = 0x7fb758194300
#14 0x00007fb8513a0c80 in slot_run (thread=0x557a02546cc8, wctx=0x557a02557700) at h2_workers.c:263
        slot = 0x557a02557700
#15 0x00007fb85622b1ca in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#16 0x00007fb855c93e73 in clone () from /lib64/libc.so.6
No symbol table info available.

The trace ends at line 597 of sapi/apache2handler/sapi_apache2.c which contains this line: ctx = SG(server_context); in this block of code:

#define PHPAP_INI_OFF php_apache_ini_dtor(r, parent_req);

        conf = ap_get_module_config(r->per_dir_config, &php_module);

        /* apply_config() needs r in some cases, so allocate server_context early */
        ctx = SG(server_context);
        if (ctx == NULL || (ctx && ctx->request_processed && !strcmp(r->protocol, "INCLUDED"))) {
normal:
                ctx = SG(server_context) = apr_pcalloc(r->pool, sizeof(*ctx));
                /* register a cleanup so we clear out the SG(server_context)
                 * after each request. Note: We pass in the pointer to the
                 * server_context in case this is handled by a different thread.
                 */
                apr_pool_cleanup_register(r->pool, (void *)&SG(server_context), php_server_context_cleanup, apr_pool_cleanup_null);
                ctx->r = r;
                ctx = NULL; /* May look weird to null it here, but it is to catch the right case in the first_try later on */
        } else {
                parent_req = ctx->r;
                ctx->r = r;
        }
        apply_config(conf);

I'm guessing that this isn't enough information to figure out what's going on. Could anyone recommend next steps for troubleshooting this?

PHP Version

8.1.16

configure line:

./configure --prefix=/usr/local --enable-fpm --disable-fileinfo --enable-bcmath --enable-calendar --with-libxml --enable-soap --enable-mbstring --enable-pdo --enable-sockets --with-zip --with-apxs2=/usr/local/apache/bin/apxs --with-bz2 --with-curl=/usr/local --with-gettext --with-libdir=lib64 --with-openssl=/usr --with-openssl-dir=/usr --with-pdo-pgsql=/usr/pgsql-11 --with-pgsql=/usr/pgsql-11 --with-pic --with-zlib --with-zlib-dir=/usr --enable-opcache --enable-debug --enable-gd --with-jpeg PKG_CONFIG_PATH=:/usr/local/lib/pkgconfig:/usr/local/bin/pkgconfig

Dynamically loaded extensions:

zend_extension=/usr/local/lib/php/extensions/debug-zts-20210902/opcache.so
opcache.memory_consumption=256
opcache.interned_strings_buffer=16
opcache.max_accelerated_files=5000
opcache.revalidate_freq=0
;opcache.validate_timestamps=1
opcache.fast_shutdown=1

extension=/usr/local/lib/php/extensions/debug-zts-20210902/memcached.so;

We experimented with disabling Zend opcache, but the segfaults persisted.

Operating System

CentOS 8 Stream

[ElliotNB]

Just a little bit more information... I launched my Apache/PHP with valgrind to see if I could identify the source of any memory problems.

I don't understand these valgrind logs very well, but I'm seeing lots of traces point back to line 426 of zend_string.c (see below). The trace differs, but the final file and line number always remain the same.

Does this indicate that anything is amiss?

==210750== Thread 26:
==210750== Conditional jump or move depends on uninitialised value(s)
==210750==    at 0xD469860: zend_string_equal_val (zend_string.c:426)
==210750==    by 0x128173D6: zend_string_equal_content (zend_string.h:355)
==210750==    by 0x12817418: zend_string_equals (zend_string.h:360)
==210750==    by 0x1281D2D0: cache_script_in_shared_memory (ZendAccelerator.c:1632)
==210750==    by 0x128200AA: persistent_compile_file (ZendAccelerator.c:2175)
==210750==    by 0xD3C96D1: zend_include_or_eval (zend_execute.c:4791)
==210750==    by 0xD3D9A95: ZEND_INCLUDE_OR_EVAL_SPEC_CONST_HANDLER (zend_vm_execute.h:4869)
==210750==    by 0xD4484E1: execute_ex (zend_vm_execute.h:56188)
==210750==    by 0xD376BA7: zend_call_function (zend_execute_API.c:912)
==210750==    by 0xD377155: zend_call_known_function (zend_execute_API.c:1001)
==210750==    by 0xD18397B: spl_perform_autoload (php_spl.c:446)
==210750==    by 0xD3778C8: zend_lookup_class_ex (zend_execute_API.c:1145)
==210750==    by 0xD3785DB: zend_fetch_class_by_name (zend_execute_API.c:1605)
==210750==    by 0xD3E43DB: ZEND_NEW_SPEC_CONST_UNUSED_HANDLER (zend_vm_execute.h:10167)
==210750==    by 0xD448CA1: execute_ex (zend_vm_execute.h:56684)
==210750==    by 0xD44C4A3: zend_execute (zend_vm_execute.h:60151)
==210750==    by 0xD3908F5: zend_execute_scripts (zend.c:1799)
==210750==    by 0xD2DB70F: php_execute_script (main.c:2542)
==210750==    by 0xD507196: php_handler (sapi_apache2.c:710)
==210750==    by 0x45582F: ap_run_handler (config.c:169)
==210750==    by 0x455DC5: ap_invoke_handler (config.c:443)
==210750==    by 0x469BAB: ap_internal_redirect (http_request.c:790)
==210750==    by 0xC8B5FB4: handler_redirect (mod_rewrite.c:5293)
==210750==    by 0x45582F: ap_run_handler (config.c:169)
==210750==    by 0x455DC5: ap_invoke_handler (config.c:443)
==210750==    by 0x46A87A: ap_process_async_request (http_request.c:452)
==210750==    by 0x46A9CD: ap_process_request (http_request.c:487)
==210750==    by 0xB04AD75: h2_task_process_request (h2_task.c:671)
==210750==    by 0xB04AD75: h2_task_process_conn (h2_task.c:713)
==210750==    by 0xB04AD75: h2_task_process_conn (h2_task.c:700)
==210750==    by 0x45E66F: ap_run_process_connection (connection.c:42)
==210750==    by 0xB04C006: h2_task_do (h2_task.c:631)

[ElliotNB]

@Girgias I saw looking at zend_string.c and saw that you most recently touched the function relevant to this valgrind trace in #8304. Any thoughts on why valgrind reports a Conditional jump or move depends on uninitialised value(s) on line 426 of zend_string.c and if it's a significant problem? My valgrind logs end up filled with that error pointing to the same file and line number. I'm out of my depth to go much further with the troubleshooting.

[nielsdos]

Any thoughts on why valgrind reports a Conditional jump or move depends on uninitialised value(s) on line 426 of zend_string.c and if it's a significant problem? My valgrind logs end up filled with that error pointing to the same file and line number. I'm out of my depth to go much further with the troubleshooting.

This is a false positive. See #10221 and #9068 (comment) for the analysis

[ElliotNB]

@nielsdos Got it, so according to #9068 I should ignore any valgrind complaints about zend_string_equal_val?

I think I've narrowed down the root cause a bit further. I ran make test on our build and a whole bunch of opcache tests failed. Starting to dig through the cause on those. Perhaps those errors are contributing to the intermittent segfault.

[nielsdos]

Yes, you should ignore those valgrind reports.

If you run opcache in production, and you have failing opcache tests then those 2 seem correlated indeed. EDIT: just read that the segfault persists without opcache.
Could you give a list of the failing opcache tests?

To debug you can configure php with --enable-address-sanitizer , which can find memory errors without having to use valgrind. You could try reproducing your apache crash with that and see what happens.

Also what do you mean with "our build"? Is it a custom fork of php or do you just mean that you compiled php yourself without modifications?

[ElliotNB]

Could you give a list of the failing opcache tests?

@nielsdos About 30 opcache-related unit tests were failing via make test, but I eventually figured out that was due to opcache.preload_user missing from our php.ini. opcache.preload_user seems to have been added in PHP 7.4. Our company is in the process of upgrading our fleet of web servers from 7.3.27 to 8.1.16 (which explains why the opcache.preload_user option was missing). After adding that missing option to our config, we still do have some failing tests, but the list is much smaller now:

Bug #79919 (Stack use-after-scope in define()) [Zend/tests/bug79919.phpt]
Bug #80839: PHP problem with JIT [ext/opcache/tests/jit/bug80861.phpt]
Multicast support: IPv4 receive options [ext/sockets/tests/mcast_ipv4_recv.phpt]
setcookie() array variant error tests [ext/standard/tests/network/setcookie_array_option_error.phpt]
setcookie() error tests [ext/standard/tests/network/setcookie_error.phpt]
setrawcookie() error tests [ext/standard/tests/network/setrawcookie_error.phpt]
Bug #69487 (SAPI may truncate POST data) [sapi/cgi/tests/bug69487.phpt]

To debug you can configure php with --enable-address-sanitizer , which can find memory errors without having to use valgrind. You could try reproducing your apache crash with that and see what happens.

Thanks for the tip -- I'll give that a try and report back.

We also just tried adding SetEnv USE_ZEND_ALLOC 0 to our httpd.conf and restarted Apache. Unfortunately the segmentation faults persisted after that.

We confirmed that USE_ZEND_ALLOC 0 appeared in the Environment Variables section of the phpinfo() output, but strangely Zend Memory Manager was still listed as enabled up top in the phpinfo() output. Would that indicate that the Zend Memory Manager was still in effect despite the USE_ZEND_ALLOC environment variable?

Also what do you mean with "our build"? Is it a custom fork of php or do you just mean that you compiled php yourself without modifications?

I'm just referring to compiling PHP from the standard 8.1.16 source with our own selection of extensions, etc. Not a custom fork of PHP or anything like that.

[nielsdos]

After adding that missing option to our config, we still do have some failing tests, but the list is much smaller now:

I don't see an immediate relation between those tests. What do the failures look like? Are they segfaults? If so, is it possible to attach gdb and see where they segfault?

We confirmed that USE_ZEND_ALLOC 0 appeared in the Environment Variables section of the phpinfo() output, but strangely Zend Memory Manager was still listed as enabled up top in the phpinfo() output. Would that indicate that the Zend Memory Manager was still in effect despite the USE_ZEND_ALLOC environment variable?

I think so. But I don't think the memory manager is the source of the issue tbh.
Looking at line 597 I don't see how that can segfault unless something goes really wrong in TSRM.

I just noticed however that you didn't use --enable-zts in your configure command. But given your mpm-event setup I would expect that you need to use zts. I also see that some extensions in your configuration use zts. Are you actually configuring&compiling php with zts enabled?

[ElliotNB]

@nielsdos

I just noticed however that you didn't use --enable-zts in your configure command. But given your mpm-event setup I would expect that you need to use zts. I also see that some extensions in your configuration use zts. Are you actually configuring&compiling php with zts enabled?

Oh that's a good catch. Yes, we are running Apache 2.4.54 with mpm_event:

[root@app ~]# /usr/local/apache/bin/httpd -l
Compiled in modules:
  core.c
  mod_so.c
  http_core.c
  event.c
[root@app ~]#

And nope, we have not compiled PHP with --enable-zts. Yet we have those ZTS extensions enabled in our php.ini...

For what it's worth, I confirmed that our prior 7.3.27 PHP build was also compiled without --enable-zts and also had those same ZTS extensions (and Apache with mpm_event), but it never caused segmentation faults.

I'll try re-compiling PHP with --enable-zts included and will report back. Thank you for the help!

[ElliotNB]

@nielsdos Unfortunately adding --enable-zts to our ./configure line didn't make a difference -- the segmentation faults persist. I came across a post made by @derickr ( https://stackoverflow.com/questions/58918146/why-php-zts-is-disabled-by-default ) where he says If you were to build PHP for the ISAPI SAPI (Server Abstraction) layer, then the PHP build process automatically turns on ZTS mode. That probably explains why our prior build of PHP 7.3.27 didn't have ZTS issues even while omitting the --enable-zts line.

I'm still working on compiling with --enable-address-sanitizer (my first compile wasn't working with Apache) and will report back on that soon. I'm also digging deeper into the handful of failed unit tests to see if they any produce segfaults (didn't see any segfaults running them individually, but will take a closer look).

I immensely appreciate your help! Aside from what you've suggested above, I'm completely out of ideas on where to go from here.

[ElliotNB]

@nielsdos Another update...

I managed to resolve all but one of the unit tests that were failing. They were all caused by a small set of differences in my php.ini compared to the default php.ini. For example, Zend/tests/bug79919.phpt and ext/opcache/tests/jit/bug80861.phpt both fail if you define a custom error_log in your php.ini (I had set error_log = /var/log/php_error_log). Is that something worth reporting as a separate minor bug? The only unit test failing now is Multicast support: IPv4 receive options [ext/sockets/tests/mcast_ipv4_recv.phpt]. However, despite getting all but one of the unit tests to pass -- the segmentation faults still persist.

To debug you can configure php with --enable-address-sanitizer

I've run into some trouble trying to accomplish that. When I compile PHP with --enable-address-sanitizer, I get this error when trying to start Apache: httpd: Syntax error on line 177 of /usr/local/apache/conf/httpd.conf: Cannot load modules/libphp.so into server: /usr/local/apache/modules/libphp.so: undefined symbol: __asan_option_detect_stack_use_after_return I'm still researching on what might be causing that, but I'm not seeing anyone else who has reported that error in the context of compiling PHP from source.

I'm also going to try switching from gcc to clang to compile PHP. The standard repos for CentOS 8 Stream only offer gcc version 8.5.0. Meanwhile clang version 15.0.7 is available.

[ElliotNB]

No luck :( I compiled PHP with clang, restarted Apache and had a segmentation fault within ~30 minutes.

[nielsdos]

The error_log issue is probably worth reporting separately yeah. I would expect clang vs gcc to make no difference.
For the asan issue, try setting LDFLAGS="-lasan" upon configuring and compiling.