SIGBUS Signal 7 Issue

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

@jruston

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.

@bukka

@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

@jruston

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

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?

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.

@bukka

@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

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:

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'.";
}
?>

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).

@bukka

@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.

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.

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

Navigation Menu

Repository navigation

SIGBUS Signal 7 Issue #13011

Description

PHP Version

Operating System

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

SIGBUS Signal 7 Issue #13011

Description

Description

PHP Version

Operating System

Activity

bukka commented on Jan 4, 2024

jruston commented on Jan 4, 2024

bukka commented on Jan 5, 2024

bukka commented on Jan 5, 2024

bukka commented on Jan 5, 2024

jruston commented on Jan 5, 2024

bukka commented on Feb 9, 2024

jruston commented on Feb 11, 2024

bukka commented on Feb 18, 2024

bukka commented on Oct 4, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions