Deploying with Forge crashes site 502

We're having the same issue on one of our servers when deploying via Envoyer. It tries to reload the PHP-FPM service, but it fails doing so. I think this is due to Forge auto-updating, but not restarting it. Reloading it then somehow triggers a crash, perhaps due to a mismatch in configuration or running services vs new code.

Can you check your logs at /var/log/php7.1-fpm.log? See screenshots below for what we're getting.

/var/syslog:

Notice how it tries to restart the service several times, but fails to do so. Usually this log only contains the "Reloading…" line, nothing else, if all goes well.

/var/php7.1-fpm.log:

The deploy at 13:03 worked fine. The one at 15:43 is where Envoyer tried to reload php7.1-fpm, failed, and didn't produce any additional output whatsoever. Then at 9:20 in the morning, I manually reloaded the service and it continued from the previous reload. All 502 nginx errors where then fixed.

Thanks for your reply.

I'm not sure what to make of this but I think this looks ok to me? This is just a excerpt.

php7.0-fpm.log

[10-Jul-2017 07:14:30] NOTICE: Reloading in progress ...
[10-Jul-2017 07:14:30] NOTICE: reloading: execvp("/usr/sbin/php-fpm7.0", {"/usr/sbin/php-fpm7.0", "--nodaemonize", "--fpm-config", "/etc/php/7.0/fpm/php-fpm.conf"})
[10-Jul-2017 07:14:31] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:14:31] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:14:31] NOTICE: fpm is running, pid 32657
[10-Jul-2017 07:14:31] NOTICE: ready to handle connections
[10-Jul-2017 07:14:31] NOTICE: systemd monitor interval set to 10000ms
[10-Jul-2017 07:17:39] NOTICE: Reloading in progress ...
[10-Jul-2017 07:17:39] NOTICE: reloading: execvp("/usr/sbin/php-fpm7.0", {"/usr/sbin/php-fpm7.0", "--nodaemonize", "--fpm-config", "/etc/php/7.0/fpm/php-fpm.conf"})
[10-Jul-2017 07:17:39] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:17:39] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:17:39] NOTICE: fpm is running, pid 32657
[10-Jul-2017 07:17:39] NOTICE: ready to handle connections
[10-Jul-2017 07:17:39] NOTICE: systemd monitor interval set to 10000ms
[10-Jul-2017 07:22:12] NOTICE: Reloading in progress ...
[10-Jul-2017 07:22:12] NOTICE: reloading: execvp("/usr/sbin/php-fpm7.0", {"/usr/sbin/php-fpm7.0", "--nodaemonize", "--fpm-config", "/etc/php/7.0/fpm/php-fpm.conf"})
[10-Jul-2017 07:22:12] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:22:12] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:22:12] NOTICE: fpm is running, pid 32657
[10-Jul-2017 07:22:12] NOTICE: ready to handle connections
[10-Jul-2017 07:22:12] NOTICE: systemd monitor interval set to 10000ms
[10-Jul-2017 07:22:55] NOTICE: Reloading in progress ...
[10-Jul-2017 07:22:55] NOTICE: reloading: execvp("/usr/sbin/php-fpm7.0", {"/usr/sbin/php-fpm7.0", "--nodaemonize", "--fpm-config", "/etc/php/7.0/fpm/php-fpm.conf"})
[10-Jul-2017 07:22:55] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:22:55] NOTICE: using inherited socket fd=8, "/run/php/php7.0-fpm.sock"
[10-Jul-2017 07:22:55] NOTICE: fpm is running, pid 32657
[10-Jul-2017 07:22:55] NOTICE: ready to handle connections

There are a few odd bits in the syslog. It doesn't look anything yours. Not sure this is relevant at all but it looks like some IP is trying 119.23.106.126 to access my server? I googled it and saw something about reported for abuse...

Jul 13 06:33:07 mmb kernel: [2208669.212392] [UFW BLOCK] IN=eth0 OUT= MAC=62:f8:2b:ad:bb:3e:40:a6:77:42:b3:f0:08:00 SRC=119.23.106.126 DST=46.101.77.130 LEN=40 TOS=0x00 PREC=0x00 TTL=237$

Also noticed this, which looks to do with queues but not sure what significance it is.

/home/forge/.forge/scheduled-184095.log 2>&1)
Jul 13 08:20:01 mmb sm-msp-queue[2278]: My unqualified host name (mmb) unknown; sleeping for retry
Jul 13 08:20:05 mmb kernel: [2215088.137408] [UFW BLOCK] IN=eth0 OUT= MAC=62:f8:2b:ad:bb:3e:40:a6:77:42:b3:f0:08:00 SRC=114.222.140.18 DST=46.101.77.130 LEN=52 TOS=0x00 PREC=0x00 TTL=37 $
Jul 13 08:21:01 mmb sm-msp-queue[2278]: unable to qualify my own domain name (mmb) -- using short name

I've done a few deployments today but turned off auto deploy on production and haven't had any problems yet. Do you have auto deploy set up on the same server for more than one site?

Regarding the UFW IP block, I'm getting those too (every few seconds). It helps to set up iptables (see serversforhackers by Chris Fidao, he explains it quite well how to set that up in just a few minutes).

Your php-fpm log looks ok to me. It reloads the service and they immediately start running again. Lots of reload calls though. How many times are you deploying in those few minutes? Should reload once per deploy.

Also, check the timestamps in your logs when nginx throws a 502. Both nginx, php-fpm, and syslog where starting to display errors at exactly the same time, which helped me track down the problem. If we have the same issue, nginx should show a 502 bad gateway error (in your browser) and an upstream error (to the php-fpm socket) in its log right after the reload when deploying (if the issue occurs). If not, it might be something else.

Mailed Taylor and got a response saying it might be related to both production and staging trying to deploy to one server for that one project. Both are trying to reload php-fpm, which somehow makes it crash without actual error. No fix there, except not deploying both at the same time.

Hi Sebastiaan,

Thanks for your advice. Since turning off auto deploy on production I haven't had any more 502 issue so I believe that Taylor's suggestion may be correct now that it is only staging on auto deploy to that server. Not ideal but at least makes me pay more attention when deploying production ;)

I checked out iptables, thank you. I'm not sure but it looks like forge set this up pretty well.

From doing sudo ufw status

Status: active

To                         Action      From
--                         ------      ----
22                         ALLOW       Anywhere
80                         ALLOW       Anywhere
443                        ALLOW       Anywhere
22 (v6)                    ALLOW       Anywhere (v6)
80 (v6)                    ALLOW       Anywhere (v6)
443 (v6)                   ALLOW       Anywhere (v6)

Also when following this tutorial https://serversforhackers.com/c/firewalls-basics-of-iptables running sudo iptables -L -v there seems to be a fair amount set up vs what he begins with in the tutorial.

Thanks again!