Fix Segmentation Fault when call fpm_get_status()

[txuna]

I am beginner contributer..

See #18595 regression in 8.3.23 and 8.4.7
fix #18595

This bug is essentially like a race condition. Imagine there is one parent process (P) and two child processes (A and B), and assume each child’s max_requests is set to 1. Now suppose two clients quickly http requests in succession:

curl localhost/bug.php

<?php
fpm_get_status();

1. Child process A handles the first request, reaches its max_requests limit, and exits. The parent then calls fpm_children_bury -> fpm_scoreboard_proc_free to zero out A's process structure

In the fpm_scoreboard_proc_s struct, both request_stage field and used field are reset to 0.

2. Next, the parent process P spawns a new child by calling fpm_children_make -> fpm_resources_prepare -> fpm_scoreboard_proc_alloc. in fpm_scoreboard_proc_alloc, the code sets

scoreboard->procs[i].used = 1;

marking this new slot as “in use.” At this point, used field is 1 but request_stage field is still 0, because the latter isn’t initialized until the child actually begins to accept a request.

Note

REMEMBER THE PROCESS A not reach fpm_request_accepting function yet!!

3. While the new child is still starting up, the second client’s request arrives and is handled by the existing child process B. inside fpm_get_status -> fpm_status_export_to_zval.

for (i = 0; i < scoreboard.nprocs; i++) {
    if (!procs[i].used) {
        continue;
    }
    proc_p = &procs[i];
    …
    add_assoc_string(&fpm_proc_stat, "state",
                     fpm_request_get_stage_name(procs[i].request_stage));
}

Since process A’s used field is set to 1, fpm_request_get_stage_name gets called. However, the newly spawned process A hasn’t yet invoked fpm_request_accepting, so its request_stage field is still 0.

static const char *requests_stages[] = {
    [FPM_REQUEST_ACCEPTING]       = "Idle",              // index 1
    [FPM_REQUEST_READING_HEADERS] = "Reading headers",   // index 2
    [FPM_REQUEST_INFO]            = "Getting request information", // index 3
    [FPM_REQUEST_EXECUTING]       = "Running",           // index 4
    [FPM_REQUEST_END]             = "Ending",            // index 5
    [FPM_REQUEST_FINISHED]        = "Finishing",         // index 6
};

In this array, because FPM_REQUEST_ACCEPTING has the value 1, the string entries begin at index 1, and index 0 is left as NULL.

Therefore, when fpm_request_get_stage_name is called with a request_stage of 0, it returns NULL, which leads to a segmentation fault.

So, I append new stage the FPM_REQUEST_CREATING and this is 0.

Reproduce in 8.3.23

pm.max_requests = 5
pm.max_children = 15

build

./configure --enable-debug --enable-fpm --disable-cgi --with-openssl --enable-phpdbg --enable-phpdbg-debug

gdb -p [parent process]
b fpm_request_get_stage_name

and do many client request burst.

curl localhost/bug.php 

Thread 2.1 "php-fpm" received signal SIGSEGV, Segmentation fault.
─────[ BACKTRACE ]─────
 ► 0   0xe8c8dad53010 __strlen_asimd+16
   1   0xb22336d361d4 add_assoc_string_ex+72
   2   0xb22336ef8088 add_assoc_string+48
   3   0xb22336ef88e0 fpm_status_export_to_zval+1692
   4   0xb22336ef00d8 zif_fpm_get_status+136
   5   0xb22336d78a28 ZEND_DO_ICALL_SPEC_RETVAL_UNUSED_HANDLER+168
   6   0xb22336e0757c execute_ex+2292
   7   0xb22336e0bd94 zend_execute+296

gdb -p [Parent Process]
break fpm_request_get_stage_name if stage == 0
c

In file: /home/tuuna/php-src/sapi/fpm/fpm/fpm_request.c:34
   29         [FPM_REQUEST_END]             = "Ending",
   30         [FPM_REQUEST_FINISHED]        = "Finishing",
   31 };
   32
   33 const char *fpm_request_get_stage_name(int stage) {
 ► 34         return requests_stages[stage];
   35 }
   36
   37 void fpm_request_accepting(void)
   38 {
   39         struct fpm_scoreboard_proc_s *proc;
────────[ STACK ]────────
00:0000│ sp 0xfffff452da70 —▸ 0xb223377e2890 ◂— 0x646970 /* 'pid' */
01:0008│    0xfffff452da78 ◂— 0xf452db00
02:0010│    0xfffff452da80 ◂— 0x2f452db70
03:0018│    0xfffff452da88 —▸ 0xfffff452dc28 —▸ 0xe8c8d865f1e0 ◂— 0x700000001
04:0020│    0xfffff452da90 ◂— 0x800000000
05:0028│    0xfffff452da98 ◂— 0
06:0030│    0xfffff452daa0 —▸ 0xe8c8db9fb000 ◂— 0
07:0038│    0xfffff452daa8 —▸ 0xe8c8d866c000 ◂— 1
────────[ BACKTRACE ]────────
 ► 0   0xb22336ef3e2c fpm_request_get_stage_name+8
   1   0xb22336ef88c8 fpm_status_export_to_zval+1668
   2   0xb22336ef00d8 zif_fpm_get_status+136
   3   0xb22336d78a28 ZEND_DO_ICALL_SPEC_RETVAL_UNUSED_HANDLER+168
   4   0xb22336e0757c execute_ex+2292
   5   0xb22336e0bd94 zend_execute+296
   6   0xb22336d2b714 zend_execute_scripts+356
   7   0xb22336c678f0 php_execute_script+648
────────────────────────
pwndbg> p stage
$10 = 0

Note

stage argument is 0!! and will occur segmentation fault when call strlen!

fixed bug branch

In file: /home/tuuna/php-src/sapi/fpm/fpm/fpm_status.c:115
   110                 }
   111
   112                 array_init(&fpm_proc_stat);
   113                 add_assoc_long(&fpm_proc_stat, "pid", procs[i].pid);
   114                 add_assoc_string(&fpm_proc_stat, "state", fpm_request_get_stage_name(procs[i].request_stage));
 ► 115                 add_assoc_long(&fpm_proc_stat, "start-time", procs[i].start_epoch);
   116                 add_assoc_long(&fpm_proc_stat, "start-since", now_epoch - procs[i].start_epoch);
   117                 add_assoc_long(&fpm_proc_stat, "requests", procs[i].requests);
   118                 if (procs[i].request_stage == FPM_REQUEST_ACCEPTING) {
   119                         duration = procs[i].duration;
   120                 } else {
────────[ STACK ]────────
00:0000│ sp 0xffffc1533bf0 ◂— 0x2c1533ce0
01:0008│    0xffffc1533bf8 —▸ 0xffffc1533d98 —▸ 0xf6694c6611e0 ◂— 0x700000001
02:0010│    0xffffc1533c00 ◂— 0xc00000000
03:0018│    0xffffc1533c08 ◂— 0
04:0020│    0xffffc1533c10 —▸ 0xf6694fa7a000 ◂— 0
05:0028│    0xffffc1533c18 —▸ 0xf6694c66c000 ◂— 1
06:0030│    0xffffc1533c20 ◂— 0x68348694
07:0038│    0xffffc1533c28 —▸ 0xf6694c6611e0 ◂— 0x700000001
────────[ BACKTRACE ]────────
 ► 0   0xaeb557f988e0 fpm_status_export_to_zval+1692
   1   0xaeb557f900d8 zif_fpm_get_status+136
   2   0xaeb557e18a28 ZEND_DO_ICALL_SPEC_RETVAL_UNUSED_HANDLER+168
   3   0xaeb557ea757c execute_ex+2292
   4   0xaeb557eabd94 zend_execute+296
   5   0xaeb557dcb714 zend_execute_scripts+356
   6   0xaeb557d078f0 php_execute_script+648
   7   0xaeb557f90d18 main+3108
─────────────────────
pwndbg> p procs[i].request_stage
$3 = FPM_REQUEST_CREATING
pwndbg>

when request_stage field is 0, but no segmentation fault

[bukka]

Thanks for a good analysis. It's spot on. I merged slightly cleaned up version in 48b4922 .

I have also create WST test (my testing tool for testing more advance scenarios - especially those that our PHP test framework might not properly cover like this one) which is here: wstool/wst-php-fpm@d30230a . It confirms that the fix works.