Nginx + php-fpm: upstream timeout

nginxphp-fpmvagrant

Setup:

I have a virtual box (vagrant) running nginx + php-fpm inside. I have xdebug module loaded. Versions:

OS:

uname -a
Linux vagrant-ubuntu-vivid-64 3.19.0-26-generic #28-Ubuntu SMP Tue Aug 11 14:16:32 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

php5-fpm:

php5-fpm -v
PHP 5.6.4-4ubuntu6.2 (fpm-fcgi) (built: Jul  2 2015 15:59:03)
Copyright (c) 1997-2014 The PHP Group
Zend Engine v2.6.0, Copyright (c) 1998-2014 Zend Technologies
    with Zend OPcache v7.0.4-dev, Copyright (c) 1999-2014, by Zend Technologies
    with Xdebug v2.2.6, Copyright (c) 2002-2014, by Derick Rethans

nginx:

nginx -V
nginx version: nginx/1.6.2 (Ubuntu)
TLS SNI support enabled

Problem:

For the unknown reason I'm getting:

upstream timed out (110: Connection timed out) while 
reading response header from upstream

I tried both unix sockets setup for php5-fpm and TCP setup – both failed with same error.

With sockets setup, I tried to change listen permissions to read-write and even to 777 – no difference. Just in case, sample of config (www.conf) for sockets:

listen.owner = www-data
listen.group = www-data
listen.mode = 0666

And user exists:

id www-data
uid=33(www-data) gid=33(www-data) groups=33(www-data)

With the TCP setup, however, I have:

$ telnet 127.0.0.1 9000
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.

Meaning that it is indeed listening on that port. Also, another check:

netstat -tulpn | grep 9000
tcp        0      0 127.0.0.1:9000          0.0.0.0:*               LISTEN      4396/php-fpm.conf)

I tried to disable xdebug also – just to make sure it's not a problem with the connection getting to there (but, in fact, it's pointless as my IDE is launched on host machine and therefore it's port has nothing to do with port inside VM).

I tried to set fastcgi_read_timeout together with max_execution_time to really high values (thousands of seconds) and that is also not helping the case.

So what could cause this behavior and how to resolve the case? Or at least, what can I do to debug the case?

Update:

When I set a very high timeout, server responds. But the thing is – that I see is not an application problem since:

  • Application basically just writes message in log-file
  • The request "hangs" for unknown reason for minutes and after that appears in the nginx access log together with in application log (so, application logs request immediately when it appears in nginx log)

With things above I'm now quite lost: nginx tells that gateway has timeout. Which should mean: request came to nginx and then was timed out in-between nginx and it's backend (so, php5-fpm in this case). If the request "hangs" even before appearing in nginx logs – how comes backend is responsible? I mean, why nginx has "upstream timeout"?

Therefore, question will be – what can cause such delays?

If there is any additional info that is needed – I will provide it.

I also tried similar questions on SO/SF and it did not help the case

Best Answer

Issue resolved. Problem lies in the vagrant setup:

# Shared folder
config.vm.synced_folder "./../", "/vagrant/",
        :nfs => true

And since application was trying to write log to the shared folder, it got stuck because the implementation of the logger was trying to apply lock on the file via flock() which simply does not work correctly in case of NFS.

So, solution is:

  • Either mount shared folders not as NFS devices
  • Or do not use file locks. While this option seems to be "easier" way to resolve the issue - it has downside since if your application is using vendor-predefined bundles (via composer as example), it is hard to even realize if the application is using something which may fail like this case.