Strange issue with php 5.6 (ubuntu 16.04 LTS e ubuntu 14.04 LTS). Bug?
| From: | Andrea Soracchi | Date: | Tue, 04 Jul 2017 21:30:32 +0000 |
| Subject: | Strange issue with php 5.6 (ubuntu 16.04 LTS e ubuntu 14.04 LTS). Bug? | ||
| Groups: | php.install | ||
| Request: | Send a blank email to php-install+get-20497@lists.php.net to get a copy of this message | ||
Hi,
with Ubuntu 16.04 LTS or Ubuntu 14.04 LTS (with php 5.6 ppa:ondrej/php) I've got this issue :
- the client posts files successfully but the answer of the post is delayed. The more the file is
bigger, the more the answer is delayed!!!
I have set the debug level log to nginx and php-fpm.
Nginx:
2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file
/var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it,
request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos
0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily
unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type:
text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M
Php-fpm:
PHPFPM
[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379:
[pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1
Any idea?
With the same configuration I have no problem with php 5.5 in ubuntu 14.04 LTS or with php 7.1 in
ubuntu 16.04 LTS!!!!
It's a bug?
Thanks,
Andrea
ANDREA SORACCHI
+39 329 0512704
System Engineer
+39 0521 24 77 91
soracchi@netbuilder.it