ActiveRecord::UnknownAttributeError: unknown attribute 'provision_method' for Host::Managed

Hello there!

I'm having an isolated issue on one of the Foreman (separate) instances,
where I can't deploy Libvirt VMs into compute resources anymore.

A standard procedure (through UI):
New Host
put a hostname for a new VM
pick a compute resource to deploy on

At this point I see that "Interfaces" tab goes red and if I go to it, I see
this message:

Error loading interfaces information: Internal Server Error

My production.log show me this:

2016-10-19 16:31:19 5e8f4434 [app] [I] Started POST "/hosts/interfaces" for
10.153.47.145 at 2016-10-19 16:31:19 -0700
2016-10-19 16:31:19 5e8f4434 [app] [I] Processing by
HostsController#interfaces as /
2016-10-19 16:31:19 5e8f4434 [app] [I] Parameters: {"utf8"=>"✓",
"authenticity_token"=>"VBTeVRN/84DLh57lDE+A5zZrn62aGfoZ4+UcKqzhKJ4pAcEYI8P9MDsE3VnRCkrT9kJ0rpBJTrHHGu6jWB+VlA==",
"host"=>{"salt_module_ids"=>[""], "name"=>"kim-magwire",
"hostgroup_id"=>"", "compute_resource_id"=>"13", "compute_profile_id"=>"",
"environment_id"=>"", "puppet_proxy_id"=>"", "salt_environment_id"=>"",
"salt_proxy_id"=>"", "managed"=>"true", "progress_report_id"=>"[FILTERED]",
"type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0",
"type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"kim-magwire",
"domain_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"1",
"provision"=>"1", "execution"=>"1", "virtual"=>"0", "tag"=>"",
"attached_to"=>""}}, "compute_attributes"=>{"cpus"=>"1",
"memory"=>"805306368", "start"=>"1",
"volumes_attributes"=>{"0"=>{"_delete"=>"", "pool_name"=>"default",
"capacity"=>"10G", "allocation"=>"0G", "format_type"=>"raw"}}},
"architecture_id"=>"", "provision_method"=>"build", "build"=>"1",
"disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"1-Users",
"enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"},
"capabilities"=>"build image", "provider"=>"Libvirt",
"fakepassword"=>"[FILTERED]", "bare_metal_capabilities"=>"build"}
2016-10-19 16:31:19 5e8f4434 [app] [W] Action failed
> ActiveRecord::UnknownAttributeError: unknown attribute
'provision_method' for Host::Managed.
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:59:in
rescue in _assign_attribute' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:54:in_assign_attribute'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:41:in
block in assign_attributes' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/strong_parameters.rb:185:ineach_pair'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/strong_parameters.rb:185:in
each_pair' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:35:inassign_attributes'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/core.rb:566:in
init_attributes' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/core.rb:281:ininitialize'
> /usr/share/foreman/app/models/host/base.rb:70:in initialize' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/url_for.rb:104:ininitialize'
> /usr/share/foreman/app/models/host/managed.rb:49:in initialize' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/inheritance.rb:61:innew'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/inheritance.rb:61:in
new' > /usr/share/foreman/app/models/concerns/foreman/sti.rb:22:innew_with_cast'
> /usr/share/foreman/app/models/host.rb:14:in method_missing' > /usr/share/foreman/app/controllers/hosts_controller.rb:155:ininterfaces'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in
send_action' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:inprocess_action'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in
process_action' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:inblock in process_action'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in
call' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:incall'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in
block (2 levels) in compile' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:incall'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in
call' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:inblock (2 levels) in around'
>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in
call' > /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:inblock (2 levels) in halting'
>
/opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in
`around'
<snip>

Originally I started having this issue while on version 1.7.1. Since this
is the long time overdue for an upgrade, I've decided to go through the
pain of jumping from 1.7.1 to 1.13.0 (one major release at the time) now
and was hoping that whatever it was preventing things from properly working
would be fixed with DB migrations and such.

But as you can see, even in 1.13.0 I still have the same problem. The
output above is from 1.13.0. Here's what I was getting on 1.7.1 while
trying to create a VM through API:

Started POST "/hosts" for 10.64.63.205 at 2016-09-21 18:52:31 -0700

Processing by HostsController#create as /

Parameters: {"utf8"=>"✓",
"authenticity_token"=>"m0XQ3dQE02YElmWptLiurEBe/yv6a8g26Bb9bWpd0xk=",
"host"=>{"name"=>"test", "hostgroup_id"=>"", "compute_resource_id"=>"5",
"compute_profile_id"=>"2", "environment_id"=>"8", "puppet_proxy_id"=>"",
"salt_environment_id"=>"", "salt_proxy_id"=>"", "salt_module_ids"=>[""],
"managed"=>"true", "progress_report_id"=>"[FILTERED]",
"type"=>"Host::Managed", "compute_attributes"=>{"cpus"=>"4",
"memory"=>"17179869184", "nics_attributes"=>{"new_nics"=>{"type"=>"bridge",
"_delete"=>"", "bridge"=>"", "model"=>"virtio"}, "0"=>{"type"=>"bridge",
"_delete"=>"", "bridge"=>"br0", "model"=>"virtio"}},
"volumes_attributes"=>{"new_volumes"=>{"pool_name"=>"default",
"capacity"=>"10G", "allocation"=>"0G", "format_type"=>"raw",
"_delete"=>""}, "0"=>{"pool_name"=>"default", "capacity"=>"50G",
"allocation"=>"0G", "format_type"=>"qcow2", "_delete"=>""}}, "start"=>"1",
"image_id"=>"/data/images/ubuntu-14.04.2-dhcp.qcow2"}, "domain_id"=>"5",
"realm_id"=>"", "mac"=>"", "ip"=>"1.1.1.1",
"interfaces_attributes"=>{"new_interfaces"=>{"_destroy"=>"false",
"type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"",
"domain_id"=>"", "ip"=>"", "managed"=>"1", "virtual"=>"0", "tag"=>"",
"attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"9",
"provision_method"=>"image", "build"=>"1", "disk"=>"",
"root_pass"=>"[FILTERED]", "is_owned_by"=>"6-Users", "enabled"=>"1",
"model_id"=>"", "comment"=>"", "overwrite"=>"false"},
"capabilities"=>"build image", "provider"=>"Libvirt"}

Operation FAILED: unknown attribute: provision_method

Rendered common/500.html.erb (183.1ms)

Completed 500 Internal Server Error in 198ms (Views: 185.3ms |
ActiveRecord: 1.6ms)

The same API call against 1.13.0:

2016-10-19 15:56:59 65e3b7a2 [app] [I] Started POST "/api/v2/hosts/" for
10.188.5.22 at 2016-10-19 15:56:59 -0700

2016-10-19 15:56:59 65e3b7a2 [app] [I] Processing by
Api::V2::HostsController#create as JSON

2016-10-19 15:56:59 65e3b7a2 [app] [I] Parameters:
{"host"=>{"operatingsystem_id"=>"6", "environment_id"=>"8",
"ip"=>"10.132.211.12", "provision_method"=>"image", "image_id"=>"29",
"domain_id"=>"5", "compute_resource_id"=>"11", "name"=>"lvs01test",
"enabled"=>"1", "hostgroup_id"=>"74",
"compute_attributes"=>{"volumes_attributes"=>{"0"=>{"allocation"=>"0G",
"pool_name"=>"default", "format_type"=>"qcow2", "capacity"=>"50G",
"_delete"=>""}}, "start"=>"0", "cpus"=>"4",
"image_id"=>"/data/images/ubuntu-14.04.2-dhcp.qcow2",
"nics_attributes"=>{"0"=>{"_delete"=>"", "model"=>"virtio",
"type"=>"bridge", "bridge"=>"br0"}}, "memory"=>"17179869184"},
"architecture_id"=>"1", "build"=>"1", "compute_profile_id"=>"2"},
"provider"=>"Libvirt", "apiv"=>"v2"}

2016-10-19 15:56:59 65e3b7a2 [app] [I] Authorized user admin(Admin User)

2016-10-19 15:56:59 65e3b7a2 [app] [W] Action failed

> ActiveRecord::UnknownAttributeError: unknown attribute
'provision_method' for Host::Managed.

>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:59:in
`rescue in _assign_attribute'

>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:54:in
`_assign_attribute'

>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:41:in
`block in assign_attributes'

>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/strong_parameters.rb:185:in
`each_pair'

>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/strong_parameters.rb:185:in
`each_pair'

>
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_assignment.rb:35:in
`assign_attributes'

<snip>

As I mentioned, I have other 5 1.7.1 instances where this still works
perfectly fine. I suspect someone has mocked around with Foreman DB on a
troubled instances, I just can't figure out what it is. And Foreman
upgrades could not fix that either :frowning:

What are my options here? Anyone had such problem and, if so, how was it
solved?

Thanks!

> Hello there!
>
> I'm having an isolated issue on one of the Foreman (separate) instances,
> where I can't deploy Libvirt VMs into compute resources anymore.
>
> A standard procedure (through UI):
> New Host
> put a hostname for a new VM
> pick a compute resource to deploy on
>
> At this point I see that "Interfaces" tab goes red and if I go to it, I
> see this message:
>
> Error loading interfaces information: Internal Server Error
>
> My production.log show me this:
>
[…]
> 2016-10-19 16:31:19 5e8f4434 [app] [W] Action failed
> > ActiveRecord::UnknownAttributeError: unknown attribute
> 'provision_method' for Host::Managed.
[snip]
>
> As I mentioned, I have other 5 1.7.1 instances where this still works
> perfectly fine. I suspect someone has mocked around with Foreman DB on a
> troubled instances, I just can't figure out what it is. And Foreman
> upgrades could not fix that either :frowning:

Yes, you're probably right - either the DB's been altered or the initial
upgrade (in 1.5.0) that added this "provision_method" column didn't run
for some reason and was skipped.

I'd suggest editing
/usr/share/foreman/db/migrate/20140304184854_add_provision_method_to_hosts.rb
and commenting out the "remove_column" line with a #, then run:

foreman-rake db:migrate:down VERSION=20140304184854
foreman-rake db:migrate:up VERSION=20140304184854

This should reverse the column add (i.e. nothing, if you comment out the
line), and then add it back.

··· On 20/10/16 00:58, 'Konstantin Orekhov' via Foreman users wrote:


Dominic Cleal
dominic@cleal.org

>
> I'd suggest editing
> /usr/share/foreman/db/migrate/20140304184854_add_provision_method_to_hosts.rb
>
> and commenting out the "remove_column" line with a #, then run:
>
> foreman-rake db:migrate:down VERSION=20140304184854
> foreman-rake db:migrate:up VERSION=20140304184854
>

Yep, this certainly fixed my problem - thank you very much, Dominic!

While we are on this topic - is there a reason why all of those files under
/usr/share/foreman/db/migrate cannot be used for DB migration steps to
allow Foreman admins to "jump" the major releases?
Since I personally just when through that exercise to go from 1.7.1 to
1.13.0, I can assure you that it was a rather major pain of figuring out
all of the repo and package dependencies and such just to install foreman
packages of intermediate versions (1.8, 1.9, 1.10, then move to a different
centos7 host to proceed with 1.11 to 1.12 and then to 1.13) and running
"foreman-rake db:migrate; foreman-rake db:seed"… (shrugs)

I'd rather have a new centos7 with 1.13.0 installed, then import a DB dump
from 1.7.1 and run all the db:migrate steps in between 1.7.1 to my desired
version minus one (so 1.12.3 in this particular case) and finish this up
with regular "foreman-rake db:migrate; foreman-rake db:seed" sequence. Is
that possible? Would it be just as simple as figuring out the db-migrate
versions in between and applying them with above procedure one by one?

Please let me know your thoughts. Having some procedure to simply that
process would be such a big help as not every time it is possible/feasible
to keep on upgrading Foreman just for the sake of staying close to the
latest version.

No, but they're largely untested and are quite prone to bugs in big
steps as they usually are only run in small steps. We used to run tests
on major version migrations, but it was removed.

··· On 21/10/16 00:57, 'Konstantin Orekhov' via Foreman users wrote: > I'd suggest editing > /usr/share/foreman/db/migrate/20140304184854_add_provision_method_to_hosts.rb > > and commenting out the "remove_column" line with a #, then run: > > foreman-rake db:migrate:down VERSION=20140304184854 > foreman-rake db:migrate:up VERSION=20140304184854 > > > Yep, this certainly fixed my problem - thank you very much, Dominic! > > While we are on this topic - is there a reason why all of those files > under /usr/share/foreman/db/migrate cannot be used for DB migration > steps to allow Foreman admins to "jump" the major releases?


Dominic Cleal
dominic@cleal.org