Hello,
I have no experience with ruby or rails, please correct me if there is
something wrong / not clear in this post.
I have redmine 1.3 with few custom plugins running under unicorn_rails
v4.3.1. Every time, after plugins upgrade and unicorn restart, redmine
throws weird errors on ~30% requests on specific urls for few days and
then
it stops. (by these few days i always restarted it few times per day). I
am
writing in hope someone could help me with fixing or debugging this
issue
(i am pretty sure this is not redmine-specific issue).
(by plugins upgrade i mean putting new / overwriting files in
./vendor/plugins/plugin_name. No db:migrate or other things)
So, after yesterdays update it shows error on this url: /issues/993. The
error is:
ActiveRecord::StatementInvalid in IssuesController#show
Mysql::Error: Unknown column ‘changesets.989’ in ‘field list’: SELECT
changesets.id AS t0_r0, changesets.989 AS t0_r1,
repositories.id AS t1_r0, repositories.project_id AS t1_r1 (…)
RAILS_ROOT: /home/redmine/redmine-1.3
(…)
As you can see in select statement instead of column name i have number.
This is always the case (i mean, number instead of column name, not this
specific number or this specific column). Today this is consistent (i.e.
everytime, when error shows under that url, this number is there); i am
pretty sure last time (few weeks ago) it was different number. I can
refresh that page and it loads without problems in about 2/3 times. I
have
full trace from that error page, it looks like this (i removed “not
important” parts for readability):
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/connection_adapters/abstract_adapter.rb:227:in
log' /var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/connection_adapters/mysql_adapter.rb:324:inexecute’
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/connection_adapters/mysql_adapter.rb:639:in
select' /var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/(...) /var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/base.rb:619:infind’
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/base.rb:639:in
all' /var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/(...) /var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/named_scope.rb:118:inwith_scope’
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/named_scope.rb:179:in
method_missing' /home/redmine/redmine-1.3/app/controllers/issues_controller.rb:117:inshow’
/var/lib/gems/1.8/gems/(…)
/var/lib/gems/1.8/gems/unicorn-4.3.1/bin/unicorn_rails:209
/usr/local/bin/unicorn_rails:19:in `load’
/usr/local/bin/unicorn_rails:19
In this case, code goes in only one file in RAILS_ROOT:
app/controllers/issues_controller.rb. It looks like this:
111 def show
112 @journals = @issue.journals.find(:all, :include => [:user,
:details], :order => “#{Journal.table_name}.created_on ASC”)
113 @journals.each_with_index {|j,i| j.indice = i+1}
114 @journals.reverse! if
User.current.wants_comments_in_reverse_order?
115
116 if User.current.allowed_to?(:view_changesets, @project)
117 @changesets = @issue.changesets.visible.all
118 @changesets.reverse! if
User.current.wants_comments_in_reverse_order?
119 end
I have full (i think full) logs from this, from both failing requests
and
working one; I can upload them to e.g. pastebin. This app still shows
errors (and will until i restart unicorn i think) so if you have any
advices how to extract more informations from it i will gladly obey. I
am
pretty sure this is not programming issue; maybe active_record have
cache
in filesystem / database that persist between unicorn restarts and
becomes
corrupted after file changes or outdated / broken ruby version?