Project

General

Profile

[SOLVED] Redmine stopped working after updated and reboot

Added by Oscar Edvardsson over 8 years ago

Hi,

I'm having some problems with our Redmine installation and would greatly appreciate any help!

Symptoms

I recently updated Redmine to 3.2 from 3.1, which worked fine. However, when I did some server maintenance the other day I rebooted the server for the first time since the upgrade (I believe). It will now not start (preloader times out). I'm redirected to a Passenger error page, but it does not output any real error (the raw output is (empty)). The output in the Apache log is the following.

[ 2016-02-24 08:25:17.8434 6628/7efdf3c1e700 age/Cor/App/Implementation.cpp:304 ]: Could not spawn process for application /usr/share/redmine: An error occurred while starting up the preloader: it did not write a startup response in time.
  Error ID: 1e8099d5
  Error details saved to: /tmp/passenger-error-xkR3xU.html
  Message from application: An error occurred while starting up the preloader: it did not write a startup response in time. Please read <a href="https://github.com/phusion/passenger/wiki/Debugging-application-startup-problems">this article</a> for more information about this problem.<br>
<h2>Raw process output:</h2>
(empty)

[ 2016-02-24 08:25:17.8558 6628/7efdedc25700 age/Cor/Con/CheckoutSession.cpp:277 ]: [Client 1-1] Cannot checkout session because a spawning error occurred. The identifier of the error is 1e8099d5. Please see earlier logs for details about the error.
[ 2016-02-24 08:25:17.8558 6628/7efded424700 age/Cor/Con/CheckoutSession.cpp:277 ]: [Client 2-1] Cannot checkout session because a spawning error occurred. The identifier of the error is 1e8099d5. Please see earlier logs for details about the error.
App 7318 stdout: 

The server works for the rest of what its being used for (Mercurial repository and file server).

Tested

I followed the Passenger debugging page, but either I didn't understand it properly or those were not the issue.

I also tried hosting the pre-update instance of Redmine, which did not work either.

I have triple verified permissions (which I believe would have given an other error anyway).

Any help in debugging this would be greatly appreciated! I'm not very familiar with Ruby or Passenger, so I'm having a hard time finding what is actually causing it to not start up.

Info

I have attached the HTML page that is displayed, which contains most variables. The more general are listed here.

OS Ubuntu Server 14.04 LTS
Web  Apache2
Redmine 3.2
Ruby 1.9.1

Replies (4)

RE: Redmine stopped working after updated and reboot - Added by Pavel Potcheptsov over 8 years ago

First of all you need to look on production.log and try to start embedded webrick server.

RE: Redmine stopped working after updated and reboot - Added by Oscar Edvardsson over 8 years ago

Thanks for your reply!

The production.log does not actually log any messages since the issue started to appear.

I didn't know there was a WEBrick server - neat! Thanks.
However, I can't make much sense of the output. I can not access the server on the specified IP and port. And it wonders if it is running on host "masked.com" with an IP that I bet is external. I would assume that port 5453 is blocked from outside, but I'm on the same (local) network. I do am running a DNS server as well on the server. I get the following. It takes quite a while before Exiting (and the rest) appears.

I'm using Postgresql and I can access the database from the terminal and it appears to contain all tables (55 or so of them).

sudo bin/rails server -e production -b 192.168.1.100
=> Booting WEBrick
=> Rails 4.2.3 application starting in production on http://192.168.1.100:3000
=> Run `rails server -h` for more startup options
=> Ctrl-C to shutdown server
Exiting
/var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:655:in `initialize': could not connect to server: Connection timed out (PG::ConnectionBad)
    Is the server running on host "masked.com" (XX.XXX.XXX.XXX) and accepting
    TCP/IP connections on port 5432?
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:655:in `new'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:655:in `connect'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:242:in `initialize'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:44:in `new'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:44:in `postgresql_connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:438:in `new_connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:448:in `checkout_new_connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:422:in `acquire_connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:349:in `block in checkout'
    from /usr/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:348:in `checkout'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:263:in `block in connection'
    from /usr/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:262:in `connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:571:in `retrieve_connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_handling.rb:113:in `retrieve_connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/connection_handling.rb:87:in `connection'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/model_schema.rb:230:in `table_exists?'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/attribute_methods/primary_key.rb:97:in `get_primary_key'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/attribute_methods/primary_key.rb:85:in `reset_primary_key'
    from /var/lib/gems/1.9.1/gems/activerecord-4.2.3/lib/active_record/attribute_methods/primary_key.rb:73:in `primary_key'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_record/mass_assignment_security/attribute_assignment.rb:15:in `attributes_protected_by_default'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:337:in `block in protected_attributes_configs'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:222:in `yield'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:222:in `default'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:222:in `protected_attributes'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:126:in `block in attr_protected'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:125:in `each'
    from /var/lib/gems/1.9.1/gems/protected_attributes-1.1.3/lib/active_model/mass_assignment_security.rb:125:in `attr_protected'
    from /usr/share/redmine-3.1.0/app/models/custom_field.rb:32:in `<class:CustomField>'
    from /usr/share/redmine-3.1.0/app/models/custom_field.rb:18:in `<top (required)>'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `block in require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:240:in `load_dependency'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:360:in `require_or_load'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:494:in `load_missing_constant'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:184:in `const_missing'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:526:in `load_missing_constant'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:184:in `const_missing'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:526:in `load_missing_constant'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:184:in `const_missing'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:526:in `load_missing_constant'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:184:in `const_missing'
    from /usr/share/redmine-3.1.0/lib/redmine/field_format.rb:83:in `field_attributes'
    from /usr/share/redmine-3.1.0/lib/redmine/field_format.rb:86:in `<class:Base>'
    from /usr/share/redmine-3.1.0/lib/redmine/field_format.rb:48:in `<module:FieldFormat>'
    from /usr/share/redmine-3.1.0/lib/redmine/field_format.rb:19:in `<module:Redmine>'
    from /usr/share/redmine-3.1.0/lib/redmine/field_format.rb:18:in `<top (required)>'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `block in require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:240:in `load_dependency'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /usr/share/redmine-3.1.0/lib/redmine.rb:38:in `<top (required)>'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `block in require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:240:in `load_dependency'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /usr/share/redmine-3.1.0/config/initializers/30-redmine.rb:6:in `<top (required)>'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:268:in `load'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:268:in `block in load'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:240:in `load_dependency'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:268:in `load'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/engine.rb:652:in `block in load_config_initializer'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/notifications.rb:166:in `instrument'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/engine.rb:651:in `load_config_initializer'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/engine.rb:616:in `block (2 levels) in <class:Engine>'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/engine.rb:615:in `each'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/engine.rb:615:in `block in <class:Engine>'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/initializable.rb:30:in `instance_exec'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/initializable.rb:30:in `run'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/initializable.rb:55:in `block in run_initializers'
    from /usr/lib/ruby/1.9.1/tsort.rb:150:in `block in tsort_each'
    from /usr/lib/ruby/1.9.1/tsort.rb:183:in `block (2 levels) in each_strongly_connected_component'
    from /usr/lib/ruby/1.9.1/tsort.rb:210:in `block (2 levels) in each_strongly_connected_component_from'
    from /usr/lib/ruby/1.9.1/tsort.rb:219:in `each_strongly_connected_component_from'
    from /usr/lib/ruby/1.9.1/tsort.rb:209:in `block in each_strongly_connected_component_from'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/initializable.rb:44:in `each'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/initializable.rb:44:in `tsort_each_child'
    from /usr/lib/ruby/1.9.1/tsort.rb:203:in `each_strongly_connected_component_from'
    from /usr/lib/ruby/1.9.1/tsort.rb:182:in `block in each_strongly_connected_component'
    from /usr/lib/ruby/1.9.1/tsort.rb:180:in `each'
    from /usr/lib/ruby/1.9.1/tsort.rb:180:in `each_strongly_connected_component'
    from /usr/lib/ruby/1.9.1/tsort.rb:148:in `tsort_each'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/initializable.rb:54:in `run_initializers'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/application.rb:352:in `initialize!'
    from /usr/share/redmine-3.1.0/config/environment.rb:14:in `<top (required)>'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `block in require'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:240:in `load_dependency'
    from /var/lib/gems/1.9.1/gems/activesupport-4.2.3/lib/active_support/dependencies.rb:274:in `require'
    from /usr/share/redmine-3.1.0/config.ru:3:in `block in <main>'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/builder.rb:55:in `instance_eval'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/builder.rb:55:in `initialize'
    from /usr/share/redmine-3.1.0/config.ru:in `new'
    from /usr/share/redmine-3.1.0/config.ru:in `<main>'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/builder.rb:49:in `eval'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/builder.rb:49:in `new_from_string'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/builder.rb:40:in `parse_file'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/server.rb:299:in `build_app_and_options_from_config'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/server.rb:208:in `app'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands/server.rb:61:in `app'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/server.rb:336:in `wrapped_app'
    from /var/lib/gems/1.9.1/gems/rack-1.6.4/lib/rack/server.rb:272:in `start'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands/server.rb:80:in `start'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:80:in `block in server'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:75:in `tap'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:75:in `server'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:39:in `run_command!'
    from /var/lib/gems/1.9.1/gems/railties-4.2.3/lib/rails/commands.rb:17:in `<top (required)>'
    from bin/rails:4:in `require'
    from bin/rails:4:in `<main>'

RE: Redmine stopped working after updated and reboot - Added by Pavel Potcheptsov over 8 years ago

So redmine and database are on different servers and you can connect to database but redmine host can't.
Do you have a static IP configuration on redmine?
Maybe after reboot redmine got a new IP and there is restriction in database to accept specific user from specific IP for redmine database?
Try to telnet to host that specified in database.yml from redmine server:

telnet database_IP 5432

You can also might want to disable firewalls on redmine and on database hosts and maybe on gateways between them just for testing connectivity.

RE: Redmine stopped working after updated and reboot - Added by Oscar Edvardsson over 8 years ago

Ah, its so obvious now.

The database actually runs on the same machine, but (I don't really remember why) the database configuration was set to use masked.com, instead of localhost. For some reason, it would not resolve masked.com to the IP it was assigned to (not sure why though, since it works on all other machines on the network), but would try to reach a server outside of the network. That's obviously a bad idea. Now I just need to figure out why the server don't resolve the IP to itself. Man I'm dumb.

Sorry about that! A ton of thanks!

    (1-4/4)