500 error on main page on some projects

[anarcat]

I got a 500 error after deploying this plugin, but only on certain projects:

ActionView::TemplateError (undefined method `[]' for nil:NilClass) on line #22 of vendor/plugins/redmine_git_hosting/app/views/projects/_git_urls.erb:
19:                     guGitUser="<%= Setting.plugin_redmine_git_hosting['gitUser'] %>";
20:                     guGitServer="<%= Setting.plugin_redmine_git_hosting['gitServer'] %>";
21:                     guHttpBase="<%= GitHosting.my_root_url %>";
22:                     guHttpProto="<%= @project.repository.extra[:git_http].to_s == "2" ? "http" : "https" %>";
23:
24:                     if (!(window.Event === undefined) && !(Event.observe === undefined)) {
25:                             Event.observe(window,"load", setGitUrlOnload);

    vendor/plugins/redmine_git_hosting/app/views/projects/_git_urls.erb:22
    /usr/lib/ruby/1.8/action_view/helpers/capture_helper.rb:36:in `call'
    /usr/lib/ruby/1.8/action_view/helpers/capture_helper.rb:36:in `capture'
    /usr/lib/ruby/1.8/action_view/helpers/capture_helper.rb:129:in `with_output_buffer'
    /usr/lib/ruby/1.8/action_view/helpers/capture_helper.rb:36:in `capture'
    /usr/lib/ruby/1.8/action_view/helpers/capture_helper.rb:120:in `content_for'
    app/helpers/application_helper.rb:856:in `content_for'
    vendor/plugins/redmine_git_hosting/app/views/projects/_git_urls.erb:2
    /usr/lib/ruby/1.8/action_view/renderable.rb:34:in `send'
    /usr/lib/ruby/1.8/action_view/renderable.rb:34:in `render'
    /usr/lib/ruby/1.8/action_view/base.rb:306:in `with_template'
    /usr/lib/ruby/1.8/action_view/renderable.rb:30:in `render'
    /usr/lib/ruby/1.8/action_view/renderable_partial.rb:20:in `render'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:30:in `benchmark'
    /usr/lib/ruby/1.8/action_view/renderable_partial.rb:19:in `render'
    /usr/lib/ruby/1.8/action_view/template.rb:205:in `render_template'
    /usr/lib/ruby/1.8/action_view/renderable_partial.rb:44:in `render_partial'
    /usr/lib/ruby/1.8/action_view/partials.rb:184:in `render_partial'
    /usr/lib/ruby/1.8/action_view/base.rb:267:in `render'
    /usr/lib/ruby/1.8/action_controller/base.rb:973:in `render_without_benchmark'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:51:in `render'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:51:in `render'
    /usr/lib/ruby/1.8/action_controller/base.rb:995:in `render_to_string'
    lib/redmine/hook.rb:113:in `send'
    lib/redmine/hook.rb:113:in `view_projects_show_left'
    lib/redmine/hook.rb:63:in `send'
    lib/redmine/hook.rb:63:in `call_hook'
    lib/redmine/hook.rb:63:in `each'
    lib/redmine/hook.rb:63:in `call_hook'
    lib/redmine/hook.rb:60:in `tap'
    lib/redmine/hook.rb:60:in `call_hook'
    lib/redmine/hook.rb:144:in `call_hook'
    app/views/projects/show.rhtml:50:in `_run_rhtml_app47views47projects47show46rhtml'
    /usr/lib/ruby/1.8/action_view/renderable.rb:34:in `send'
    /usr/lib/ruby/1.8/action_view/renderable.rb:34:in `render'
    /usr/lib/ruby/1.8/action_view/base.rb:306:in `with_template'
    /usr/lib/ruby/1.8/action_view/renderable.rb:30:in `render'
    /usr/lib/ruby/1.8/action_view/template.rb:205:in `render_template'
    /usr/lib/ruby/1.8/action_view/base.rb:265:in `render'
    /usr/lib/ruby/1.8/action_view/base.rb:348:in `_render_with_layout'
    /usr/lib/ruby/1.8/action_view/base.rb:262:in `render'
    /usr/lib/ruby/1.8/action_controller/base.rb:1250:in `render_for_file'
    /usr/lib/ruby/1.8/action_controller/base.rb:951:in `render_without_benchmark'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:51:in `render'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:51:in `render'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:135:in `send'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:135:in `custom'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:179:in `call'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:179:in `respond'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:173:in `each'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:173:in `respond'
    /usr/lib/ruby/1.8/action_controller/mime_responds.rb:107:in `respond_to'
    app/controllers/projects_controller.rb:166:in `show'
    /usr/lib/ruby/1.8/action_controller/base.rb:1331:in `send'
    /usr/lib/ruby/1.8/action_controller/base.rb:1331:in `perform_action_without_filters'
    /usr/lib/ruby/1.8/action_controller/filters.rb:617:in `call_filters'
    /usr/lib/ruby/1.8/action_controller/filters.rb:610:in `perform_action_without_benchmark'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:68:in `perform_action_without_rescue'
    /usr/lib/ruby/1.8/action_controller/benchmarking.rb:68:in `perform_action_without_rescue'
    /usr/lib/ruby/1.8/action_controller/rescue.rb:160:in `perform_action_without_flash'
    /usr/lib/ruby/1.8/action_controller/flash.rb:146:in `perform_action'
    /usr/lib/ruby/1.8/action_controller/base.rb:532:in `send'
    /usr/lib/ruby/1.8/action_controller/base.rb:532:in `process_without_filters'
    /usr/lib/ruby/1.8/action_controller/filters.rb:606:in `process'
    /usr/lib/ruby/1.8/action_controller/base.rb:391:in `process'
    /usr/lib/ruby/1.8/action_controller/base.rb:386:in `call'
    /usr/lib/ruby/1.8/action_controller/routing/route_set.rb:437:in `call'
    /usr/lib/ruby/1.8/action_controller/dispatcher.rb:87:in `dispatch'
    /usr/lib/ruby/1.8/action_controller/dispatcher.rb:121:in `_call'
    /usr/lib/ruby/1.8/action_controller/dispatcher.rb:130:in `build_middleware_stack'
    /usr/lib/ruby/1.8/active_record/query_cache.rb:29:in `call'
    /usr/lib/ruby/1.8/active_record/query_cache.rb:29:in `call'
    /usr/lib/ruby/1.8/active_record/connection_adapters/abstract/query_cache.rb:34:in `cache'
    /usr/lib/ruby/1.8/active_record/query_cache.rb:9:in `cache'
    /usr/lib/ruby/1.8/active_record/query_cache.rb:28:in `call'
    /usr/lib/ruby/1.8/active_record/connection_adapters/abstract/connection_pool.rb:361:in `call'
    /usr/lib/ruby/1.8/action_controller/string_coercion.rb:25:in `call'
    /usr/lib/ruby/1.8/rack/head.rb:9:in `call'
    /usr/lib/ruby/1.8/rack/methodoverride.rb:24:in `call'
    /usr/lib/ruby/1.8/action_controller/params_parser.rb:15:in `call'
    /usr/lib/ruby/1.8/action_controller/session/cookie_store.rb:93:in `call'
    /usr/lib/ruby/1.8/action_controller/failsafe.rb:26:in `call'
    /usr/lib/ruby/1.8/rack/lock.rb:11:in `call'
    /usr/lib/ruby/1.8/rack/lock.rb:11:in `synchronize'
    /usr/lib/ruby/1.8/rack/lock.rb:11:in `call'
    /usr/lib/ruby/1.8/action_controller/dispatcher.rb:106:in `call'
    /usr/lib/ruby/1.8/phusion_passenger/rack/request_handler.rb:92: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:418:in `start_request_handler'
    /usr/lib/ruby/1.8/phusion_passenger/railz/application_spawner.rb:358: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:354: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:213: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__'
    /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/phusion_passenger/passenger-spawn-server:61

Rendering /usr/share/redmine/public/500.html (500 Internal Server Error)

[anarcat]

That project also yields 500 errors when i save the main settings page:

NoMethodError (undefined method `git_daemon' for nil:NilClass):
  /usr/lib/ruby/1.8/action_controller/base.rb:1331:in `send'
  /usr/lib/ruby/1.8/action_controller/base.rb:1331:in `perform_action_without_filters'
  /usr/lib/ruby/1.8/action_controller/filters.rb:617:in `call_filters'
  /usr/lib/ruby/1.8/action_controller/filters.rb:610:in `perform_action_without_benchmark'
  /usr/lib/ruby/1.8/action_controller/benchmarking.rb:68:in `perform_action_without_rescue'
  /usr/lib/ruby/1.8/action_controller/benchmarking.rb:68:in `perform_action_without_rescue'
  /usr/lib/ruby/1.8/action_controller/rescue.rb:160:in `perform_action_without_flash'
  /usr/lib/ruby/1.8/action_controller/flash.rb:146:in `perform_action'
  /usr/lib/ruby/1.8/action_controller/base.rb:532:in `send'
  /usr/lib/ruby/1.8/action_controller/base.rb:532:in `process_without_filters'
  /usr/lib/ruby/1.8/action_controller/filters.rb:606:in `process'
  /usr/lib/ruby/1.8/action_controller/base.rb:391:in `process'
  /usr/lib/ruby/1.8/action_controller/base.rb:386:in `call'
  /usr/lib/ruby/1.8/action_controller/routing/route_set.rb:437:in `call'
  /usr/lib/ruby/1.8/action_controller/dispatcher.rb:87:in `dispatch'
  /usr/lib/ruby/1.8/action_controller/dispatcher.rb:121:in `_call'
  /usr/lib/ruby/1.8/action_controller/dispatcher.rb:130:in `build_middleware_stack'
  /usr/lib/ruby/1.8/active_record/query_cache.rb:29:in `call'
  /usr/lib/ruby/1.8/active_record/query_cache.rb:29:in `call'
  /usr/lib/ruby/1.8/active_record/connection_adapters/abstract/query_cache.rb:34:in `cache'
  /usr/lib/ruby/1.8/active_record/query_cache.rb:9:in `cache'
  /usr/lib/ruby/1.8/active_record/query_cache.rb:28:in `call'
  /usr/lib/ruby/1.8/active_record/connection_adapters/abstract/connection_pool.rb:361:in `call'
  /usr/lib/ruby/1.8/action_controller/string_coercion.rb:25:in `call'
  /usr/lib/ruby/1.8/rack/head.rb:9:in `call'
  /usr/lib/ruby/1.8/rack/methodoverride.rb:24:in `call'
  /usr/lib/ruby/1.8/action_controller/params_parser.rb:15:in `call'
  /usr/lib/ruby/1.8/action_controller/session/cookie_store.rb:93:in `call'
  /usr/lib/ruby/1.8/action_controller/failsafe.rb:26:in `call'
  /usr/lib/ruby/1.8/rack/lock.rb:11:in `call'
  /usr/lib/ruby/1.8/rack/lock.rb:11:in `synchronize'
  /usr/lib/ruby/1.8/rack/lock.rb:11:in `call'
  /usr/lib/ruby/1.8/action_controller/dispatcher.rb:106:in `call'
  /usr/lib/ruby/1.8/phusion_passenger/rack/request_handler.rb:92: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:418:in `start_request_handler'
  /usr/lib/ruby/1.8/phusion_passenger/railz/application_spawner.rb:358: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:354: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:213: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__'
  /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/phusion_passenger/passenger-spawn-server:61

Rendering /usr/share/redmine/public/500.html (500 Internal Server Error)

[anarcat]

Alright, I found out that some projects do not have any entry in git_repository_extras, with the following request:

SELECT p.name, r.id, r.url, g . * 
FROM  `projects` p
LEFT JOIN  `repositories` r ON r.project_id = p.id
LEFT JOIN  `git_repository_extras` g ON g.repository_id = r.id
WHERE g.id IS NULL 
AND r.id IS NOT NULL ;

And with the following I could insert valid data in the table that fix the 500 error:

INSERT INTO git_repository_extras( repository_id, git_daemon, git_http, notify_cia ) 
SELECT repositories.id AS repository_id, 1 AS git_daemon, 0 AS git_http, 0 AS notify_cia
FROM  `repositories` 
LEFT JOIN  `git_repository_extras` g ON g.repository_id = repositories.id
WHERE g.id IS NULL 
AND repositories.id IS NOT NULL

You'll notice that I do not create a valid value for the key column - I am not sure how to do that in SQL, and I do not know what that column is for so I am just skipping it for now.

It seems to me important that the plugin should recover if data is corrupted like this, no?

[kubitron]

Ok. See if my answer to #23 helps in this regard. I suspect that you have a problem with the size of entries that the cache is attempting to put into mysql (assuming you are using mysql?)

[anarcat]

I am using MySQL. This is a shared server so I cannot change the max packet size, which is currently set to 16M. I don't understand why there would be more than 16M of data sent into the database anyways, especially since the corrupted table contains fairly small columns.

Which cache is being sent there?

Update: anyways, the cache setting in the plugin is set to max 16M, so it shouldn't be trying to cache more than 16M at a time...

[kubitron]

Oops. I missed your comment on the missing git_repositories_extras.

Did you remember to run rake db:migrate_plugins?

Assuming that the answer is "yes", how were these weird projects created? Were they pre-existing? Are new projects ok?

[kubitron]

Now that I think of this, I'm pretty confused on how you got into that state... Did you import projects into redmine after getting the plugin configured?

[kubitron]

I'm going to wait for you to get back to me on this. I could certainly put in something so that an update_repositories operation fixed the extra data, but the fact that it is missing really leads me to worry about what else is wrong. If we can figure out (1) how this happened and (2) whether it was a reasonable-enough use-case to put in support for it.

Note that migration from earlier versions of Redmine (if that is what you did) is a very tricky business. You really need to get all the old projects loaded first, then run rake db:migrate and rake db:migrate_plugins, which will fix up changes to the db schema that have occurred over time. Now, it is possible that the migrate_plugins operation that was supposed to add the extra data is broken (another option). However, once db:migrate_plugins has been run on a particular db, then it won't have any effect later (keeps track of which migrations were run).

[anarcat]

I did run db:migrate_plugins during the install. Those projects were pre-existing. New projects are okay.

And no, I didn't import new projects into redmine after the plugin was installed. Mystery! :)

I guess it is possible that some Redmine upgrade went wrong at some point... Anyways, at this point I fixed the stuff manually for me, if it happens again it will be more of a concern...

[kubitron]

Ok. Please pull the testing branch. One of the two commits there should fix this problem. I realized that, if you somehow managed to invoke this problem, then someone else might in the future.

Please do the following: go back into mysql and delete the git_repository_extra structures that you added. Then, try executing an update_repositories operation. Everything should correct itself (and you should see a bunch of messages in the log about repairing or installing "hooks").

Note that you need the "key" in order to make sure that pushes to the repos get properly reflected in redmine. Thus, you are not actually operating well without them....

[anarcat]

here is the result of my tests: removing the git_repository_extra entry for a project doesn't reproduce the bug anymore. It looks like even the web interface restores the entry in the extra table.

I have even been able to truncate the table and run the update_repositories hook to regenerate the whole thing, which is nice, because there were two entries per project, for some strange reason. Now there is only one entry per repository. One thing though: the generated entries do not respect the defaults set in the configuration (e.g. the git_http flag was set even though it is unset in the config).

Regardless: this works well enough for my needs, thanks!

I think this is now completely fixed for our production uses, congratulations on your plugin, it's great!

[kubitron]

Before you completely close this out, can you try it again and see if the defaults are properly set in the git_repository_extras entries, (my theory is that they are just not being reflected properly in the interface)? As far as I can tell, it appears that these should be fine....

[kubitron]

Also, I'm assuming that the defaults are properly set on new projects...?

[anarcat]

No, the database itself is wrong. Not just the interface.

New projects also have the same problem though, so that's a separate issue...

[kubitron]

Ok. Pull from master now. Hopefully all will be well. (Obvious mistake, in retrospect).

I've deleted the testing branch.

[kubitron]

After you make sure that the issue with defaults is fixed, please close again.

[anarcat]

this works, thanks.