Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500

Added by Alex Guzun over 10 years ago

Hi guys... im using redmine from 0.8 i think and always made SVN update with no issues.
Few days ago i made another update, this one required some rail/gems update.. all went fine. After service restart for me all was fine, but for some other guys not.

When they open main page they see:

Internal error

An error occurred on the page you were trying to access.
If you continue to experience problems please contact your redMine administrator for assistance.

Back

URL remains: http://server/login

when you want to browse Projects (http://server/projects), they are getting:

Oops! This link appears to be broken. (in Chrome)
The webpage cannot be found (IE)

But they can open link: http://server/projects/clientapp/issues directly

Also they can't loging (Internal Error)

In production.log i have:

Processing AccountController#login (for 10.0.0.207 at 2011-03-14 08:31:46) [GET]
Parameters: {"action"=>"login", "controller"=>"account"}
Rendering template within layouts/base
Rendering account/login
Completed in 21ms (View: 17, DB: 2) | 200 OK [http://server/login]

Processing AccountController#login (for 10.0.0.207 at 2011-03-14 08:31:54) [GET]
Parameters: {"action"=>"login", "controller"=>"account"}
Rendering template within layouts/base
Rendering account/login
Completed in 21ms (View: 18, DB: 1) | 200 OK [http://server/login]

Processing AccountController#login (for 10.0.0.207 at 2011-03-14 08:32:05) [POST]
Parameters: {"action"=>"login", "authenticity_token"=>"gM292Oh3fsn32kJCuTFzUyhXjL0hM9tJAMDACXqo9e4=", "username"=>"domainuser", "controller"=>"account", "password"=>"[FILTERED]", "login"=>"Prihlásiť »"}

NoMethodError (undefined method `destroy' for {}:Hash):
app/controllers/application_controller.rb:89:in `logged_user='
app/controllers/account_controller.rb:203:in `successful_authentication'
app/controllers/account_controller.rb:155:in `password_authentication'
app/controllers/account_controller.rb:142:in `authenticate_user'
app/controllers/account_controller.rb:30:in `login'

Rendering c:/redmine/public/500.html (500 Internal Server Error)

Processing AccountController#login (for 10.0.0.207 at 2011-03-14 08:32:32) [POST]
Parameters: {"action"=>"login", "authenticity_token"=>"gM292Oh3fsn32kJCuTFzUyhXjL0hM9tJAMDACXqo9e4=", "username"=>"domainuser", "controller"=>"account", "password"=>"[FILTERED]", "login"=>"Prihlásiť »"}

NoMethodError (undefined method `destroy' for {}:Hash):
app/controllers/application_controller.rb:89:in `logged_user='
app/controllers/account_controller.rb:203:in `successful_authentication'
app/controllers/account_controller.rb:155:in `password_authentication'
app/controllers/account_controller.rb:142:in `authenticate_user'
app/controllers/account_controller.rb:30:in `login'

Rendering c:/redmine/public/500.html (500 Internal Server Error)

Processing AccountController#login (for 10.0.0.207 at 2011-03-14 08:33:30) [POST]
Parameters: {"back_url"=>"http%3A%2F%2Fserver%3A3000%2Flogin", "action"=>"login", "authenticity_token"=>"v7QKLNAqWY+kSlMSlOwEh3CdvX+qRCOdA+59Oces40I=", "username"=>"domainuser", "controller"=>"account", "password"=>"[FILTERED]", "login"=>"Prihlásiť »"}

NoMethodError (undefined method `destroy' for {}:Hash):
app/controllers/application_controller.rb:89:in `logged_user='
app/controllers/account_controller.rb:203:in `successful_authentication'
app/controllers/account_controller.rb:155:in `password_authentication'
app/controllers/account_controller.rb:142:in `authenticate_user'
app/controllers/account_controller.rb:30:in `login'

Rendering c:/redmine/public/500.html (500 Internal Server Error)

Strange thing is, my redmine server is running on port 3000, so main page url is: http://server:3000/ and this port is seen in last part of the log ( Parameters: {"back_url"=>"http%3A%2F%2Fserver%3A3000%2Flogin", "action"=>"login", ) but some logs have only server address and no port (Completed in 21ms (View: 18, DB: 1) | 200 OK [http://server/login])

And all this is happening to users who has no stored and remembered browser session. Those guys who has login:pass stored and remembered whole redmine acts like it should be, no problems at all, all can be opened and browsed.

Some errors when i migrated db:

C:\redmine>rake tmp:cache:clear
(in C:/redmine)
DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks and vendor/plugins/open_id_authentication/tasks are deprecated. Use lib/tasks instead.
(called from C:/Ruby/lib/ruby/gems/1.8/gems/rails-2.3.11/lib/tasks/rails.rb:10)

C:\redmine>rake tmp:sessions:clear
(in C:/redmine)
DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks and vendor/plugins/open_id_authentication/tasks are deprecated. Use lib/tasks instead.
(called from C:/Ruby/lib/ruby/gems/1.8/gems/rails-2.3.11/lib/tasks/rails.rb:10)

C:\redmine>rake config/initializers/session_store.rb
(in C:/redmine)
DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks and vendor/plugins/open_id_authentication/tasks are deprecated. Use lib/tasks instead.
(called from C:/Ruby/lib/ruby/gems/1.8/gems/rails-2.3.11/lib/tasks/rails.rb:10)

My local gems:

C:\redmine>gem list --local

  • LOCAL GEMS ***

actionmailer (2.3.11, 2.3.5)
actionpack (2.3.11, 2.3.5)
activerecord (2.3.11, 2.3.5)
activeresource (2.3.11, 2.3.5)
activesupport (2.3.11, 2.3.5)
cgi_multipart_eof_fix (2.5.0)
fxri (0.3.6)
fxruby (1.6.16)
gem_plugin (0.2.3)
hpricot (0.6.164)
i18n (0.4.2)
log4r (1.0.5)
mongrel (1.1.5)
mongrel_service (0.3.4)
mysql (2.8.1)
ptools (1.1.6)
rack (1.1.1, 1.0.1)
rails (2.3.11, 2.3.5)
rake (0.8.7, 0.8.1)
ruby-opengl (0.60.0)
test-unit (2.0.1)
win32-api (1.2.1, 1.2.0)
win32-clipboard (0.4.4)
win32-dir (0.3.2)
win32-eventlog (0.5.0)
win32-file (0.5.5)
win32-file-stat (1.3.1)
win32-process (0.5.9)
win32-sapi (0.1.4)
win32-service (0.5.2)
win32-sound (0.4.1)
windows-api (0.2.4)
windows-pr (0.9.3)

Please how to solve this annoying issue? My team can't work :(
Thank you in advance.
Alex

Replies (59)

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

Guess this is related to this Rails 2.3.11 issue.

There's a monkey patch in the issue thread you can try.

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

moved

c:\redmine\vendor\plugins\engines\tasks\engines.rake

to

c:\redmine\lib\tasks\engines.rake

and made some clears... didn't help

removed open_id_authentication plugin and made pluginmigrate, didn't help :(

You can see the same problem in build log:
http://www.redmine.org/builds/index.html
Revision r5126 (build 192 started on Mar 14, 2011 12:20:25 PM): success (build log)

DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks and vendor/plugins/open_id_authentication/tasks are deprecated. Use lib/tasks instead. (called from /var/lib/gems/1.8/gems/rails-2.3.11/lib/tasks/rails.rb:10)

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

I applied this patch:

https://github.com/robdimarco/rails/commit/8ca8ac379d8a2d10f39fdef67db545732fe95309

not working

and can't find

_./actionpack/lib/action_controller/session/abstract_store.rb (original):

def session
@env['rack.session'] ||= {}
end
  • def reset_session*
    session.destroy if session
    self.session = {}
    end_

in

c:\Ruby\lib\ruby\gems\1.8\gems\actionpack-2.3.11\lib\action_controller\session\abstract_store.rb

P.s. is it ok to have two version of rail when i do gem list --local

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

can't find

def reset_session
session.destroy if session
self.session = {}
end

in

c:\Ruby\lib\ruby\gems\1.8\gems\actionpack-2.3.11\lib\action_controller\session\abstract_store.rb

:(

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

i only can find

def reset_session

session.destroy if session

self.session = {}

end

in

c:\Ruby\lib\ruby\gems\1.8\gems\actionpack-2.3.11\lib\action_controller\request.rb

not in abstract_store.rb
Anyway.. changed it, restarted redmine, same problem :( but a little bit better, after entering login:pass i got redirect page to /my/page/.. then Not Found again

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

The patch is supposed to be applied to request.rb

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

can you please check you request.rb in actionpack-2.3.11 if it has

def reset_session

session.destroy if session

self.session = {}

end

And line number (attach it, please if possibe)
My file has nothing like this :(

And i can't restore DB, coz after few days there was a lot of traffic over redmine i can just ignore it :(

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

Yes, it has.

You just told the opposite ?!

i only can find

def reset_session
session.destroy if session
self.session = {}
end
in c:\Ruby\lib\ruby\gems\1.8\gems\actionpack-2.3.11\lib\action_controller\request.rb

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

sorry, yes.. but it doesn't work for me :(

Is it ok to have this?

C:\redmine>gem list

  • LOCAL GEMS ***

actionmailer (2.3.11, 2.3.5)

actionpack (2.3.11, 2.3.5)

activerecord (2.3.11, 2.3.5)

activeresource (2.3.11, 2.3.5)

activesupport (2.3.11, 2.3.5)

cgi_multipart_eof_fix (2.5.0)

fxri (0.3.6)

fxruby (1.6.16)

gem_plugin (0.2.3)

hpricot (0.6.164)

i18n (0.4.2)

log4r (1.0.5)

mongrel (1.1.5)

mongrel_service (0.3.4)

mysql (2.8.1)

ptools (1.1.6)

rack (1.1.1, 1.0.1)

rails (2.3.11, 2.3.5)

rake (0.8.7, 0.8.1)

ruby-opengl (0.60.0)

test-unit (2.0.1)

win32-api (1.2.1, 1.2.0)

win32-clipboard (0.4.4)

win32-dir (0.3.2)

win32-eventlog (0.5.0)

win32-file (0.5.5)

win32-file-stat (1.3.1)

win32-process (0.5.9)

win32-sapi (0.1.4)

win32-service (0.5.2)

win32-sound (0.4.1)

windows-api (0.2.4)

windows-pr (0.9.3)

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

Yes. It won't work until you restart your server.

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

Hardware was rebooted several times, i restarted it again now and no luck.

Processing WelcomeController#index (for 10.0.0.40 at 2011-03-14 17:09:24) [GET]
Parameters: {"action"=>"index", "controller"=>"welcome"}
Rendering template within layouts/base
Rendering welcome/index
Completed in 571ms (View: 226, DB: 306) | 200 OK [http://server/] no 3000 port here

Processing AccountController#login (for 10.0.0.40 at 2011-03-14 17:09:31) [GET]
Parameters: {"action"=>"login", "controller"=>"account"}
Rendering template within layouts/base
Rendering account/login
Completed in 21654ms (View: 21640, DB: 3) | 200 OK [http://server/login] no 3000 port here

Processing WelcomeController#index (for 10.0.0.147 at 2011-03-14 17:09:52) [GET]
Parameters: {"action"=>"index", "controller"=>"welcome"}
Rendering template within layouts/base
Rendering welcome/index
Completed in 3338ms (View: 3270, DB: 41) | 200 OK [http://server/] no 3000 port here

Processing AccountController#login (for 10.0.0.40 at 2011-03-14 17:09:59) [POST]
Parameters: {"action"=>"login", "authenticity_token"=>"+boghXfA0aB0D3daltCx6DXTCJTD9KX8dmGk2VyWaVk=", "username"=>"admin", "autologin"=>"1", "controller"=>"account", "password"=>"[FILTERED]", "login"=>"Login »"}
Redirected to http://server:3000/my/page
Completed in 95ms (DB: 28) | 302 Found [http://server/login] no 3000 port here

Processing MyController#page (for 10.0.0.40 at 2011-03-14 17:10:10) [GET]
Parameters: {"action"=>"page", "controller"=>"my"}
Redirected to http://server:3000/login?back_url=http%3A%2F%2Fmercury.ardaco.com%3A3000%2Fmy%2Fpage
Filter chain halted as [:require_login] rendered_or_redirected.
Completed in 8ms (DB: 1) | 302 Found [http://mercury.ardaco.com/my/page] no 3000 port here

+++++++++++++
+++++++++++++

The required Ruby and Ruby on Rails versions for a given Redmine version is:
Redmine version - current trunk
Supported Ruby versions - ruby 1.8.6, 1.8.7
Required Rails version - Rails 2.3.11
Required Rack version - Rack 1.1.0

and i have

current trunk
rails (2.3.11, 2.3.5)
rack (1.1.1, 1.0.1)

Should i remove rails 2.3.5 and remove all racks to install Rack 1.1.0 (i have 1.1.1 and 1.0.1)

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

one more update, after this patch those who had redmine without issue got problem to open anything from main page. I mean, main page can be opened but not any link to projects or issues :(

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

This patch can't break anything.

If something is broken, then the patch has not been well applied.

Moreover, port is never displayed in response url.

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

The "Internal error" problem must be fixed with the patch, so what is exactly your problem ?

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

So you still have some "NoMethodError (undefined method `destroy' for {}:Hash):" errors in log ?
Otherwise, there is another bug with Rails 2.3.11 and AJAX requests (so not during login), see #7843.

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

My c:\Ruby\lib\ruby\gems\1.8\gems\actionpack-2.3.11\lib\action_controller\request.rb
at line 448 looks like this now

def reset_session

#session.destroy if session

#session may be a hash, if so, we do not want to call destroy

#fixes issue 6440

session.destroy if session and session.respond_to?(:destroy)

self.session = {}

end

after reboot redmine page renders blank.

So i applied this patch:
http://www.redmine.org/attachments/5570/ajax_session_reset.patch

and almost all is working like it should be :)
One more thing, i can't login...
i enter loginname:pass hit enter i im redirected to -> http://server:3000/login with text:

You are being redirected.

Redirected URL is: http://server:3000/my/page

When i click this link im getting the page where i was before (projects or issue number.. whatever)

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

Try to clear session and cache and reboot server again ?

If this does not work, please post the content of the log file.

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

C:\redmine>rake tmp:cache:clear
(in C:/redmine)
DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks are deprecated. Use lib/tasks instead. (called from C:/Ruby/lib/ruby/gems/1.8/gems/rai
ls-2.3.11/lib/tasks/rails.rb:10)

C:\redmine>rake tmp:sessions:clear
(in C:/redmine)
DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks are deprecated. Use lib/tasks instead. (called from C:/Ruby/lib/ruby/gems/1.8/gems/rai
ls-2.3.11/lib/tasks/rails.rb:10)

C:\redmine>

nothing!

log:

Processing WelcomeController#index (for 10.0.0.40 at 2011-03-15 10:32:04) [GET]
Parameters: {"action"=>"index", "controller"=>"welcome"}
Rendering template within layouts/base
Rendering welcome/index
Completed in 56ms (View: 35, DB: 11) | 200 OK [http://server/]

Processing ProjectsController#show (for 10.0.0.40 at 2011-03-15 10:32:12) [GET]
Parameters: {"action"=>"show", "id"=>"etask", "controller"=>"projects"}
Rendering template within layouts/base
Rendering projects/show
Completed in 163ms (View: 71, DB: 40) | 200 OK [http://server/projects/etask]

Processing AccountController#login (for 10.0.0.40 at 2011-03-15 10:32:16) [GET]
Parameters: {"action"=>"login", "controller"=>"account"}
Rendering template within layouts/base
Rendering account/login
Completed in 26ms (View: 20, DB: 4) | 200 OK [http://server/login]

Processing AccountController#login (for 10.0.0.40 at 2011-03-15 10:32:18) [POST]
Parameters: {"back_url"=>"http%3A%2F%2Fserver%3A3000%2Fprojects%2Fetask", "action"=>"login", "authenticity_token"=>"KfzmuxZlvSHeOLbivhcreYK1cVUMhyfoVuRXhbbZET0=", "username"=>"admin", "controller"=>"account", "password"=>"[FILTERED]", "login"=>"Login »"}
Redirected to http://server:3000/projects/etask
Completed in 17ms (DB: 3) | 302 Found [http://server/login]

Processing ProjectsController#show (for 10.0.0.40 at 2011-03-15 10:32:22) [GET]
Parameters: {"action"=>"show", "id"=>"etask", "controller"=>"projects"}
Rendering template within layouts/base
Rendering projects/show
Completed in 284ms (View: 191, DB: 38) | 200 OK [http://server/projects/etask]

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

but login was not remembered :(

How to fix

C:\redmine>rake tmp:cache:clear

(in C:/redmine)

DEPRECATION WARNING: Rake tasks in vendor/plugins/engines/tasks are deprecated. Use lib/tasks instead. >(called from C:/Ruby/lib/ruby/gems/1.8/gems/rai
ls-2.3.11/lib/tasks/rails.rb:10)

and.. should i create new session_store?

rake config/initializers/session_store.rb

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Etienne Massip over 10 years ago

No, don't need to.

Could you describe what happens precisely, maybe remove your session cookies ?

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Alex Guzun over 10 years ago

Cookies are deleted, server is restarted...
im going to redmine main page, then klick to projects, for example.. it opens, then i click login (upper right url), redmine renders login page, i enter login:pass hit enter i im redirected to -> http://server:3000/login with text:

You are being redirected.

Redirected URL is: http://server:3000/projects

When i click this link im getting the page where i was before (projects or issue number.. whatever)
And still not logged in :(

1 2 3 (1-25/59)