ActiveRecord::StatementInvalid errors after upgrading from foreman 1.0 to 1.2

Hi all,

I'm running Scientific Linux 6.4 on the server with Apache and
mod_passenger, puppet 3.0.1 and puppetDB 1.3.2 and I upgraded from Foreman
1.0 to 1.2 today using the foreman repo

I followed the instructions at
http://www.theforeman.org/manuals/1.2/index.html#3.3.1RPMPackages and I ran
the dbmigrate script as well.
Server is up and running and things seem to be working for the most part,
hosts can connect, get their definitions and catalogs and run puppet
successfully.

However sometimes when browsing through the web interface I'll get random
error messages like:

··· -- Oops, we're sorry but something went wrong

x Mysql::Error: : SELECT users.* FROM users WHERE users.id = ?
LIMIT 1
If you feel this is an error with Foreman itself, please open a new issue
with Foreman ticketing system, You would probably need to attach the Full
trace and relevant log entries.

ActiveRecord::StatementInvalid
Mysql::Error: : SELECT users.* FROM users WHERE users.id = ? LIMIT 1
app/controllers/application_controller.rb:71:in require_login' lib/foreman/thread_session.rb:31:inclear_thread’
Back

And I keep getting errors in the /var/log/foreman/production.log file like:


Started GET “/puppetclasses/services::puppetserver/edit” for 10.130.49.176
at 2013-08-07 14:04:04 -0700
Processing by PuppetclassesController#edit as HTML
Parameters: {“id”=>“services::puppetserver”}
Operation FAILED: Mysql::Error: : SELECT users.* FROM users WHERE
users.id = ? LIMIT 1
Rendered common/500.html.erb within layouts/application (2.8ms)
Completed 500 Internal Server Error in 8ms (Views: 6.0ms | ActiveRecord:
0.2ms)

ActiveRecord::StatementInvalid (Mysql::Error: : INSERT INTO sessions
(created_at, data, session_id, updated_at) VALUES (?, ?, ?, ?)):

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in
`process_request’

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in
`accept_and_process_next_request’

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in
`main_loop’

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in
`block (3 levels) in start_threads’

Started GET “/statistics” for 10.130.49.176 at 2013-08-07 14:23:25 -0700
Processing by StatisticsController#index as HTML
Operation FAILED: Mysql::Error: : SELECT environments.* FROM
environments WHERE environments.id = ? ORDER BY environments.name
LIMIT 1
Rendered common/500.html.erb within layouts/application (5.9ms)
Completed 500 Internal Server Error in 36ms (Views: 9.0ms | ActiveRecord:
15.5ms)

Started GET “/hosts/auto_complete_search?search=is+ma” for 10.130.49.176 at
2013-08-07 14:24:28 -0700
Processing by HostsController#auto_complete_search as JSON
Parameters: {“search”=>“is ma”}
Operation FAILED: Mysql::Error: : SELECT users.* FROM users WHERE
users.id = ? LIMIT 1
Rendered common/500.html.erb (3.8ms)
Completed 500 Internal Server Error in 8ms (Views: 4.6ms | ActiveRecord:
0.3ms)

Started GET “/statistics” for 10.130.49.176 at 2013-08-07 15:50:35 -0700
Processing by StatisticsController#index as HTML
Operation FAILED: Mysql::Error: : SELECT users.* FROM users WHERE
users.id = ? LIMIT 1
Rendered common/500.html.erb within layouts/application (4.8ms)
Completed 500 Internal Server Error in 14ms (Views: 10.9ms | ActiveRecord:
0.3ms)

Started GET “/reports/3319935” for 10.130.49.176 at 2013-08-07 16:47:17
-0700
Processing by ReportsController#show as HTML
Parameters: {“id”=>“3319935”}
Operation FAILED: Mysql::Error: : SELECT reports.* FROM reports WHERE
reports.id = ? LIMIT 1
Rendered common/500.html.erb within layouts/application (3.0ms)
Completed 500 Internal Server Error in 8ms (Views: 5.0ms | ActiveRecord:
1.0ms)

Started POST “/fact_values/create?format=yml” for 10.130.48.13 at
2013-08-07 16:50:34 -0700
Processing by FactValuesController#create as YML
Parameters: {“facts”=>"[FILTERED]"}
Failed to save irv6b-213.corp.blizzard.net: Mysql::Error: : INSERT INTO
fact_values (created_at, fact_name_id, host_id, updated_at,
value) VALUES (?, ?, ?, ?, ?)
Rendered text template (0.0ms)
Completed 200 OK in 45ms (Views: 0.6ms | ActiveRecord: 11.5ms)

ActiveRecord::StatementInvalid (Mysql::Error: : INSERT INTO sessions
(created_at, data, session_id, updated_at) VALUES (?, ?, ?, ?)):

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in
`process_request’

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in
`accept_and_process_next_request’

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in
`main_loop’

/usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in
`block (3 levels) in start_threads’

Has anyone seen this before or has any idea what could be going on?

This does not happen all the time, it only happens periodically.

Joey,

without further investigation, can you first clear all cookies from your
browser? Or at least those related to your instance.

OR

You can log on using an Anonymous Tab which is in any decent internet
browser, that should be cookie free. See if you experience similar
issues first.

If that does not help, delete all sessions from your instance (you can
google that - delete session rails).

LZ

··· On Wed, Aug 07, 2013 at 06:26:19PM -0700, Joey wrote: > Hi all, > > I'm running Scientific Linux 6.4 on the server with Apache and > mod_passenger, puppet 3.0.1 and puppetDB 1.3.2 and I upgraded from Foreman > 1.0 to 1.2 today using the foreman repo > > I followed the instructions at > http://www.theforeman.org/manuals/1.2/index.html#3.3.1RPMPackages and I ran > the dbmigrate script as well. > Server is up and running and things seem to be working for the most part, > hosts can connect, get their definitions and catalogs and run puppet > successfully. > > However sometimes when browsing through the web interface I'll get random > error messages like: > > -- > Oops, we're sorry but something went wrong > > x Mysql::Error: : SELECT `users`.* FROM `users` WHERE `users`.`id` = ? > LIMIT 1 > If you feel this is an error with Foreman itself, please open a new issue > with Foreman ticketing system, You would probably need to attach the Full > trace and relevant log entries. > > ActiveRecord::StatementInvalid > Mysql::Error: : SELECT `users`.* FROM `users` WHERE `users`.`id` = ? LIMIT 1 > app/controllers/application_controller.rb:71:in `require_login' > lib/foreman/thread_session.rb:31:in `clear_thread' > Back > -- > > And I keep getting errors in the /var/log/foreman/production.log file like: > > -- > Started GET "/puppetclasses/services::puppetserver/edit" for 10.130.49.176 > at 2013-08-07 14:04:04 -0700 > Processing by PuppetclassesController#edit as HTML > Parameters: {"id"=>"services::puppetserver"} > Operation FAILED: Mysql::Error: : SELECT `users`.* FROM `users` WHERE > `users`.`id` = ? LIMIT 1 > Rendered common/500.html.erb within layouts/application (2.8ms) > Completed 500 Internal Server Error in 8ms (Views: 6.0ms | ActiveRecord: > 0.2ms) > > ActiveRecord::StatementInvalid (Mysql::Error: : INSERT INTO `sessions` > (`created_at`, `data`, `session_id`, `updated_at`) VALUES (?, ?, ?, ?)): > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in > `process_request' > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in > `accept_and_process_next_request' > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in > `main_loop' > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in > `block (3 levels) in start_threads' > > Started GET "/statistics" for 10.130.49.176 at 2013-08-07 14:23:25 -0700 > Processing by StatisticsController#index as HTML > Operation FAILED: Mysql::Error: : SELECT `environments`.* FROM > `environments` WHERE `environments`.`id` = ? ORDER BY environments.name > LIMIT 1 > Rendered common/500.html.erb within layouts/application (5.9ms) > Completed 500 Internal Server Error in 36ms (Views: 9.0ms | ActiveRecord: > 15.5ms) > > Started GET "/hosts/auto_complete_search?search=is+ma" for 10.130.49.176 at > 2013-08-07 14:24:28 -0700 > Processing by HostsController#auto_complete_search as JSON > Parameters: {"search"=>"is ma"} > Operation FAILED: Mysql::Error: : SELECT `users`.* FROM `users` WHERE > `users`.`id` = ? LIMIT 1 > Rendered common/500.html.erb (3.8ms) > Completed 500 Internal Server Error in 8ms (Views: 4.6ms | ActiveRecord: > 0.3ms) > > Started GET "/statistics" for 10.130.49.176 at 2013-08-07 15:50:35 -0700 > Processing by StatisticsController#index as HTML > Operation FAILED: Mysql::Error: : SELECT `users`.* FROM `users` WHERE > `users`.`id` = ? LIMIT 1 > Rendered common/500.html.erb within layouts/application (4.8ms) > Completed 500 Internal Server Error in 14ms (Views: 10.9ms | ActiveRecord: > 0.3ms) > > Started GET "/reports/3319935" for 10.130.49.176 at 2013-08-07 16:47:17 > -0700 > Processing by ReportsController#show as HTML > Parameters: {"id"=>"3319935"} > Operation FAILED: Mysql::Error: : SELECT `reports`.* FROM `reports` WHERE > `reports`.`id` = ? LIMIT 1 > Rendered common/500.html.erb within layouts/application (3.0ms) > Completed 500 Internal Server Error in 8ms (Views: 5.0ms | ActiveRecord: > 1.0ms) > > Started POST "/fact_values/create?format=yml" for 10.130.48.13 at > 2013-08-07 16:50:34 -0700 > Processing by FactValuesController#create as YML > Parameters: {"facts"=>"[FILTERED]"} > Failed to save irv6b-213.corp.blizzard.net: Mysql::Error: : INSERT INTO > `fact_values` (`created_at`, `fact_name_id`, `host_id`, `updated_at`, > `value`) VALUES (?, ?, ?, ?, ?) > Rendered text template (0.0ms) > Completed 200 OK in 45ms (Views: 0.6ms | ActiveRecord: 11.5ms) > > ActiveRecord::StatementInvalid (Mysql::Error: : INSERT INTO `sessions` > (`created_at`, `data`, `session_id`, `updated_at`) VALUES (?, ?, ?, ?)): > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in > `process_request' > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in > `accept_and_process_next_request' > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in > `main_loop' > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in > `block (3 levels) in start_threads' > > -- > > Has anyone seen this before or has any idea what could be going on? > > This does not happen all the time, it only happens periodically. > > -- > You received this message because you are subscribed to the Google Groups "Foreman users" group. > To unsubscribe from this group and stop receiving emails from it, send an email to foreman-users+unsubscribe@googlegroups.com. > To post to this group, send email to foreman-users@googlegroups.com. > Visit this group at http://groups.google.com/group/foreman-users. > For more options, visit https://groups.google.com/groups/opt_out. > >


Later,

Lukas “lzap” Zapletal
irc: lzap #theforeman

Hey,

I had already tried clearing all browsing data, including cookies from my
browser and still had the issue.
I was also seeing the issue in the logs from nodes connecting to foreman
with puppet.

However I switched my database adapter from mysql to mysql2 and that seemed
to resolve the issue.

Thank you for the reply though!

Best regards

Joey

··· On Thursday, August 8, 2013 7:42:19 AM UTC-7, Lukas Zapletal wrote: > > Joey, > > without further investigation, can you first clear all cookies from your > browser? Or at least those related to your instance. > > OR > > You can log on using an Anonymous Tab which is in any decent internet > browser, that should be cookie free. See if you experience similar > issues first. > > If that does not help, delete all sessions from your instance (you can > google that - delete session rails). > > LZ > > On Wed, Aug 07, 2013 at 06:26:19PM -0700, Joey wrote: > > Hi all, > > > > I'm running Scientific Linux 6.4 on the server with Apache and > > mod_passenger, puppet 3.0.1 and puppetDB 1.3.2 and I upgraded from > Foreman > > 1.0 to 1.2 today using the foreman repo > > > > I followed the instructions at > > http://www.theforeman.org/manuals/1.2/index.html#3.3.1RPMPackages and I > ran > > the dbmigrate script as well. > > Server is up and running and things seem to be working for the most > part, > > hosts can connect, get their definitions and catalogs and run puppet > > successfully. > > > > However sometimes when browsing through the web interface I'll get > random > > error messages like: > > > > -- > > Oops, we're sorry but something went wrong > > > > x Mysql::Error: : SELECT `users`.* FROM `users` WHERE `users`.`id` = ? > > LIMIT 1 > > If you feel this is an error with Foreman itself, please open a new > issue > > with Foreman ticketing system, You would probably need to attach the > Full > > trace and relevant log entries. > > > > ActiveRecord::StatementInvalid > > Mysql::Error: : SELECT `users`.* FROM `users` WHERE `users`.`id` = ? > LIMIT 1 > > app/controllers/application_controller.rb:71:in `require_login' > > lib/foreman/thread_session.rb:31:in `clear_thread' > > Back > > -- > > > > And I keep getting errors in the /var/log/foreman/production.log file > like: > > > > -- > > Started GET "/puppetclasses/services::puppetserver/edit" for > 10.130.49.176 > > at 2013-08-07 14:04:04 -0700 > > Processing by PuppetclassesController#edit as HTML > > Parameters: {"id"=>"services::puppetserver"} > > Operation FAILED: Mysql::Error: : SELECT `users`.* FROM `users` WHERE > > `users`.`id` = ? LIMIT 1 > > Rendered common/500.html.erb within layouts/application (2.8ms) > > Completed 500 Internal Server Error in 8ms (Views: 6.0ms | ActiveRecord: > > 0.2ms) > > > > ActiveRecord::StatementInvalid (Mysql::Error: : INSERT INTO `sessions` > > (`created_at`, `data`, `session_id`, `updated_at`) VALUES (?, ?, ?, ?)): > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in > > > `process_request' > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in > > > `accept_and_process_next_request' > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in > > > `main_loop' > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in > > > `block (3 levels) in start_threads' > > > > Started GET "/statistics" for 10.130.49.176 at 2013-08-07 14:23:25 -0700 > > Processing by StatisticsController#index as HTML > > Operation FAILED: Mysql::Error: : SELECT `environments`.* FROM > > `environments` WHERE `environments`.`id` = ? ORDER BY environments.name > > LIMIT 1 > > Rendered common/500.html.erb within layouts/application (5.9ms) > > Completed 500 Internal Server Error in 36ms (Views: 9.0ms | > ActiveRecord: > > 15.5ms) > > > > Started GET "/hosts/auto_complete_search?search=is+ma" for 10.130.49.176 > at > > 2013-08-07 14:24:28 -0700 > > Processing by HostsController#auto_complete_search as JSON > > Parameters: {"search"=>"is ma"} > > Operation FAILED: Mysql::Error: : SELECT `users`.* FROM `users` WHERE > > `users`.`id` = ? LIMIT 1 > > Rendered common/500.html.erb (3.8ms) > > Completed 500 Internal Server Error in 8ms (Views: 4.6ms | ActiveRecord: > > 0.3ms) > > > > Started GET "/statistics" for 10.130.49.176 at 2013-08-07 15:50:35 -0700 > > Processing by StatisticsController#index as HTML > > Operation FAILED: Mysql::Error: : SELECT `users`.* FROM `users` WHERE > > `users`.`id` = ? LIMIT 1 > > Rendered common/500.html.erb within layouts/application (4.8ms) > > Completed 500 Internal Server Error in 14ms (Views: 10.9ms | > ActiveRecord: > > 0.3ms) > > > > Started GET "/reports/3319935" for 10.130.49.176 at 2013-08-07 16:47:17 > > -0700 > > Processing by ReportsController#show as HTML > > Parameters: {"id"=>"3319935"} > > Operation FAILED: Mysql::Error: : SELECT `reports`.* FROM `reports` > WHERE > > `reports`.`id` = ? LIMIT 1 > > Rendered common/500.html.erb within layouts/application (3.0ms) > > Completed 500 Internal Server Error in 8ms (Views: 5.0ms | ActiveRecord: > > 1.0ms) > > > > Started POST "/fact_values/create?format=yml" for 10.130.48.13 at > > 2013-08-07 16:50:34 -0700 > > Processing by FactValuesController#create as YML > > Parameters: {"facts"=>"[FILTERED]"} > > Failed to save irv6b-213.corp.blizzard.net: Mysql::Error: : INSERT INTO > > `fact_values` (`created_at`, `fact_name_id`, `host_id`, `updated_at`, > > `value`) VALUES (?, ?, ?, ?, ?) > > Rendered text template (0.0ms) > > Completed 200 OK in 45ms (Views: 0.6ms | ActiveRecord: 11.5ms) > > > > ActiveRecord::StatementInvalid (Mysql::Error: : INSERT INTO `sessions` > > (`created_at`, `data`, `session_id`, `updated_at`) VALUES (?, ?, ?, ?)): > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in > > > `process_request' > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:140:in > > > `accept_and_process_next_request' > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler/thread_handler.rb:108:in > > > `main_loop' > > > > > /usr/lib/ruby/gems/1.8/gems/passenger-4.0.5/lib/phusion_passenger/request_handler.rb:441:in > > > `block (3 levels) in start_threads' > > > > -- > > > > Has anyone seen this before or has any idea what could be going on? > > > > This does not happen all the time, it only happens periodically. > > > > -- > > You received this message because you are subscribed to the Google > Groups "Foreman users" group. > > To unsubscribe from this group and stop receiving emails from it, send > an email to foreman-user...@googlegroups.com . > > To post to this group, send email to forema...@googlegroups.com. > > > Visit this group at http://groups.google.com/group/foreman-users. > > For more options, visit https://groups.google.com/groups/opt_out. > > > > > > -- > Later, > > Lukas "lzap" Zapletal > irc: lzap #theforeman >