php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #79928 fastcgi_finish_request() doesn't finish request
Submitted: 2020-08-04 13:47 UTC Modified: -
From: vedad at kajtaz dot net Assigned:
Status: Open Package: FPM related
PHP Version: 7.4.8 OS: FreeBSD 12.1-RELEASE
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 this is not your bug, you can add a comment by following this link.
If this is your bug, but you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: vedad at kajtaz dot net
New email:
PHP Version: OS:

 

 [2020-08-04 13:47 UTC] vedad at kajtaz dot net
Description:
------------
Hi,

I have a FPM (unix socket) + nginx setup.

I have a couple of scripts, invoked from cron through nginx, that are designed to run lengthy tasks.

The very first thing these scripts do is to invoke fastcgi_finish_request() (after going through some routing logic).

They don't produce any output, neither before nor after invoking fastcgi_finish_request(). I did try writing to stdout and/or seanding headers before the call, the behavior remains the same.

Seldomly (roughly one request out of 10), FPM doesn't seem to notify nginx, which results in nginx reporting a timeout (which is configured to 30 seconds):

	2020/08/03 18:38:33 [error] 82940#103032: *41412 upstream timed out (60: Operation timed out) while reading response header from upstream, client: XX.XXX.XXX.XXX, server: XXXXXXXXX.XXXXXXXXXX.com, request: "GET /cron/XXXXXXXXXX HTTP/1.1", upstream: "fastcgi://unix:/tmp/XXXXXXXXX.sock", host: "XXXXXXXXX.XXXXXXXXXX.com"

Even when the 30 seconds timeout is not reached, I see instances of scripts running for more that a couple of milliseconds one would except when fastcgi_finish_request() is invoked straight away (first column = response time in seconds):

	0.001 XX.XXX.XXX.XXX - - [04/Aug/2020:14:34:17 +0200] "GET /cron/XXXXXXXXXX HTTP/1.1" 200 5 "-" "cron"
	17.253 XX.XXX.XXX.XXX - - [04/Aug/2020:14:34:17 +0200] "GET /cron/XXXXXXXXXX HTTP/1.1" 200 5 "-" "cron"

I have no idea where to start to try debugging this issue.

Any ideas?





Patches

Add a Patch

Pull Requests

Add a Pull Request

 
PHP Copyright © 2001-2020 The PHP Group
All rights reserved.
Last updated: Wed Nov 25 20:01:23 2020 UTC