Skip to content

SIGBUS Signal 7 Issue #13011

Description

@jruston

Description

Hi,

I have a high traffic server using PHP-FPM (8.1.27). I have noticed that every so often (once every few hours), one of the child processes end with a message such as this:

WARNING: [pool www] child 2210486 exited on signal 7 (SIGBUS - core dumped) after 2215.744554 seconds from start

You can see the core dump below:

(gdb) bt
#0  __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:361
#1  0x00005611cdf29556 in memcpy (__len=<optimized out>, __src=<optimized out>, __dest=<optimized out>) at /usr/include/bits/string_fortified.h:34
#2  php_output_handler_append (buf=0x7ffd180c0488, buf=0x7ffd180c0488, handler=0x7f67b5202230) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/main/output.c:903
#3  php_output_handler_op (context=0x7ffd180c0480, handler=0x7f67b5202230) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/main/output.c:951
#4  php_output_op (len=28045, str=0xd579836c4a30 <error: Cannot access memory at address 0xd579836c4a30>, op=0) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/main/output.c:1067
#5  php_output_write (str=str@entry=0x7f67ba622000 "\037\213\b", len=28045) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/main/output.c:261
#6  0x00005611cdf2f47c in _php_stream_passthru (stream=stream@entry=0x7f67b527a000) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/main/streams/streams.c:1438
#7  0x00005611cdeb8b60 in zif_readfile (execute_data=<optimized out>, return_value=0x7ffd180c2680) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/ext/standard/file.c:1344
#8  0x00007f679a9a4c64 in phar_readfile () from /usr/lib64/php/modules/phar.so
#9  0x00005611cdfe6eb3 in ZEND_DO_ICALL_SPEC_RETVAL_UNUSED_HANDLER () at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/Zend/zend_vm_execute.h:1235
#10 execute_ex (ex=0x7f67b527b000) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/Zend/zend_vm_execute.h:55812
#11 0x00005611cdfedccc in zend_execute (op_array=0x7f67b5276100, return_value=0x0) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/Zend/zend_vm_execute.h:60188
#12 0x00005611cdf7d235 in zend_execute_scripts (type=type@entry=8, retval=retval@entry=0x0, file_count=file_count@entry=3) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/Zend/zend.c:1857
#13 0x00005611cdf182aa in php_execute_script (primary_file=<optimized out>) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/main/main.c:2551
#14 0x00005611cddca231 in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/php-8.1.27-1.el8.remi.x86_64/sapi/fpm/fpm/fpm_main.c:1935

PHP Version

8.1.27

Operating System

AlmaLinux 8.9

Activity

  1. bukka commented on Jan 4, 2024

    @bukka
    Member

    There seems to be some output buffer corruption but can't really say why is that from the provided back trace. So I will need a bit more info.

    @jruston PHP 8.1 is no longer actively supported (security support only) so it would be great to first confirm if the issue is still happening on the later versions (at least 8.2). Although if you are able to provide some way how to recreate this, I could verify it myself. So ideally we would need some piece of code that causes this. It would be useful to also enable FPM debug log level and see if there is a correlation between child termination and the crash.

  2. jruston commented on Jan 4, 2024

    @jruston
    Author

    @bukka Thanks for looking into this. I can try this on a newer version at a later date. As it is a high-traffic production server, it's not so easy to upgrade the PHP version :)

    I haven't yet been able to find out how to recreate it. It seems to occur very randomly - sometimes happening every few hours, sometimes with several days in between. It normally happens to just one process, but occasionally it can affect many processes at the same time (highest I've seen is 60 processes all crashing at the same time).

    I have turned on the debug log level which produced the following output when it crashed:

    [04-Jan-2024 14:49:33.319603] DEBUG: pid 2531556, fpm_got_signal(), line 82: received SIGCHLD
    [04-Jan-2024 14:49:33.319639] DEBUG: pid 2531556, fpm_event_loop(), line 435: event module triggered 1 events
    [04-Jan-2024 14:49:33.320033] WARNING: pid 2531556, fpm_children_bury(), line 281: [pool www] child 2531772 exited on signal 7 (SIGBUS) after 2146.706401 seconds from start
    [04-Jan-2024 14:49:33.320042] DEBUG: pid 2531556, fpm_children_make(), line 430: blocking signals before child birth
    [04-Jan-2024 14:49:33.321774] DEBUG: pid 2531556, fpm_children_make(), line 454: unblocking signals, child born
    [04-Jan-2024 14:49:33.321791] NOTICE: pid 2531556, fpm_children_make(), line 460: [pool www] child 2584265 started

  3. bukka commented on Jan 5, 2024

    @bukka
    Member

    @jruston can you provide more info about application and your fpm config might be useful as well?

  4. bukka commented on Jan 5, 2024

    @bukka
    Member

    If you can provide as much as info about your setup (OS, VM or cloud provider if you use any, devices - mainly for disk storage), that would be great. Also can you check system logs to see if there are any unusual events that would correlate with this?

  5. bukka commented on Jan 5, 2024

    @bukka
    Member

    btw from the logs it doesn't look like the child would be killed by master so it's most likely just crashing. So the above info is essential to get better idea what might be happening.

  6. jruston commented on Jan 5, 2024

    @jruston
    Author

    @bukka I just updated to 8.2.14 and it seems the issue is still present in this version. The debug log from 8.2.14:

    [05-Jan-2024 16:04:20.655157] DEBUG: pid 51702, fpm_got_signal(), line 82: received SIGCHLD
    [05-Jan-2024 16:04:20.655193] DEBUG: pid 51702, fpm_event_loop(), line 435: event module triggered 1 events
    [05-Jan-2024 16:04:20.655629] WARNING: pid 51702, fpm_children_bury(), line 281: [pool www] child 52386 exited on signal 7 (SIGBUS - core dumped) after 5644.984603 seconds from start
    [05-Jan-2024 16:04:20.655637] DEBUG: pid 51702, fpm_children_make(), line 430: blocking signals before child birth
    [05-Jan-2024 16:04:20.657845] DEBUG: pid 51702, fpm_children_make(), line 454: unblocking signals, child born
    [05-Jan-2024 16:04:20.657863] NOTICE: pid 51702, fpm_children_make(), line 460: [pool www] child 162093 started
    

    Core dump:

    #0  __memmove_avx_unaligned_erms ()
        at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:361
    #1  0x000055f872851e06 in memcpy (__len=<optimized out>, 
        __src=<optimized out>, __dest=<optimized out>)
        at /usr/include/bits/string_fortified.h:34
    #2  php_output_handler_append (buf=0x7fff7efc23e8, buf=0x7fff7efc23e8, 
        handler=0x7f2efe4022d0)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/main/output.c:903
    #3  php_output_handler_op (context=0x7fff7efc23e0, handler=0x7f2efe4022d0)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/main/output.c:951
    #4  php_output_op (len=31906, 
        str=0xd527711db6f0 <error: Cannot access memory at address 0xd527711db6f0>, op=0) at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/main/output.c:1067
    #5  php_output_write (str=str@entry=0x7f2f03768000 "\037\213\b", len=31906)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/main/output.c:261
    #6  0x000055f872857d0c in _php_stream_passthru (
        stream=stream@entry=0x7f2efe4581c0)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/main/streams/streams.c:1441
    #7  0x000055f8727e04a0 in zif_readfile (execute_data=<optimized out>, 
        return_value=0x7fff7efc45e0)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/ext/standard/file.c:1214
    #8  0x00007f2ee3b6fc54 in phar_readfile () from /usr/lib64/php/modules/phar.so
    #9  0x000055f872914215 in ZEND_DO_ICALL_SPEC_RETVAL_UNUSED_HANDLER ()
    --Type <RET> for more, q to quit, c to continue without paging--
       c/debug/php-8.2.14-1.el8.remi.x86_64/Zend/zend_vm_execute.h:1250
    #10 execute_ex (ex=0x7f2efe47c000) at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/Zend/zend_vm_execute.h:56071
    #11 0x000055f87291a672 in zend_execute (op_array=0x7f2efe477100, return_value=0x0)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/Zend/zend_vm_execute.h:60439
    #12 0x000055f8728a7075 in zend_execute_scripts (type=type@entry=8, retval=retval@entry=0x0, file_count=file_count@entry=3)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/Zend/zend.c:1838
    #13 0x000055f87284059a in php_execute_script (primary_file=<optimized out>) at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/main/main.c:2551
    #14 0x000055f8726e4bfc in main (argc=<optimized out>, argv=<optimized out>)
        at /usr/src/debug/php-8.2.14-1.el8.remi.x86_64/sapi/fpm/fpm/fpm_main.c:1920
    

    I have attached the config files for PHP-FPM as well as the pool.

    This occurs on a high-traffic API server which handles many fast-returning requests for small amounts of data (usually returning JSON). This is why the number of children is so high. The timing of these crashes seem to be very inconsistent, and don't time up with any particular script or job being run on the server.

    This is occurring on a dedicated server running AlmaLinux 8.9. Storage is two internal NVMe drives in RAID 1 configuration. There is sufficient RAM and available disk space. I'm not seeing anything unusual in the logs.

    EDIT: Also to mention, I have another server with a similar setup (same PHP version, same OS and similar hardware) which does not have this issue, but is much lower traffic.

    I am wondering if there is some kind of race condition or specific edge case which is happening when there are so many children and web requests. Considering the volume of traffic and the number of children, this crash affecting only a couple of children every few hours is quite a rare event.

    php-fpm.txt
    www.txt

  7. bukka commented on Feb 9, 2024

    @bukka
    Member

    I have done a bit more investigation and it seems to me like this is not related to FPM.

    What's happening is that your application is using readfile function that internally maps the file to memory (using mmap) and then outputs it. The mapping works but reading from that mapped memory fails. That causes segfault. The question is why the memory is no longer accessible. I did a bit of research and it could be potentially due to those issues:

    1. There might be some process that modifies the file while it's being read (it could be even the same application if the file is modified there and updated from different worker). This could be potentially handled in application by replacing readfile by something like:
    <?php
    
    function lockedReadFile($filename) {
        $handle = fopen($filename, 'r');
        if (!$handle) {
            return false;
        }
        
        if (flock($handle, LOCK_SH)) { // Acquire shared lock
            while (!feof($handle)) {
                echo fread($handle, 8192); // Adjust buffer size as needed
            }
            flock($handle, LOCK_UN); // Release the lock
        } else {
            fclose($handle);
            return false;
        }
        
        fclose($handle);
        return true;
    }
    
    // Example usage:
    $filename = 'example.txt';
    if (lockedReadFile($filename)) {
        echo "File '$filename' was read successfully.";
    } else {
        echo "Failed to read file '$filename'.";
    }
    ?>
    1. There might be some hardware issue with your storage. However in that case you should be able to see it in system logs which you said you didn't see so this is probably less likely.

    So I would suggest you try to find the places where readfile is used in your application and try to potentially find out if any of those places might contain file that can be modified. If it's there and you can modify the application, it might be worth to try to replace by the code above and see if it helps.

    Going forward we could consider introducing some optional locking during readfile (potentially by adding stream context file option or new argument - not sure yet what would make more sense).

  8. jruston commented on Feb 11, 2024

    @jruston
    Author

    @bukka Can confirm that your investigations are correct, thanks! The issue appears to be a rare occurrence with the use of the readfile function whilst the file is being updated. Out of curiosity I decided to simply swap out readfile for file_get_contents + echo without me implementing any file locking, and that does not cause any segfaults. The segfault is specific to readfile.

    Of course, file_get_contents can also struggle when the file is being updated, but in a much more manageable way that does not lead to a segfault. I will look into mitigating the root problem using file locking, as per your advice.

    From a PHP perspective, it is probably not desirable that a segfault can be triggered because of this. There were occasions where PHP-FPM would restart because I was using emergency_restart_threshold, which would be triggered when eg. 100 processes crashed because they all tried to read the file whilst it was being updated.

  9. bukka commented on Feb 18, 2024

    @bukka
    Member

    Yes the segfault can happen only for functions using mmap which are following:

    • fpassthru (including SplFileObject::fpassthru)
    • readfile
    • readgzfile
    • copy
    • stream_copy_to_stream
    • bunch of other functions using stream copying internally

    So as you can see there are quite a few cases where mmap is used. Unfortunately I don't see any way how to handle using mmap flags or locking as it is not in the user control to prevent modification to the mapped file. I agree that this is a problem. Disabling mmap will likely result in some performance hit but it will prevent potential segfaults. I think that behaviour that might segfault should not be default though. We could maybe have some options (INI comes to my mind that would allow it) and improve documentation to explicitly mention that any used files should not be resized if mmap is enabled.

  10. bukka commented on Oct 4, 2026

    @bukka
    Member

    The mmap is no longer used in PHP 8.6 - changed in #20399

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions