Some Phusion Passenger agent processes did not exit in time, forcefully shutting down all

[Rupesh Helwade]

We have deployed Red mine Application with following details :

Ruby : ruby 1.9.3p429 (2013-05-15 revision 40747) [i686-linux]

passenger version
4.0.2

OS :
Linux 3.3.4-5.fc17.i686.PAE #1 SMP Mon May 7 17:37:39 UTC 2012 i686 i686 i386 GNU/Linux

Apache
Server version: Apache/2.2.22 (Unix)

Redmine: 2.3.1 stable

rails (3.2.13)

=============================
It is installed using Bitnami Redmine stack : bitnami-redmine-2.3.1-1-linux-installer.run
It was working fine for almost 4 months when suddenly the application shut down with messaeg on browser as

We're sorry, but something went wrong.

We've been notified about this issue and we'll take a look at it shortly.

================================================

I have also upgraded the RAM from 2 GB to 4 GB

I tried shutting down the machine- restarting it, restarting the application (redmine) - uninstalling and re-installing it but no luck so far.The application log does not have any error messages but the Apache error_log showed following extract :

-------------------------------------------------

[Sun Jun 29 13:56:03.824641 2014] [ssl:warn] [pid 8828] AH01909: RSA certificate configured for www.exam ple.com:8443 does NOT include an ID which matches the server name
[ 2014-06-29 13:56:03.8364 8832/b76cc700 agents/HelperAgent/Main.cpp:554 ]: PassengerHelperAgent online, listening at unix:/tmp/passenger.1.0.8828/generation-0/request.socket
[ 2014-06-29 13:56:03.8439 8837/b740f700 agents/LoggingAgent/Main.cpp:272 ]: PassengerLoggingAgent online, listening at unix:/tmp/passenger.1.0.8828/generation-0/logging.socket
[Sun Jun 29 13:56:04.032237 2014] [ssl:warn] [pid 8848] AH01909: RSA certificate configured for ww w.example.com:8443 does NOT include an ID which matches the server name
[Sun Jun 29 13:56:04.032378 2014] [lbmethod_heartbeat:notice] [pid 8848] AH02282: No slotmem from mod_heartmonitor
[ 2014-06-29 13:56:04.0632 8853/b7660700 agents/HelperAgent/Main.cpp:554 ]: PassengerHelperAgent online, listening at unix:/tmp/passenger.1.0.8848/generation-0/request.socket
[ 2014-06-29 13:56:04.0662 8858/b7332700 agents/LoggingAgent/Main.cpp:272 ]: PassengerLoggingAgent online, listening at unix:/tmp/passenger.1.0.8848/generation-0/logging.socket
[Sun Jun 29 13:56:04.068767 2014] [mpm_prefork:notice] [pid 8848] AH00163: Apache/2.4.4 (Unix) OpenSSL/1.0.1e PHP/5.4.15 Phusion_Passenger/4.0.2 configured -- resuming normal operations
[Sun Jun 29 13:56:04.068837 2014] [core:notice] [pid 8848] AH00094: Command line: '/opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf'
[Sun Jun 29 13:57:34.612912 2014] [mpm_prefork:notice] [pid 8848] AH00169: caught SIGTERM, shutting down
[Sun Jun 29 13:57:38.861313 2014] [ssl:warn] [pid 9034] AH01909: RSA certificate configured for w ww.example.com:8443 does NOT include an ID which matches the server name
[ 2014-06-29 13:57:38.8736 9038/b767d700 agents/HelperAgent/Main.cpp:554 ]: PassengerHelperAgent online, listening at unix:/tmp/passenger.1.0.9034/generation-0/request.socket
[ 2014-06-29 13:57:38.8803 9043/b7386700 agents/LoggingAgent/Main.cpp:272 ]: PassengerLoggingAgent online, listening at unix:/tmp/passenger.1.0.9034/generation-0/logging.socket
[Sun Jun 29 13:57:39.046162 2014] [ssl:warn] [pid 9054] AH01909: RSA certificate configured for w ww.example.com:8443 does NOT include an ID which matches the server name
[Sun Jun 29 13:57:39.046296 2014] [lbmethod_heartbeat:notice] [pid 9054] AH02282: No slotmem from mod_heartmonitor
[ 2014-06-29 13:57:39.0736 9059/b7677700 agents/HelperAgent/Main.cpp:554 ]: PassengerHelperAgent online, listening at unix:/tmp/passenger.1.0.9054/generation-0/request.socket
[ 2014-06-29 13:57:39.0802 9064/b73a4700 agents/LoggingAgent/Main.cpp:272 ]: PassengerLoggingAgent online, listening at unix:/tmp/passenger.1.0.9054/generation-0/logging.socket
[Sun Jun 29 13:57:39.082762 2014] [mpm_prefork:notice] [pid 9054] AH00163: Apache/2.4.4 (Unix) OpenSSL/1.0.1e PHP/5.4.15 Phusion_Passenger/4.0.2 configured -- resuming normal operations
[Sun Jun 29 13:57:39.082832 2014] [core:notice] [pid 9054] AH00094: Command line: '/opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf'
[ 2014-06-29 13:58:08.8984 9053/b76d7700 agents/Watchdog/Main.cpp:989 ]: Some Phusion Passenger agent processes did not exit in time, forcefully shutting down all.
[ 2014-06-29 14:00:40.9813 9059/b747db40 Pool2/Implementation.cpp:762 ]: Could not spawn process for group /opt/Redmine/apps/redmine/htdocs#default: An error occurred while starting up the preloader: it did not write a handshake message in time.

[Rupesh Helwade]

[admin@ubsdev ~]$ /opt/Redmine/ruby/bin/passenger-status
----------- General information -----------
Max pool size : 6
Processes     : 0
Requests in top-level queue : 0

----------- Application groups -----------
/opt/Redmine/apps/redmine/htdocs#default:
  App root: /opt/Redmine/apps/redmine/htdocs
  (spawning new process...)
  Requests in queue: 3
==========================================

[admin@ubsdev ~]$  /opt/Redmine/ruby/bin/passenger-memory-stats

-------- Apache processes ---------
PID   PPID  VMSize   Private  Name
-----------------------------------
2386  1     85.6 MB  4.3 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2419  2386  85.6 MB  0.2 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2420  2386  85.6 MB  0.2 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2421  2386  85.6 MB  0.2 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2422  2386  85.6 MB  0.2 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2423  2386  85.6 MB  0.2 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2458  2386  85.6 MB  0.2 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2496  2386  85.6 MB  0.1 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2516  2386  85.6 MB  0.1 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2524  2386  85.6 MB  0.1 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2525  2386  85.6 MB  0.1 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
2526  2386  85.6 MB  0.1 MB   /opt/Redmine/apache2/bin/httpd -f /opt/Redmine/apache2/conf/httpd.conf
### Processes: 12
### Total private dirty RSS: 6.23 MB


-------- Nginx processes --------

### Processes: 0
### Total private dirty RSS: 0.00 MB


---- Passenger processes ----
PID   VMSize   Private  Name
-----------------------------
2402  8.0 MB   0.2 MB   PassengerWatchdog
2405  33.9 MB  2.4 MB   PassengerHelperAgent
2410  8.9 MB   0.4 MB   PassengerLoggingAgent
### Processes: 3

[Hongli Lai]

It's not clear from the log messages why Redmine fails to start. The only thing I can see is that Redmine somehow froze during startup, or starts too slowly. You can try the techniques here to debug Redmine: http://blog.phusion.nl/2012/09/21/the-right-way-to-deal-with-frozen-processes-on-unix/

--
You received this message because you are subscribed to the Google Groups "Phusion Passenger Discussions" group.
To unsubscribe from this group and stop receiving emails from it, send an email to phusion-passen...@googlegroups.com.
To post to this group, send email to phusion-...@googlegroups.com.
Visit this group at http://groups.google.com/group/phusion-passenger.

To view this discussion on the web visit https://groups.google.com/d/msgid/phusion-passenger/3adcec61-b7e6-4533-92ab-8cec6496bfa3%40googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
Phusion | Web Application deployment, scaling, and monitoring solutions

Web: http://www.phusion.nl/
E-mail: in...@phusion.nl
Chamber of commerce no: 08173483 (The Netherlands)