php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #72185 php-fpm writes stdout with contentlength =0 causing nginx 502
Submitted: 2016-05-10 15:21 UTC Modified: 2016-05-10 15:26 UTC
Votes:4
Avg. Score:4.8 ± 0.4
Reproduced:4 of 4 (100.0%)
Same Version:3 (75.0%)
Same OS:3 (75.0%)
From: kenny at kennynet dot co dot uk Assigned:
Status: Closed Package: FPM related
PHP Version: 5.6.21 OS: Debian 7.0
Private report: No CVE-ID: None
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: kenny at kennynet dot co dot uk
New email:
PHP Version: OS:

 

 [2016-05-10 15:21 UTC] kenny at kennynet dot co dot uk
Description:
------------
When error bytes written to stderr equal to sizeof(req->out_buf) - sizeof(fcgi_header) [8192 - 8] php5-fpm will emit an empty FGCI_STDOUT frame which causes nginx to trigger a 502 Gateway error (and a SIGPIPE to the FPM worker).

E.g. stracing the fpm worker running the 502 script below through nginx yields:

# strace -ewrite -p $WORKER_PID -s99999999 2>&1 | grep 'write(3'
write(3, "\1\7\0\1\37\360\0\0PHP message: PHP Warning:  aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa...\n<REMOVED FOR BREVITY> in /data/Projects/KMv3/502.php on line 15\n\1\6\0\1\0\0\0\0", 8192) = 8192

write(3, "\1\6\0\1\0003\5\0Content-type: text/html; charset=UTF-8\r\n\r\nOK: 8134\n\0\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0aaa", 80) = -1 EPIPE (Broken pipe)

Note: The trailing 8 bytes of the first write(3, ...): 

ver  stdout  requestid   contentlen  padlen  reserved
\1   \6      \0\1        \0\0        \0      \0

I believe this is due to the following code-path (as of 5.6.19, sorry, but I can't test 5.6.21 yet but I presume it's not changed):-

fcgi_write()

    if (req->out_hdr && req->out_hdr->type != type) {
        close_packet(req); <---- Transitioning from FCGI_STDERR to FCGI_STDOUT
    }

...

    } else if (len - limit < sizeof(req->out_buf) - sizeof(fcgi_header)) {
        if (!req->out_hdr) {
            open_packet(req, type); <-- Packet closed above, so opens one for FCGI_STDOUT
        }

...
        // NB: limit == 0 so memcpy() wasn't hit.
        if (!fcgi_flush(req, 0)) { <-- Call fcgi_flush
            return -1;
        }
...
fcgi_flush()

    close_packet(req); <-- Packet closed with no data added to it
...
    if (safe_write(req, req->out_buf, len) != len) { <-- Empty FCGI_STDOUT frame emitted with the FCGI_STDERR data. 
...

NB: While debugging this if your total error bytes write 8192-8+(0 < n < 8) then it looks like the open_packet() call overflows req->out_buf by 8 bytes (due to the padding) and the write() returns 8200 bytes written. (Easiest thing is to subtract from $len, 1 or 3 etc...)

NBB: PoC given not heavily tested. 

Test script:
---------------
<?php
// YMMV. Ideally leave log_errors_max_len at the default of 1024
define('ERR_HDR', 'PHP message: PHP Warning:  ');
define('FCGI_OUT_BUF_SIZE', 8192);
define('FCGI_HDR_SIZE', 8);

$max = ini_get('log_errors_max_len');
$len = FCGI_OUT_BUF_SIZE - (2 * FCGI_HDR_SIZE) - strlen($_SERVER['SCRIPT_FILENAME']) - strlen(" on line 15");
$bytes = 0;

sleep(30);

while ($bytes < $len) {
    $p = str_repeat('a', min($max, $len - $bytes) - strlen(ERR_HDR) - 1);
    $bytes += strlen($p) + strlen(ERR_HDR) + 1;
    trigger_error($p, E_USER_WARNING);
}


echo "OK: $bytes\n";

Expected result:
----------------
No 502 error and the page renders correctly.

Actual result:
--------------
nginx 502 error due to empty FCGI_STDOUT frame.

Patches

php_fix_bug_72185.patch (last revision 2018-09-04 09:38 UTC by kenny at kennynet dot co dot uk)

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2016-05-10 15:26 UTC] kenny at kennynet dot co dot uk
(The sleep(30) is obviously not required. It was just to give me time to attach the strace!)
 [2018-09-04 09:38 UTC] kenny at kennynet dot co dot uk
We've been using the added patch for a while now without any obvious issues.

No idea if it's "technically correct" but it seems to work all the same.
 [2018-09-04 09:59 UTC] kenny at kennynet dot co dot uk
(That patch should apply on top of 7.2.9)
 [2022-05-10 20:40 UTC] git@php.net
Automatic comment on behalf of bukka
Revision: https://github.com/php/php-src/commit/23a20304381c930ea0843386a650044846586a0b
Log: Fix bug #72185: php-fpm writes empty fcgi record causing nginx 502
 [2022-05-10 20:40 UTC] git@php.net
-Status: Open +Status: Closed
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Thu Nov 21 13:01:29 2024 UTC