Redmine

No, this time it crashed at:

[[4;35;1mChange Create (0.2ms)[[0m   [[0mINSERT INTO `changes` (`changeset_id`, `action`, `branch`, `path`, `revision`, `from_path`, `from_revision`) VALUES(5436, 'A', NULL, '/3rdparty/xxxx', NULL, NULL, NULL)[[0m
  [[4;36;1mSQL (3.5ms)[[0m   [[0;1mCOMMIT[[0m
before svn command
Shelling out: svn --trust-server-cert --config-dir /usr/share/redmine/svn log --xml -r 153:103 --username xxxx --password xxxx --no-auth-cache --non-interactive --verbose  'https://xxxx/svn/xxxx/'

Not important, but looks like 49 would be cleaner than 50.

What if you comment the Changeset#after_create_part (source:tags/1.1.1/app/models/changeset.rb#L95) ?

Interesting! After I commented that out, I navigated to the repository page and after a minute or two received the usual 500 error. After checking out the logs I noticed that the first svn command had started at revisions 150-100 and then gone up to 200-150 as if 0-100 were done. So I refreshed the page and after a few seconds it loaded with all the info in place (revision, age, author, comments, file structure, diffs). The log shows that on the second page load it finished off the remaining revisions as I had suspected it would, 200 through the HEAD (275).

Maybe it's just a coincidence, but it looks like the last two times it crashed it occurred immediately after "shelling out" the svn command to start on the third range of revisions. Last time it crashed when starting 100-150 after doing 0-50 and 50-100. This time it crashed on 200-250 after doing 100-150 and 150-200.

[[4;35;1mSQL (3.0ms)[[0m   [[0mCOMMIT[[0m
before svn command
Shelling out: svn --trust-server-cert --config-dir /usr/share/redmine/svn log --xml -r 255:205 --username xxxx --password xxxx --no-auth-cache --non-interactive --verbose  'https://xxxx/svn/xxxx/'

Errno::ENOMEM (Cannot allocate memory - svn --trust-server-cert --config-dir /usr/share/redmine/svn log --xml -r 255:205 --username 'xxxx' --password 'xxxx' --no-auth-cache --non-interactive --verbose 'https://xxxx/svn/xxxx/'):
lib/redmine/scm/adapters/abstract_adapter.rb:191:in `popen'
lib/redmine/scm/adapters/abstract_adapter.rb:191:in `shellout'
lib/redmine/scm/adapters/abstract_adapter.rb:177:in `shellout'
lib/redmine/scm/adapters/subversion_adapter.rb:148:in `revisions'
app/models/repository/subversion.rb:56:in `fetch_changesets'
app/controllers/repositories_controller.rb:77:in `show'
/usr/lib/ruby/1.8/phusion_passenger/rack/request_handler.rb:95:in `process_request'
/usr/lib/ruby/1.8/phusion_passenger/abstract_request_handler.rb:207:in `main_loop'
/usr/lib/ruby/1.8/phusion_passenger/railz/application_spawner.rb:374:in `start_request_handler'
/usr/lib/ruby/1.8/phusion_passenger/railz/application_spawner.rb:332:in `handle_spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/utils.rb:184:in `safe_fork'
/usr/lib/ruby/1.8/phusion_passenger/railz/application_spawner.rb:330:in `handle_spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:352:in `__send__'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:352:in `main_loop'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:196:in `start_synchronously'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:163:in `start'
/usr/lib/ruby/1.8/phusion_passenger/railz/application_spawner.rb:209:in `start'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:262:in `spawn_rails_application'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server_collection.rb:126:in `lookup_or_add'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:256:in `spawn_rails_application'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server_collection.rb:80:in `synchronize'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server_collection.rb:79:in `synchronize'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:255:in `spawn_rails_application'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:154:in `spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:287:in `handle_spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:352:in `__send__'

I forgot to mention, it may be obvious but it seems like changing the increment from 199 to 49 was the "solution". I've uncommented after_create_part and it still works. Maybe the default increment should be lower? Or is it only beneficial in unusually large repositories like this one?

Anthony C wrote:

I noticed that the first svn command had started at revisions 150-100 and then gone up to 200-150 as if 0-100 were done.

Guess this could be due to the "no transaction" test you've done earlier ?

What's your Ruby 1.8.7 patch level ?

Etienne Massip wrote:

Guess this could be due to the "no transaction" test you've done earlier?

That was my thought too, and the logs agree.

Ruby info:

ii ruby 4.2
ii ruby1.8 1.8.7.249-2
ii ruby1.8-dev 1.8.7.249-2
ii rubygems 1.3.5-1ubuntu2
ii rubygems1.8 1.3.5-1ubuntu2

More info for you. I removed the repository to go through the process of adding it again. I noticed that unless I use the libxml backend I get a 500 error with nothing in the log.

Works:
ActiveSupport::XmlMini.backend = 'LibXML'
doc = ActiveSupport::XmlMini.parse(output)

Doesn't work:
#ActiveSupport::XmlMini.backend = 'LibXML'
doc = ActiveSupport::XmlMini.parse(output)

Also, this time Ruby crashed after the first 50 revisions and then after the next 150 and on the third attempt finished loading everything. So there's not a pattern of when it crashes.

In summary, it works only if the two next conditions are met :

• Xml parsing lib is set to 'LibXml'
• revisions step is lowered (49 / 50)

Then you don't have any error and the process run fully to its end.

Any other combination will cause a OOM SIGKILL.

Is that it ?

If those two conditions are met ruby still ends with an OOM SIGKILL the first two times Redmine tries to download and parse all the information, but after that the process completes successfully and the page functions normally.

Within transaction ?

Sorry, I'm not sure what you are asking.

Sorry, I meant : the transaction block was not commented (= transaction was used) ?

Correct, I didn't see a difference with it commented out.