Bug 1103224

[ 2014-05-30 08:34:57.9564 27564/7f1946200700 agents/HelperAgent/RequestHandler.h:1967 ]: [Client 25] Cannot checkout session. An error occurred while starting up the preloader: it did not write a startup response in time.
Error seen during timeout in /var/log/httpd/error_log:

[ 2014-05-30 08:34:57.9568 27564/7f1946200700 agents/HelperAgent
/RequestHandler.h:1967 ]: [Client 26] Cannot checkout session. An error occurred while starting up the preloader: it did not write a startup response in time.
[ 2014-05-30 09:01:57.8388 27564/7f19457be700 Pool2/Spawner.h:738 ]: [App 24003 stdout]
[ 2014-05-30 09:03:27.9270 27564/7f19457be700 Pool2/Implementation.cpp:849 ]: Could not spawn process for group /usr/share/foreman#default: An error occurred while starting up the preloader: it did not write a startup response in time.
     in 'void Passenger::ApplicationPool2::SmartSpawner::throwPreloaderSpawnException(const std::string&, Passenger::SpawnException::ErrorKind, Passenger::ApplicationPool2::Spawner::BackgroundIOCapturerPtr&, const Passenger::ApplicationPool2::Spawner::DebugDirPtr&)' (SmartSpawner.h:150)
     in 'std::string Passenger::ApplicationPool2::SmartSpawner::negotiatePreloaderStartup(Passenger::ApplicationPool2::SmartSpawner::StartupDetails&)' (SmartSpawner.h:558)
     in 'void Passenger::ApplicationPool2::SmartSpawner::startPreloader()' (SmartSpawner.h:206)
     in 'virtual Passenger::ApplicationPool2::ProcessPtr Passenger::ApplicationPool2::SmartSpawner::spawn(const Passenger::ApplicationPool2::Options&)' (SmartSpawner.h:744)
     in 'void Passenger::ApplicationPool2::Group::spawnThreadRealMain(const Passenger::ApplicationPool2::SpawnerPtr&, const Passenger::ApplicationPool2::Options&, unsigned int)' (Implementation.cpp:782)

*** Bug 1103229 has been marked as a duplicate of this bug. ***

Justin, can you append production.log of the foreman instance? What is going on there? Also can you watch load/top during the initialization? What does it do? I am afraid 90 seconds should be enough even for Foreman/Katello...

It looks like this machine is really booting rails 2 minutes:

[root@quartet ~]# date <<< REQUEST STARTED
Fri May 30 10:59:01 EDT 2014

[root@quartet ~]# date <<< REQUEST HANDLED
Fri May 30 11:00:53 EDT 2014

Intel(R) Xeon(R) CPU            5120  @ 1.86GHz

The box was swapping a bit, not much:

[root@quartet ~]# free -m
             total       used       free     shared    buffers     cached
Mem:          9890       9660        229          0        418       3134
-/+ buffers/cache:       6107       3782
Swap:         6043        609       5434

When we killed one qemu instance from there, it helped a bit (approx 10%) but its still above 1.5 minute passenger default timeout.

Resolution: We need to make sure that we have set to 10 minutes:

PassengerStartTimeout 600

Also there is this upstream patch that preloads passenger processes ASAP when Apache2 httpd is restarted, so users/customers will not need to wait until the first request is processed:

https://github.com/theforeman/puppet-foreman/pull/194

Created redmine issue http://projects.theforeman.org/issues/6034 from this bug

lzap has another bug, taking it off.

Connecting redmine issue http://projects.theforeman.org/issues/6036 from this bug

Upstream merged, this can be tricky to cherry-pick. Ping me if you need assistance.

Moving to POST since upstream bug http://projects.theforeman.org/issues/6036 has been closed

The PR against katello-installer https://github.com/Katello/katello-installer/pull/72

Jason, the katello-installer has been merged.

Installed sat6 beta snap9 and I didn't face the issue related to setting value "PassengerStartTimeout to 360. 

However, as per this bz comments, where I can see PassengerTimeout value set to 600?

/etc/httpd/conf.d/05-foreman.conf

Thanks Lzap.

[root@dhcp201-103 yum.repos.d]# cat /etc/httpd/conf.d/05-foreman.conf | grep PassengerStartTimeout
PassengerStartTimeout 600
[root@dhcp201-103 yum.repos.d]# 

So I tried installation on two diff nodes, one with 8 cores and 12G ram and other on a VM with 2 cores and 4G ram.

And didn't see any issue. So moving this to verified.

This was delivered with 6.0.3, which is the Satellite 6 Beta.

This was delivered in 6.0.3, the Beta version of Satellite 6.0