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:3
Avg. Score:4.7 ± 0.5
Reproduced:3 of 3 (100.0%)
Same Version:2 (66.7%)
Same OS:2 (66.7%)
From: kenny at kennynet dot co dot uk Assigned:
Status: Open Package: FPM related
PHP Version: 5.6.21 OS: Debian 7.0
Private report: No CVE-ID: None
View Add Comment Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
You can add a comment by following this link or if you reported this bug, you can edit this bug over here.
(description)
Block user comment
Status: Assign to:
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)

Add a Patch

Pull Requests

Add a Pull Request

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)
 
PHP Copyright © 2001-2020 The PHP Group
All rights reserved.
Last updated: Thu Nov 26 03:01:23 2020 UTC