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

Added by Alex Guzun about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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 about 8 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)