Opened 12 years ago

Closed 12 years ago

#373 closed defect (invalid)

nginx unexpectedly terminate php-fastcgi when it has lot of errors

Reported by: oliver nadj Owned by:
Priority: minor Milestone:
Component: nginx-core Version:
Keywords: php-fastcgi Cc:
uname -a: Linux balbu.interfex.eu 2.6.32-318-ec2 #38-Ubuntu SMP Thu Sep 1 18:09:30 UTC 2011 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.4.1
TLS SNI support enabled
configure arguments: --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-log-path=/var/log/nginx/access.log --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --with-pcre-jit --with-debug --with-http_addition_module --with-http_dav_module --with-http_geoip_module --with-http_gzip_static_module --with-http_image_filter_module --with-http_realip_module --with-http_stub_status_module --with-http_ssl_module --with-http_sub_module --with-http_xslt_module --with-ipv6 --with-mail --with-mail_ssl_module --add-module=/build/buildd/nginx-1.4.1/debian/modules/nginx-auth-pam --add-module=/build/buildd/nginx-1.4.1/debian/modules/nginx-dav-ext-module --add-module=/build/buildd/nginx-1.4.1/debian/modules/nginx-echo --add-module=/build/buildd/nginx-1.4.1/debian/modules/nginx-upstream-fair --add-module=/build/buildd/nginx-1.4.1/debian/modules/ngx_http_substitutions_filter_module
root@balbu:/home/oliver# uname -a
Linux balbu.interfex.eu 2.6.32-318-ec2 #38-Ubuntu SMP Thu Sep 1 18:09:30 UTC 2011 x86_64 GNU/Linux

Description

The nginx server unexpectedly terminates php-fastcgi when it produces lot of errors. It seems like truncate page because the part of the page is missing and the errors log doesn't show why.

This script can reproduce these issue.

<?php
//error_reporting(E_ALL ^ E_NOTICE ^ E_DEPRECATED); //the whole content printed as expected
error_reporting(E_ALL & ~E_DEPRECATED); //truncated content
header("Content-Type: text/plain; charset=iso-8859-2");

$i = 500000;
while ($i) {
  $i--;
  printf("%10s", $i);
  if (!($i%50)) {
    echo "\n";
  }
  $a = $undefined;
}

Antecedences: http://serverfault.com/questions/514044/nginx-is-cutting-the-end-of-dynamic-pages-and-cache-it


php -v
PHP 5.3.2-1ubuntu4.18 with Suhosin-Patch (cli) (built: Sep 12 2012 19:12:47) 
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2010 Zend Technologies

Attachments (2)

error.log.gz (10.1 KB ) - added by oliver nadj 12 years ago.
error log without debug flag
error.with-debug.log.gz (74.0 KB ) - added by oliver nadj 12 years ago.
error log with debug flag

Download all attachments as: .zip

Change History (8)

comment:1 by Maxim Dounin, 12 years ago

Script in question works fine here.

Note well: script in question produced 60+ megabyte response, and most likely truncation happened due to nginx not being able to create/write a file in fastcgi_temp_path. It should produce error in relevant error_log, but likely it was just overlooked (or wrong error log was checked - note the configuration snippet posted on serverfault uses different error logs at global level and for the server{} block).

Please provide debug log if you still think there is an issue in nginx, see http://nginx.org/en/docs/debugging_log.html.

by oliver nadj, 12 years ago

Attachment: error.log.gz added

error log without debug flag

by oliver nadj, 12 years ago

Attachment: error.with-debug.log.gz added

error log with debug flag

comment:2 by oliver nadj, 12 years ago

I just added logs, I hope it is ok.
Currently I check fastcgi_temp_path and I will post the results.

Thanks Maxim

comment:3 by oliver nadj, 12 years ago

Now the location ~ ^.+\.php section looks like this:

location ~ ^.+\.php {
  fastcgi_temp_path                   /tmp/nginxcache 1 2;
  fastcgi_max_temp_file_size          1024m;
  fastcgi_split_path_info ^((?U).+\.php)(/?.+)$;
  fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
  fastcgi_param SCRIPT_NAME $fastcgi_script_name;
  fastcgi_param PATH_INFO $fastcgi_path_info;
  fastcgi_pass   127.0.0.1:9000;
  include        fastcgi_params;
}

And the temporary directory tree after 4 trial looks like this:

$ tree -g -u -p /tmp/nginxcache/
/tmp/nginxcache/
├── [drwx------ www-data www-data]  1
│   └── [drwx------ www-data www-data]  00
├── [drwx------ www-data www-data]  3
│   └── [drwx------ www-data www-data]  00
└── [drwx------ www-data www-data]  5
    └── [drwx------ www-data www-data]  00

But unfortunately the request unexpectedly terminated as before.

Would You suggest me a better fastscgi configuration?

comment:4 by Maxim Dounin, 12 years ago

From debug log, it looks like a php problem:

2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 01
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 06
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 01
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record length: 0
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi closed stdout
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 01
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 06
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 01
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 10
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 03
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 05
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record byte: 00
2013/06/10 19:56:35 [debug] 22752#0: *6 http fastcgi record length: 4099

That is, stdout is closed - and then there is another stdout record. This is clearly incorrect. You may want to try to upgrade php / examine known and/or recently fixed errors, as well as play with various php buffering options.

Note well - fastcgi option you use (php-cgi vs. php-fpm) may also affect things. I've tested with php 5.4.13, php-cgi, and see no problem.

comment:5 by oliver nadj, 12 years ago

I updated PHP to 5.3.2-1ubuntu4.19, not helped, but my distro is out of date. I will do a distro upgrade within a few days.

It seems newer version of PHP resolve this issue.

Thanks your time. Please close the ticket.

comment:6 by Maxim Dounin, 12 years ago

Resolution: invalid
Status: newclosed
Note: See TracTickets for help on using tickets.