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

Added by Alex Guzun about 9 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 Alex Guzun about 9 years ago

Damn.. nothing.
Server rebooted, cookies deleted

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.0, 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)

Guys im lost.. what to do?
How can i reinstall stable version using the same DB?

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

It may by due to the new per-user-salt.

Did you run rake db:migrate ?
Do you have a salt column in you users table, is it filled with something for your admin user ?

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

C:\redmine>rake db:migrate
(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)
rake aborted!
Access denied for user 'root'@'localhost' (using password: NO)

(See full trace by running task with --trace)

C:\redmine>rake db:migrate RAILS_ENV=production
(in C:/redmine)

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>

reboot, nothing.. can't login
What do you mean by mysql, what to check, please? what should it be in there?

Thank you

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

A column named "salt" at the end of your "users" table.

It should contain a hash value (except for the Anonymous user record).

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

im using phpmyadmin and when i do BROWSE for USERS i can see hashed_password for everyone, except Anonymous

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

And what about the salt column (see source:trunk/db/migrate/20110223180944_add_users_salt.rb) ?

Did you migrate your db before importing data ?

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

Importing data? What do you mean? It is raw redmine from the beginning, no trac or other stuff.
Salt? i have no salt...
i tried to find salt word in my exported redmine.sql file and found only this:

DROP TABLE IF EXISTS `open_id_authentication_nonces`;
/*!40101 SET saved_cs_client = @character_set_client /;
/
!40101 SET character_set_client = utf8 /;
CREATE TABLE `open_id_authentication_nonces` (
`id` int(11) NOT NULL auto_increment,
`timestamp` int(11) NOT NULL,
`server_url` varchar(255) default NULL,
`salt` varchar(255) NOT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
/
!40101 SET character_set_client = @saved_cs_client */;

Structure of the live sql user table is:

id
login
hashed_password
firstname
lastname
mail
mail_notification
admin
status
last_login_on
language
auth_source_id
created_on
updated_on
type
identity_url

no salt

i think something is wrong, maybe something changed when rake db:migrate RAILS_ENV=production after 1.0dev to 1.2dev

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

strange thing: when i enter wrong pass im getting: Invalid user or password
so it can check pass ;)

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

What's your 1.1.2 devel revision ?

Guess this can't be latest or else you would have a salt column after migration.

Anyway, your latest comment make think that it's not related to this salt thing...

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

Redmine 1.1.2.devel.5121 (MySQL)
from monday i think

any more logs req, to solve this, please?
We are stuck from monday :(
few people can make changes.. those are still logged in (remembered credentials in browser with remember me)

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

You say you're running devel, so maybe could you just override and update from SVN trunk and run migrations ?

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

Does the syntax rake db:migrate RAILS_ENV=production really work with windows ?

Shouldn't you use

set RAILS_ENV=production
rake db:migrate

instead ?

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

C:\redmine>svn update

A vendor\plugins\open_id_authentication

.

.

.

U lib\redcloth3.rb

Conflict discovered in 'public/javascripts/application.js'.

Select: (p) postpone, (df) diff-full, (e) edit,

(mc) mine-conflict, (tc) theirs-conflict,

(s) show all options: tf

G public\javascripts\application.js

Updated to revision 5164.

here i updated application.js, coz mine was patched...

C:\redmine>set RAILS_ENV=production

C:\redmine>rake db:migrate
(in C:/redmine)

C:\redmine>

rebooted, cookies deleted, no luck again

p.s. how to reset production.log, coz no it has about 32MB (and it is updated not realtime, need to wait to get actual logz)

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

p.s. how to reset production.log, coz no it has about 32MB (and it is updated not realtime, need to wait to get actual logz)

Remove it or edit it and suppress its contents.

Could you attach the contents of your schema_migrations table, please ?

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

PS : did you try again after update, session & cache clean and server restart ?

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

yes... it gave me
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>

then i restarted mongrel

Table: schema_migrations
version

1
1-advanced_roadmap
10
100
101
102
103
104
105
106
107
108
11
12
13
14
15
16
17
18
19
2
2-advanced_roadmap
20
20090214190337
20090312172426
20090312194159
20090318181151
20090323224724
20090401221305

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

Is that all ?

Please join the full contents in an attached file.

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

p.s. after last step, i have salt column with hashes ;)

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

exactly... restarted server, removed cookies

RE: Upgrade from 1.0dev to 1.1.2.devel - can't login or Error 500 - Added by Klaus-Peter Webersinke about 9 years ago

Just upgraded to last version from trunk and having the same problem: login is not possible !

always getting

Processing AccountController#login (for 127.0.0.1 at 2011-03-18 00:10:49) [GET]
  Parameters: {"action"=>"login", "controller"=>"account"}
Rendering template within layouts/base
Rendering account/login
Completed in 13816ms (View: 13781, DB: 27) | 200 OK [http://127.0.0.1/login]

Processing AccountController#login (for 127.0.0.1 at 2011-03-18 00:11:44) [POST]
  Parameters: {"action"=>"login", "authenticity_token"=>"JST/bj+jjM254iSDmM7siN326nbc5wB+LIR2gI0iL8g=", "username"=>"kpw", "controller"=>"account", "password"=>"[FILTERED]", "login"=>"Anmelden \302\273"}

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'

svn info shows :

URL: http://redmine.rubyforge.org/svn/trunk
Repository Root: http://redmine.rubyforge.org/svn
Repository UUID: e93f8b46-1217-0410-a6f0-8f06a7374b81
Revision: 5164
Node Kind: directory
Schedule: normal
Last Changed Author: tmaruyama
Last Changed Rev: 5164
Last Changed Date: 2011-03-17 04:54:22 +0100 (Do, 17 Mrz 2011)

and yes rake db:migrate was running without any error....

What's wrong here ????

many regards,
kpw

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

Welcome aboard ;)

C:\redmine>svn info
Path: .
URL: http://redmine.rubyforge.org/svn/trunk
Repository Root: http://redmine.rubyforge.org/svn
Repository UUID: e93f8b46-1217-0410-a6f0-8f06a7374b81
Revision: 5164
Node Kind: directory
Schedule: normal
Last Changed Author: tmaruyama
Last Changed Rev: 5164
Last Changed Date: 2011-03-17 04:54:22 +0100 (št, 17 3 2011)

1 2 3 (26-50/59)