foreman.log - Foreman

Bug #12487 » foreman.log

Log File Containing Provision - Michael Speth, 11/15/2015 07:53 PM

 -11-13T14:29:05 [app] [I] Started GET "/tasks/11c85ca7-4304-40da-8533-285bc62d48fb" for 172.20.8.22 at 2015-11-13 14:29:05 +1300
 -11-13T14:29:05 [app] [I] Processing by TasksController#show as */*
 -11-13T14:29:05 [app] [I]   Parameters: {"id"=>"11c85ca7-4304-40da-8533-285bc62d48fb"}
 -11-13T14:29:05 [app] [I]   Rendered tasks/_list.html.erb (1.0ms)
 -11-13T14:29:05 [app] [I] Completed 200 OK in 23.6ms (Views: 2.0ms | ActiveRecord: 5.6ms)
 -11-13T14:29:05 [app] [I]   Rendered puppetclasses/_classes.html.erb (198.7ms)
 -11-13T14:29:05 [app] [I]   Rendered puppetclasses/_class_selection.html.erb (610.9ms)
 -11-13T14:29:05 [app] [I]   Rendered nic/_base_form.html.erb (18.8ms)
 -11-13T14:29:05 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:29:06 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (436.9ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/_provider_specific_form.html.erb (440.0ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/manageds/_managed.html.erb (463.7ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/_base_form.html.erb (16.5ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/_virtual_form.html.erb (1.6ms)
 -11-13T14:29:06 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (206.0ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/_provider_specific_form.html.erb (207.9ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/manageds/_managed.html.erb (228.9ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/_base_form.html.erb (14.7ms)
 -11-13T14:29:06 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:29:07 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (420.3ms)
 -11-13T14:29:07 [app] [I]   Rendered nic/_provider_specific_form.html.erb (421.8ms)
 -11-13T14:29:07 [app] [I]   Rendered nic/manageds/_managed.html.erb (440.8ms)
 -11-13T14:29:07 [app] [I]   Rendered hosts/_interfaces.html.erb (1137.8ms)
 -11-13T14:29:07 [app] [I] Started GET "/tasks/11c85ca7-4304-40da-8533-285bc62d48fb" for 172.20.8.22 at 2015-11-13 14:29:07 +1300
 -11-13T14:29:07 [app] [I] Processing by TasksController#show as */*
 -11-13T14:29:07 [app] [I]   Parameters: {"id"=>"11c85ca7-4304-40da-8533-285bc62d48fb"}
 -11-13T14:29:07 [app] [I]   Rendered tasks/_list.html.erb (1.0ms)
 -11-13T14:29:07 [app] [I] Completed 200 OK in 13.2ms (Views: 1.9ms | ActiveRecord: 3.3ms)
 -11-13T14:29:07 [app] [I]   Rendered compute_resources_vms/form/vmware/_base.html.erb (765.3ms)
 -11-13T14:29:09 [app] [I] Started GET "/tasks/11c85ca7-4304-40da-8533-285bc62d48fb" for 172.20.8.22 at 2015-11-13 14:29:09 +1300
 -11-13T14:29:09 [app] [I] Processing by TasksController#show as */*
 -11-13T14:29:09 [app] [I]   Parameters: {"id"=>"11c85ca7-4304-40da-8533-285bc62d48fb"}
 -11-13T14:29:09 [app] [I]   Rendered tasks/_list.html.erb (1.2ms)
 -11-13T14:29:09 [app] [I] Completed 200 OK in 23.1ms (Views: 2.3ms | ActiveRecord: 12.0ms)
 -11-13T14:29:09 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (1582.8ms)
 -11-13T14:29:10 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (1240.7ms)
 -11-13T14:29:10 [app] [I]   Rendered compute_resources_vms/form/_volumes.html.erb (2829.2ms)
 -11-13T14:29:10 [app] [I]   Rendered hosts/_compute_detail.html.erb (3598.8ms)
 -11-13T14:29:10 [app] [I]   Rendered hosts/_compute.html.erb (3604.9ms)
 -11-13T14:29:10 [app] [I]   Rendered common/os_selection/_architecture.html.erb (7.8ms)
 -11-13T14:29:10 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (13.7ms)
 -11-13T14:29:10 [app] [I]   Rendered hosts/_operating_system.html.erb (31.6ms)
 -11-13T14:29:10 [app] [I]   Rendered hosts/_unattended.html.erb (3638.8ms)
 -11-13T14:29:10 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:29:10 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (14.5ms)
 -11-13T14:29:10 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (4.7ms)
 -11-13T14:29:10 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (10.9ms)
 -11-13T14:29:10 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (1.6ms)
 -11-13T14:29:10 [app] [I]   Rendered common_parameters/_parameter.html.erb (2.2ms)
 -11-13T14:29:10 [app] [I]   Rendered common_parameters/_parameters.html.erb (5.0ms)
 -11-13T14:29:10 [app] [I]   Rendered hosts/_form.html.erb (5548.0ms)
 -11-13T14:29:10 [app] [I]   Rendered hosts/new.html.erb within layouts/application (5601.5ms)
 -11-13T14:29:10 [app] [I] Started GET "/tasks/11c85ca7-4304-40da-8533-285bc62d48fb" for 172.20.8.22 at 2015-11-13 14:29:10 +1300
 -11-13T14:29:10 [app] [I] Processing by TasksController#show as */*
 -11-13T14:29:10 [app] [I]   Parameters: {"id"=>"11c85ca7-4304-40da-8533-285bc62d48fb"}
 -11-13T14:29:10 [app] [I]   Rendered tasks/_list.html.erb (1.0ms)
 -11-13T14:29:10 [app] [I] Completed 200 OK in 11.9ms (Views: 2.3ms | ActiveRecord: 1.6ms)
 -11-13T14:29:10 [app] [I]   Rendered home/_user_dropdown.html.erb (9.8ms)
 -11-13T14:29:10 [app] [I] Read fragment views/tabs_and_title_records-4 11.0ms
 -11-13T14:29:10 [app] [I]   Rendered home/_topbar.html.erb (22.4ms)
 -11-13T14:29:10 [app] [I]   Rendered layouts/base.html.erb (44.4ms)
 -11-13T14:29:11 [app] [I] Completed 200 OK in 62939.3ms (Views: 5812.7ms | ActiveRecord: 76.0ms)
 -11-13T14:29:12 [app] [I] Started GET "/tasks/11c85ca7-4304-40da-8533-285bc62d48fb" for 172.20.8.22 at 2015-11-13 14:29:12 +1300
 -11-13T14:29:12 [app] [I] Processing by TasksController#show as */*
 -11-13T14:29:12 [app] [I]   Parameters: {"id"=>"11c85ca7-4304-40da-8533-285bc62d48fb"}
 -11-13T14:29:12 [app] [I]   Rendered tasks/_list.html.erb (1.4ms)
 -11-13T14:29:12 [app] [I] Completed 200 OK in 17.5ms (Views: 5.3ms | ActiveRecord: 1.6ms)
 -11-13T14:29:26 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:29:26 +1300
 -11-13T14:29:26 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:29:26 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:29:26 [app] [I] processing report for dev-snowflake-app-01.config.zen.landcareresearch.co.nz
 -11-13T14:29:26 [app] [I] Imported report for dev-snowflake-app-01.config.zen.landcareresearch.co.nz in 0.09 seconds
 -11-13T14:29:26 [app] [I]   Rendered api/v2/reports/create.json.rabl (24.2ms)
 -11-13T14:29:26 [app] [I] Completed 201 Created in 467.7ms (Views: 20.9ms | ActiveRecord: 92.7ms)
 -11-13T14:30:19 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:30:19 +1300
 -11-13T14:30:19 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:30:19 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:30:19 [app] [I] processing report for scenz-data-01.config.zen.landcareresearch.co.nz
 -11-13T14:30:19 [app] [I] Imported report for scenz-data-01.config.zen.landcareresearch.co.nz in 0.2 seconds
 -11-13T14:30:20 [app] [I]   Rendered api/v2/reports/create.json.rabl (89.2ms)
 -11-13T14:30:20 [app] [I] Completed 201 Created in 520.8ms (Views: 69.4ms | ActiveRecord: 228.4ms)
 -11-13T14:30:32 [app] [I] Connecting to database specified by database.yml
 -11-13T14:30:32 [app] [I] Connecting to database specified by database.yml
 -11-13T14:33:22 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:33:22 +1300
 -11-13T14:33:22 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:33:22 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:33:23 [app] [I] processing report for scenz.store
 -11-13T14:33:23 [app] [I] Imported report for scenz.store in 0.13 seconds
 -11-13T14:33:23 [app] [I]   Rendered api/v2/reports/create.json.rabl (49.3ms)
 -11-13T14:33:23 [app] [I] Completed 201 Created in 713.3ms (Views: 49.3ms | ActiveRecord: 52.1ms)
 -11-13T14:35:54 [app] [I] Connecting to database specified by database.yml
 -11-13T14:36:34 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:36:34 +1300
 -11-13T14:36:34 [app] [I] Started GET "/compute_resources/4-vSphere-PN" for 172.20.8.22 at 2015-11-13 14:36:34 +1300
 -11-13T14:36:35 [app] [I] Started GET "/" for 172.20.8.22 at 2015-11-13 14:36:35 +1300
 -11-13T14:36:36 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:36:36 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:36:37 [app] [I] Started GET "/" for 172.20.8.22 at 2015-11-13 14:36:37 +1300
 -11-13T14:36:38 [app] [I] Processing by ComputeResourcesController#show as HTML
 -11-13T14:36:38 [app] [I]   Parameters: {"id"=>"4-vSphere-PN"}
 -11-13T14:36:38 [app] [I] processing report for javadoc
 -11-13T14:36:39 [app] [I] Processing by DashboardController#index as HTML
 -11-13T14:36:40 [app] [I] Processing by DashboardController#index as HTML
 -11-13T14:36:41 [app] [I] Imported report for javadoc in 3.46 seconds
 -11-13T14:36:43 [app] [I]   Rendered compute_resources/show/_vmware.html.erb (1.9ms)
 -11-13T14:36:44 [app] [I]   Rendered compute_resources/show.html.erb within layouts/application (1186.6ms)
 -11-13T14:36:44 [app] [I]   Rendered home/_user_dropdown.html.erb (126.9ms)
 -11-13T14:36:44 [app] [I] Read fragment views/tabs_and_title_records-4 15.0ms
 -11-13T14:36:44 [app] [I]   Rendered home/_topbar.html.erb (180.4ms)
 -11-13T14:36:44 [app] [I]   Rendered layouts/base.html.erb (203.2ms)
 -11-13T14:36:44 [app] [I] Completed 200 OK in 6136.6ms (Views: 3308.8ms | ActiveRecord: 151.2ms)
 -11-13T14:36:44 [app] [I]   Rendered api/v2/reports/create.json.rabl (63.7ms)
 -11-13T14:36:44 [app] [I] Completed 201 Created in 7904.2ms (Views: 1866.8ms | ActiveRecord: 359.1ms)
 -11-13T14:37:16 [app] [I]   Rendered dashboard/_status_widget.html.erb (15.0ms)
 -11-13T14:37:16 [app] [I]   Rendered dashboard/_status_widget.html.erb (16.0ms)
 -11-13T14:37:16 [app] [I]   Rendered dashboard/_status_chart_widget.html.erb (3.0ms)
 -11-13T14:37:16 [app] [I]   Rendered dashboard/_status_chart_widget.html.erb (7.8ms)
 -11-13T14:37:17 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:37:17 +1300
 -11-13T14:37:17 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:37:17 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:37:17 [app] [I] processing report for test-nsdr-db-01.config.zen.landcareresearch.co.nz
 -11-13T14:37:19 [app] [I]   Rendered dashboard/_reports_widget.html.erb (2322.4ms)
 -11-13T14:37:19 [app] [I]   Rendered dashboard/_reports_widget.html.erb (1872.7ms)
 -11-13T14:37:19 [app] [I] Imported report for test-nsdr-db-01.config.zen.landcareresearch.co.nz in 1.56 seconds
 -11-13T14:37:19 [app] [I]   Rendered dashboard/_distribution_widget.html.erb (125.6ms)
 -11-13T14:37:19 [app] [I]   Rendered dashboard/index.html.erb within layouts/application (34814.8ms)
 -11-13T14:37:19 [app] [I]   Rendered dashboard/_distribution_widget.html.erb (116.2ms)
 -11-13T14:37:19 [app] [I]   Rendered dashboard/index.html.erb within layouts/application (35990.1ms)
 -11-13T14:37:19 [app] [I]   Rendered api/v2/reports/create.json.rabl (64.9ms)
 -11-13T14:37:19 [app] [I]   Rendered common/_searchbar.html.erb (44.3ms)
 -11-13T14:37:19 [app] [I]   Rendered common/_searchbar.html.erb (49.6ms)
 -11-13T14:37:19 [app] [I] Completed 201 Created in 1780.2ms (Views: 62.2ms | ActiveRecord: 180.2ms)
 -11-13T14:37:19 [app] [I]   Rendered home/_user_dropdown.html.erb (8.6ms)
 -11-13T14:37:19 [app] [I]   Rendered home/_user_dropdown.html.erb (5.8ms)
 -11-13T14:37:19 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:37:19 [app] [I]   Rendered home/_topbar.html.erb (20.5ms)
 -11-13T14:37:19 [app] [I] Read fragment views/tabs_and_title_records-4 2.7ms
 -11-13T14:37:19 [app] [I]   Rendered home/_topbar.html.erb (19.6ms)
 -11-13T14:37:19 [app] [I]   Rendered layouts/base.html.erb (32.1ms)
 -11-13T14:37:19 [app] [I] Completed 200 OK in 40115.9ms (Views: 37032.6ms | ActiveRecord: 393.5ms)
 -11-13T14:37:19 [app] [I]   Rendered layouts/base.html.erb (30.9ms)
 -11-13T14:37:19 [app] [I] Completed 200 OK in 38650.7ms (Views: 35791.3ms | ActiveRecord: 286.8ms)
 -11-13T14:37:19 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:37:19 +1300
 -11-13T14:37:20 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:37:20 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:37:20 [app] [I] processing report for foreman-01
 -11-13T14:37:20 [app] [I] Imported report for foreman-01 in 0.39 seconds
 -11-13T14:37:20 [app] [I]   Rendered api/v2/reports/create.json.rabl (20.3ms)
 -11-13T14:37:20 [app] [I] Completed 201 Created in 727.6ms (Views: 22.8ms | ActiveRecord: 27.7ms)
 -11-13T14:37:31 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:37:31 +1300
 -11-13T14:37:31 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:37:31 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:37:31 [app] [I] processing report for dhcp-prod
 -11-13T14:37:32 [app] [I] Imported report for dhcp-prod in 0.54 seconds
 -11-13T14:37:32 [app] [I]   Rendered api/v2/reports/create.json.rabl (21.9ms)
 -11-13T14:37:32 [app] [I] Completed 201 Created in 611.7ms (Views: 21.0ms | ActiveRecord: 50.0ms)
 -11-13T14:37:34 [app] [I] Started GET "/hosts/new" for 172.20.8.22 at 2015-11-13 14:37:34 +1300
 -11-13T14:37:34 [app] [I] Processing by HostsController#new as HTML
 -11-13T14:37:34 [app] [I]   Rendered hosts/_progress.html.erb (1.1ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_base_form.html.erb (366.3ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_virtual_form.html.erb (3.2ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_provider_specific_form.html.erb (1.3ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/manageds/_managed.html.erb (379.3ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_base_form.html.erb (15.7ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.4ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/manageds/_managed.html.erb (22.3ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_interfaces.html.erb (411.9ms)
 -11-13T14:37:35 [app] [I]   Rendered common/os_selection/_architecture.html.erb (3.9ms)
 -11-13T14:37:35 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (10.0ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_operating_system.html.erb (51.6ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_unattended.html.erb (53.6ms)
 -11-13T14:37:35 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:37:35 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (45.4ms)
 -11-13T14:37:35 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (6.8ms)
 -11-13T14:37:35 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (26.0ms)
 -11-13T14:37:35 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (6.3ms)
 -11-13T14:37:35 [app] [I]   Rendered common_parameters/_parameter.html.erb (4.1ms)
 -11-13T14:37:35 [app] [I]   Rendered common_parameters/_parameters.html.erb (26.3ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_form.html.erb (955.2ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/new.html.erb within layouts/application (957.6ms)
 -11-13T14:37:35 [app] [I]   Rendered home/_user_dropdown.html.erb (2.9ms)
 -11-13T14:37:35 [app] [I] Read fragment views/tabs_and_title_records-4 0.5ms
 -11-13T14:37:35 [app] [I]   Rendered home/_topbar.html.erb (4.6ms)
 -11-13T14:37:35 [app] [I]   Rendered layouts/base.html.erb (6.6ms)
 -11-13T14:37:35 [app] [I] Completed 200 OK in 990.8ms (Views: 873.3ms | ActiveRecord: 101.5ms)
 -11-13T14:37:35 [app] [I] Started GET "/hosts/new" for 172.20.8.22 at 2015-11-13 14:37:35 +1300
 -11-13T14:37:35 [app] [I] Processing by HostsController#new as HTML
 -11-13T14:37:35 [app] [I]   Rendered hosts/_progress.html.erb (0.3ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_base_form.html.erb (20.2ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.4ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/manageds/_managed.html.erb (25.0ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_base_form.html.erb (14.7ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:37:35 [app] [I]   Rendered nic/manageds/_managed.html.erb (19.1ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_interfaces.html.erb (47.9ms)
 -11-13T14:37:35 [app] [I]   Rendered common/os_selection/_architecture.html.erb (3.0ms)
 -11-13T14:37:35 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (4.4ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_operating_system.html.erb (16.5ms)
 -11-13T14:37:35 [app] [I]   Rendered hosts/_unattended.html.erb (16.9ms)
 -11-13T14:37:35 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:37:35 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (8.9ms)
 -11-13T14:37:36 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (18.5ms)
 -11-13T14:37:36 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (20.7ms)
 -11-13T14:37:36 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (1.6ms)
 -11-13T14:37:36 [app] [I]   Rendered common_parameters/_parameter.html.erb (2.0ms)
 -11-13T14:37:36 [app] [I]   Rendered common_parameters/_parameters.html.erb (4.6ms)
 -11-13T14:37:36 [app] [I]   Rendered hosts/_form.html.erb (171.5ms)
 -11-13T14:37:36 [app] [I]   Rendered hosts/new.html.erb within layouts/application (172.8ms)
 -11-13T14:37:36 [app] [I]   Rendered home/_user_dropdown.html.erb (2.1ms)
 -11-13T14:37:36 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:37:36 [app] [I]   Rendered home/_topbar.html.erb (3.5ms)
 -11-13T14:37:36 [app] [I]   Rendered layouts/base.html.erb (5.5ms)
 -11-13T14:37:36 [app] [I] Completed 200 OK in 440.4ms (Views: 166.5ms | ActiveRecord: 16.8ms)
 -11-13T14:37:42 [app] [I] Started POST "/hosts/process_hostgroup" for 172.20.8.22 at 2015-11-13 14:37:42 +1300
 -11-13T14:37:42 [app] [I] Processing by HostsController#process_hostgroup as */*
 -11-13T14:37:42 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"", "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"", "provision_method"=>"build", "build"=>"1", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
 -11-13T14:37:42 [app] [I]   Rendered hosts/_progress.html.erb (1.0ms)
 -11-13T14:37:42 [app] [I]   Rendered puppetclasses/_selectedClasses.html.erb (0.0ms)
 -11-13T14:37:42 [app] [I]   Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms)
 -11-13T14:37:42 [app] [I]   Rendered puppetclasses/_classes.html.erb (184.9ms)
 -11-13T14:37:42 [app] [I]   Rendered puppetclasses/_class_selection.html.erb (581.4ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/_base_form.html.erb (21.6ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/_virtual_form.html.erb (2.7ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/_provider_specific_form.html.erb (1.1ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/manageds/_managed.html.erb (40.4ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/_base_form.html.erb (15.2ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:37:42 [app] [I]   Rendered nic/manageds/_managed.html.erb (23.2ms)
 -11-13T14:37:42 [app] [I]   Rendered hosts/_interfaces.html.erb (73.7ms)
 -11-13T14:37:43 [app] [I]   Rendered common/os_selection/_architecture.html.erb (331.0ms)
 -11-13T14:37:43 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (73.6ms)
 -11-13T14:37:43 [app] [I]   Rendered hosts/_operating_system.html.erb (420.8ms)
 -11-13T14:37:43 [app] [I]   Rendered hosts/_unattended.html.erb (424.6ms)
 -11-13T14:37:43 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:37:43 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (18.0ms)
 -11-13T14:37:43 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (5.2ms)
 -11-13T14:37:43 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (11.5ms)
 -11-13T14:37:43 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (3.3ms)
 -11-13T14:37:43 [app] [I]   Rendered common_parameters/_parameter.html.erb (3.9ms)
 -11-13T14:37:43 [app] [I]   Rendered common_parameters/_parameters.html.erb (10.6ms)
 -11-13T14:37:43 [app] [I]   Rendered hosts/_form.html.erb (1268.3ms)
 -11-13T14:37:43 [app] [I] Completed 200 OK in 1407.9ms (Views: 1184.0ms | ActiveRecord: 114.8ms)
 -11-13T14:37:43 [app] [I] Started POST "/hosts/interfaces" for 172.20.8.22 at 2015-11-13 14:37:43 +1300
 -11-13T14:37:43 [app] [I] Processing by HostsController#interfaces as */*
 -11-13T14:37:43 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
 -11-13T14:37:43 [app] [I]   Rendered nic/_base_form.html.erb (20.7ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/manageds/_managed.html.erb (25.3ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/_base_form.html.erb (13.7ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:37:43 [app] [I]   Rendered nic/manageds/_managed.html.erb (18.0ms)
 -11-13T14:37:43 [app] [I]   Rendered hosts/_interfaces.html.erb (47.8ms)
 -11-13T14:37:43 [app] [I]   Rendered hosts/_interfaces_tab.html.erb (51.4ms)
 -11-13T14:37:43 [app] [I] Completed 200 OK in 80.2ms (Views: 53.3ms | ActiveRecord: 5.5ms)
 -11-13T14:37:43 [app] [I] Started POST "/subnets/freeip" for 172.20.8.22 at 2015-11-13 14:37:43 +1300
 -11-13T14:37:43 [app] [I] Processing by SubnetsController#freeip as JSON
 -11-13T14:37:43 [app] [I]   Parameters: {"subnet_id"=>"13", "host_mac"=>"", "taken_ips"=>["", ""]}
 -11-13T14:37:46 [app] [I] Started POST "/hosts/compute_resource_selected" for 172.20.8.22 at 2015-11-13 14:37:46 +1300
 -11-13T14:37:46 [app] [I] Processing by HostsController#compute_resource_selected as */*
 -11-13T14:37:46 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
 -11-13T14:37:47 [app] [I] Completed 200 OK in 3276.4ms (Views: 0.5ms | ActiveRecord: 5.2ms)
 -11-13T14:37:49 [app] [I]   Rendered compute_resources_vms/form/vmware/_base.html.erb (893.2ms)
 -11-13T14:38:00 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:00 +1300
 -11-13T14:38:00 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:00 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:01 [app] [I] processing report for test-snowflake-app-01.config.zen.landcareresearch.co.nz
 -11-13T14:38:01 [app] [I] Imported report for test-snowflake-app-01.config.zen.landcareresearch.co.nz in 0.07 seconds
 -11-13T14:38:01 [app] [I]   Rendered api/v2/reports/create.json.rabl (25.9ms)
 -11-13T14:38:01 [app] [I] Completed 201 Created in 185.3ms (Views: 25.5ms | ActiveRecord: 81.5ms)
 -11-13T14:38:03 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:03 +1300
 -11-13T14:38:03 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:03 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:03 [app] [I] processing report for test-snowflake-db-01.config.zen.landcareresearch.co.nz
 -11-13T14:38:03 [app] [I] Imported report for test-snowflake-db-01.config.zen.landcareresearch.co.nz in 0.09 seconds
 -11-13T14:38:03 [app] [I]   Rendered api/v2/reports/create.json.rabl (31.9ms)
 -11-13T14:38:03 [app] [I] Completed 201 Created in 230.2ms (Views: 25.9ms | ActiveRecord: 97.6ms)
 -11-13T14:38:03 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (13628.4ms)
 -11-13T14:38:04 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (1226.6ms)
 -11-13T14:38:04 [app] [I]   Rendered compute_resources_vms/form/_volumes.html.erb (14862.3ms)
 -11-13T14:38:04 [app] [I]   Rendered hosts/_compute_detail.html.erb (15765.3ms)
 -11-13T14:38:04 [app] [I]   Rendered hosts/_compute.html.erb (18163.8ms)
 -11-13T14:38:04 [app] [I] Completed 200 OK in 18670.6ms (Views: 18172.1ms | ActiveRecord: 22.8ms)
 -11-13T14:38:04 [app] [I] Started GET "/compute_resources/4/images?search=operatingsystem%3D5%20architecture%3D1" for 172.20.8.22 at 2015-11-13 14:38:04 +1300
 -11-13T14:38:04 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:04 +1300
 -11-13T14:38:04 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:04 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:04 [app] [I] Processing by ImagesController#index as JSON
 -11-13T14:38:04 [app] [I]   Parameters: {"search"=>"operatingsystem=5 architecture=1", "compute_resource_id"=>"4"}
 -11-13T14:38:04 [app] [I] processing report for dev-nsdr-db-01.config.zen.landcareresearch.co.nz
 -11-13T14:38:05 [app] [I] Imported report for dev-nsdr-db-01.config.zen.landcareresearch.co.nz in 0.13 seconds
 -11-13T14:38:05 [app] [I] Completed 200 OK in 156.1ms (Views: 62.9ms | ActiveRecord: 53.7ms)
 -11-13T14:38:05 [app] [I]   Rendered api/v2/reports/create.json.rabl (31.4ms)
 -11-13T14:38:05 [app] [I] Completed 201 Created in 279.3ms (Views: 23.1ms | ActiveRecord: 165.7ms)
 -11-13T14:38:05 [app] [I] Started POST "/hosts/interfaces" for 172.20.8.22 at 2015-11-13 14:38:05 +1300
 -11-13T14:38:05 [app] [I] Processing by HostsController#interfaces as */*
 -11-13T14:38:05 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"192.168.250.45", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"1024", "cluster"=>"Palmerston North HA", "path"=>"/Datacenters/Palmerston North/vm/Informatics VM's", "guest_id"=>"ubuntu64Guest", "scsi_controller_type"=>"VirtualLsiLogicController", "hardware_version"=>"Default", "start"=>"1", "volumes_attributes"=>{"new_volumes"=>{"_delete"=>"", "datastore"=>"3Par_AO_1", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}, "0"=>{"_delete"=>"", "datastore"=>"PN_IBM_SAN_VM03", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "capabilities"=>"build image", "provider"=>"Vmware", "fakepassword"=>"[FILTERED]"}
 -11-13T14:38:06 [app] [I]   Rendered nic/_base_form.html.erb (343.1ms)
 -11-13T14:38:06 [app] [I]   Rendered nic/_virtual_form.html.erb (3.1ms)
 -11-13T14:38:06 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:06 +1300
 -11-13T14:38:07 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:07 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:07 [app] [I] processing report for ckan
 -11-13T14:38:12 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (5560.5ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/_provider_specific_form.html.erb (5567.1ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/manageds/_managed.html.erb (5929.4ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/_base_form.html.erb (25.6ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/_virtual_form.html.erb (6.5ms)
 -11-13T14:38:12 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (680.3ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/_provider_specific_form.html.erb (682.6ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/manageds/_managed.html.erb (717.4ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/_base_form.html.erb (30.9ms)
 -11-13T14:38:12 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:38:13 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (577.7ms)
 -11-13T14:38:13 [app] [I]   Rendered nic/_provider_specific_form.html.erb (579.1ms)
 -11-13T14:38:13 [app] [I]   Rendered nic/manageds/_managed.html.erb (622.7ms)
 -11-13T14:38:13 [app] [I]   Rendered hosts/_interfaces.html.erb (7291.3ms)
 -11-13T14:38:13 [app] [I]   Rendered hosts/_interfaces_tab.html.erb (7294.8ms)
 -11-13T14:38:13 [app] [I] Completed 200 OK in 8075.4ms (Views: 7288.1ms | ActiveRecord: 25.8ms)
 -11-13T14:38:18 [app] [I] Imported report for ckan in 11.49 seconds
 -11-13T14:38:22 [app] [I]   Rendered api/v2/reports/create.json.rabl (3956.1ms)
 -11-13T14:38:22 [app] [I] Completed 201 Created in 15498.1ms (Views: 3719.2ms | ActiveRecord: 6201.6ms)
 -11-13T14:38:23 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:23 +1300
 -11-13T14:38:23 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:23 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:23 [app] [I] processing report for landcare-test-repository
 -11-13T14:38:23 [app] [I] Imported report for landcare-test-repository in 0.03 seconds
 -11-13T14:38:23 [app] [I]   Rendered api/v2/reports/create.json.rabl (17.1ms)
 -11-13T14:38:23 [app] [I] Completed 201 Created in 85.1ms (Views: 16.0ms | ActiveRecord: 19.1ms)
 -11-13T14:38:23 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:23 +1300
 -11-13T14:38:23 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:23 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:23 [app] [I] processing report for zenoss
 -11-13T14:38:23 [app] [I] Imported report for zenoss in 0.02 seconds
 -11-13T14:38:23 [app] [I]   Rendered api/v2/reports/create.json.rabl (10.2ms)
 -11-13T14:38:23 [app] [I] Completed 201 Created in 61.0ms (Views: 10.2ms | ActiveRecord: 12.0ms)
 -11-13T14:38:29 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:38:29 +1300
 -11-13T14:38:29 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:38:29 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:38:29 [app] [I] processing report for aep-test3
 -11-13T14:38:29 [app] [I] Imported report for aep-test3 in 0.04 seconds
 -11-13T14:38:29 [app] [I]   Rendered api/v2/reports/create.json.rabl (21.8ms)
 -11-13T14:38:29 [app] [I] Completed 201 Created in 113.5ms (Views: 19.4ms | ActiveRecord: 36.3ms)
 -11-13T14:40:58 [app] [I] Connecting to database specified by database.yml
 -11-13T14:41:38 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:41:38 +1300
 -11-13T14:41:38 [app] [I] Started GET "/hosts/new" for 172.20.8.22 at 2015-11-13 14:41:38 +1300
 -11-13T14:41:39 [app] [I] Started GET "/" for 172.20.8.22 at 2015-11-13 14:41:39 +1300
 -11-13T14:41:40 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:41:40 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:41:40 [app] [I] Started GET "/" for 172.20.8.22 at 2015-11-13 14:41:40 +1300
 -11-13T14:41:41 [app] [I] Processing by HostsController#new as HTML
 -11-13T14:41:41 [app] [I] processing report for gisapps-b-01.config.zen.landcareresearch.co.nz
 -11-13T14:41:42 [app] [I] Processing by DashboardController#index as HTML
 -11-13T14:41:44 [app] [I] Processing by DashboardController#index as HTML
 -11-13T14:41:47 [app] [I] Imported report for gisapps-b-01.config.zen.landcareresearch.co.nz in 5.57 seconds
 -11-13T14:41:49 [app] [I]   Rendered hosts/_progress.html.erb (1.3ms)
 -11-13T14:41:49 [app] [I]   Rendered api/v2/reports/create.json.rabl (108.2ms)
 -11-13T14:41:49 [app] [I] Completed 201 Created in 9402.1ms (Views: 1990.5ms | ActiveRecord: 1637.8ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/_base_form.html.erb (288.3ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/_virtual_form.html.erb (3.2ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/_provider_specific_form.html.erb (1.3ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/manageds/_managed.html.erb (331.2ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/_base_form.html.erb (66.2ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:41:51 [app] [I]   Rendered nic/manageds/_managed.html.erb (106.0ms)
 -11-13T14:41:51 [app] [I]   Rendered hosts/_interfaces.html.erb (477.2ms)
 -11-13T14:41:52 [app] [I]   Rendered common/os_selection/_architecture.html.erb (16.5ms)
 -11-13T14:41:52 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (21.0ms)
 -11-13T14:41:52 [app] [I]   Rendered hosts/_operating_system.html.erb (1057.6ms)
 -11-13T14:41:52 [app] [I]   Rendered hosts/_unattended.html.erb (1061.6ms)
 -11-13T14:41:52 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:41:52 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (213.5ms)
 -11-13T14:42:30 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:42:30 +1300
 -11-13T14:42:30 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:42:30 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:42:30 [app] [I] processing report for foreman-01
 -11-13T14:42:32 [app] [I] Imported report for foreman-01 in 1.88 seconds
 -11-13T14:42:32 [app] [I]   Rendered api/v2/reports/create.json.rabl (69.8ms)
 -11-13T14:42:32 [app] [I] Completed 201 Created in 2083.3ms (Views: 47.1ms | ActiveRecord: 411.2ms)
 -11-13T14:42:47 [app] [I]   Rendered dashboard/_status_widget.html.erb (667.4ms)
 -11-13T14:42:47 [app] [I]   Rendered dashboard/_status_chart_widget.html.erb (3.2ms)
 -11-13T14:42:48 [app] [I]   Rendered dashboard/_status_widget.html.erb (17.7ms)
 -11-13T14:42:48 [app] [I]   Rendered dashboard/_status_chart_widget.html.erb (10.2ms)
 -11-13T14:42:50 [app] [I]   Rendered dashboard/_reports_widget.html.erb (2037.3ms)
 -11-13T14:42:50 [app] [I]   Rendered dashboard/_distribution_widget.html.erb (148.8ms)
 -11-13T14:42:50 [app] [I]   Rendered dashboard/index.html.erb within layouts/application (64025.3ms)
 -11-13T14:42:50 [app] [I]   Rendered common/_searchbar.html.erb (76.6ms)
 -11-13T14:42:50 [app] [I]   Rendered home/_user_dropdown.html.erb (24.7ms)
 -11-13T14:42:50 [app] [I] Read fragment views/tabs_and_title_records-4 6.9ms
 -11-13T14:42:50 [app] [I]   Rendered home/_topbar.html.erb (40.0ms)
 -11-13T14:42:50 [app] [I]   Rendered layouts/base.html.erb (52.6ms)
 -11-13T14:42:50 [app] [I] Completed 200 OK in 67764.4ms (Views: 64841.1ms | ActiveRecord: 508.0ms)
 -11-13T14:42:50 [app] [I]   Rendered dashboard/_reports_widget.html.erb (2347.5ms)
 -11-13T14:42:50 [app] [I]   Rendered dashboard/_distribution_widget.html.erb (58.7ms)
 -11-13T14:42:50 [app] [I]   Rendered dashboard/index.html.erb within layouts/application (63341.8ms)
 -11-13T14:42:50 [app] [I]   Rendered common/_searchbar.html.erb (32.8ms)
 -11-13T14:42:50 [app] [I]   Rendered home/_user_dropdown.html.erb (7.9ms)
 -11-13T14:42:50 [app] [I] Read fragment views/tabs_and_title_records-4 0.1ms
 -11-13T14:42:50 [app] [I]   Rendered home/_topbar.html.erb (15.0ms)
 -11-13T14:42:50 [app] [I]   Rendered layouts/base.html.erb (23.2ms)
 -11-13T14:42:50 [app] [I] Completed 200 OK in 66844.7ms (Views: 64218.7ms | ActiveRecord: 228.0ms)
 -11-13T14:42:53 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:42:53 +1300
 -11-13T14:42:53 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:42:53 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:42:53 [app] [I] processing report for nzvh-dev
 -11-13T14:42:54 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (61411.1ms)
 -11-13T14:42:54 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (61521.3ms)
 -11-13T14:42:54 [app] [I] Imported report for nzvh-dev in 0.78 seconds
 -11-13T14:42:54 [app] [I] Started GET "/hosts/new" for 172.20.8.22 at 2015-11-13 14:42:54 +1300
 -11-13T14:42:55 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (19.3ms)
 -11-13T14:42:55 [app] [I]   Rendered common_parameters/_parameter.html.erb (14.3ms)
 -11-13T14:42:55 [app] [I]   Rendered common_parameters/_parameters.html.erb (93.4ms)
 -11-13T14:42:55 [app] [I]   Rendered api/v2/reports/create.json.rabl (61.7ms)
 -11-13T14:42:55 [app] [I] Completed 201 Created in 1737.7ms (Views: 57.9ms | ActiveRecord: 115.9ms)
 -11-13T14:42:55 [app] [I] Processing by HostsController#new as HTML
 -11-13T14:42:55 [app] [I]   Rendered hosts/_form.html.erb (66442.4ms)
 -11-13T14:42:55 [app] [I]   Rendered hosts/new.html.erb within layouts/application (67391.9ms)
 -11-13T14:42:55 [app] [I]   Rendered hosts/_progress.html.erb (1.3ms)
 -11-13T14:42:56 [app] [I]   Rendered home/_user_dropdown.html.erb (56.9ms)
 -11-13T14:42:56 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:42:56 [app] [I]   Rendered home/_topbar.html.erb (758.2ms)
 -11-13T14:42:56 [app] [I]   Rendered layouts/base.html.erb (770.5ms)
 -11-13T14:42:56 [app] [I] Completed 200 OK in 74634.5ms (Views: 69443.6ms | ActiveRecord: 858.8ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/_base_form.html.erb (598.9ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/_virtual_form.html.erb (7.6ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/_provider_specific_form.html.erb (1.2ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/manageds/_managed.html.erb (627.1ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/_base_form.html.erb (28.9ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:42:57 [app] [I]   Rendered nic/manageds/_managed.html.erb (43.7ms)
 -11-13T14:42:57 [app] [I]   Rendered hosts/_interfaces.html.erb (702.2ms)
 -11-13T14:42:57 [app] [I]   Rendered common/os_selection/_architecture.html.erb (8.0ms)
 -11-13T14:42:57 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (9.6ms)
 -11-13T14:42:57 [app] [I]   Rendered hosts/_operating_system.html.erb (73.0ms)
 -11-13T14:42:57 [app] [I]   Rendered hosts/_unattended.html.erb (74.8ms)
 -11-13T14:42:57 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:42:57 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (49.2ms)
 -11-13T14:42:57 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (10.6ms)
 -11-13T14:42:57 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (49.7ms)
 -11-13T14:42:58 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (13.4ms)
 -11-13T14:42:58 [app] [I]   Rendered common_parameters/_parameter.html.erb (8.4ms)
 -11-13T14:42:58 [app] [I]   Rendered common_parameters/_parameters.html.erb (56.3ms)
 -11-13T14:42:58 [app] [I]   Rendered hosts/_form.html.erb (2799.7ms)
 -11-13T14:42:58 [app] [I]   Rendered hosts/new.html.erb within layouts/application (2801.6ms)
 -11-13T14:42:58 [app] [I]   Rendered home/_user_dropdown.html.erb (6.7ms)
 -11-13T14:42:58 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:42:58 [app] [I]   Rendered home/_topbar.html.erb (8.1ms)
 -11-13T14:42:58 [app] [I]   Rendered layouts/base.html.erb (10.0ms)
 -11-13T14:42:59 [app] [I] Completed 200 OK in 3766.9ms (Views: 3161.8ms | ActiveRecord: 160.0ms)
 -11-13T14:42:59 [app] [I] Started GET "/hosts/new" for 172.20.8.22 at 2015-11-13 14:42:59 +1300
 -11-13T14:42:59 [app] [I] Processing by HostsController#new as HTML
 -11-13T14:42:59 [app] [I]   Rendered hosts/_progress.html.erb (0.3ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/_base_form.html.erb (29.0ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.4ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/manageds/_managed.html.erb (45.9ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/_base_form.html.erb (28.8ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/_virtual_form.html.erb (5.6ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:42:59 [app] [I]   Rendered nic/manageds/_managed.html.erb (37.4ms)
 -11-13T14:42:59 [app] [I]   Rendered hosts/_interfaces.html.erb (86.6ms)
 -11-13T14:42:59 [app] [I]   Rendered common/os_selection/_architecture.html.erb (7.1ms)
 -11-13T14:42:59 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (8.2ms)
 -11-13T14:42:59 [app] [I]   Rendered hosts/_operating_system.html.erb (36.6ms)
 -11-13T14:42:59 [app] [I]   Rendered hosts/_unattended.html.erb (37.1ms)
 -11-13T14:42:59 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:42:59 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (19.6ms)
 -11-13T14:42:59 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (27.1ms)
 -11-13T14:42:59 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (29.4ms)
 -11-13T14:42:59 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (1.6ms)
 -11-13T14:42:59 [app] [I]   Rendered common_parameters/_parameter.html.erb (2.0ms)
 -11-13T14:42:59 [app] [I]   Rendered common_parameters/_parameters.html.erb (8.6ms)
 -11-13T14:42:59 [app] [I]   Rendered hosts/_form.html.erb (324.9ms)
 -11-13T14:42:59 [app] [I]   Rendered hosts/new.html.erb within layouts/application (326.2ms)
 -11-13T14:42:59 [app] [I]   Rendered home/_user_dropdown.html.erb (7.0ms)
 -11-13T14:42:59 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:42:59 [app] [I]   Rendered home/_topbar.html.erb (8.3ms)
 -11-13T14:42:59 [app] [I]   Rendered layouts/base.html.erb (10.3ms)
 -11-13T14:42:59 [app] [I] Completed 200 OK in 370.2ms (Views: 269.9ms | ActiveRecord: 84.4ms)
 -11-13T14:43:13 [app] [I] Started POST "/hosts/process_hostgroup" for 172.20.8.22 at 2015-11-13 14:43:13 +1300
 -11-13T14:43:13 [app] [I] Processing by HostsController#process_hostgroup as */*
 -11-13T14:43:13 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"", "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"", "provision_method"=>"build", "build"=>"1", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
 -11-13T14:43:13 [app] [I]   Rendered hosts/_progress.html.erb (1.0ms)
 -11-13T14:43:14 [app] [I]   Rendered puppetclasses/_selectedClasses.html.erb (0.0ms)
 -11-13T14:43:14 [app] [I]   Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms)
 -11-13T14:43:14 [app] [I]   Rendered puppetclasses/_classes.html.erb (435.8ms)
 -11-13T14:43:14 [app] [I]   Rendered puppetclasses/_class_selection.html.erb (692.1ms)
 -11-13T14:43:14 [app] [I]   Rendered nic/_base_form.html.erb (22.8ms)
 -11-13T14:43:14 [app] [I]   Rendered nic/_virtual_form.html.erb (3.0ms)
 -11-13T14:43:14 [app] [I]   Rendered nic/_provider_specific_form.html.erb (1.1ms)
 -11-13T14:43:14 [app] [I]   Rendered nic/manageds/_managed.html.erb (41.8ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_base_form.html.erb (32.0ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/manageds/_managed.html.erb (45.9ms)
 -11-13T14:43:15 [app] [I]   Rendered hosts/_interfaces.html.erb (104.7ms)
 -11-13T14:43:15 [app] [I]   Rendered common/os_selection/_architecture.html.erb (43.7ms)
 -11-13T14:43:15 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (111.4ms)
 -11-13T14:43:15 [app] [I]   Rendered hosts/_operating_system.html.erb (172.7ms)
 -11-13T14:43:15 [app] [I]   Rendered hosts/_unattended.html.erb (176.5ms)
 -11-13T14:43:15 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:43:15 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (21.7ms)
 -11-13T14:43:15 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (5.5ms)
 -11-13T14:43:15 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (25.7ms)
 -11-13T14:43:15 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (247.7ms)
 -11-13T14:43:15 [app] [I]   Rendered common_parameters/_parameter.html.erb (4.3ms)
 -11-13T14:43:15 [app] [I]   Rendered common_parameters/_parameters.html.erb (29.2ms)
 -11-13T14:43:15 [app] [I]   Rendered hosts/_form.html.erb (1860.9ms)
 -11-13T14:43:15 [app] [I] Completed 200 OK in 2173.2ms (Views: 1615.1ms | ActiveRecord: 357.4ms)
 -11-13T14:43:15 [app] [I] Started POST "/hosts/interfaces" for 172.20.8.22 at 2015-11-13 14:43:15 +1300
 -11-13T14:43:15 [app] [I] Processing by HostsController#interfaces as */*
 -11-13T14:43:15 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
 -11-13T14:43:15 [app] [I]   Rendered nic/_base_form.html.erb (19.8ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/manageds/_managed.html.erb (24.1ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_base_form.html.erb (13.7ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/_provider_specific_form.html.erb (0.3ms)
 -11-13T14:43:15 [app] [I]   Rendered nic/manageds/_managed.html.erb (17.8ms)
 -11-13T14:43:15 [app] [I]   Rendered hosts/_interfaces.html.erb (46.2ms)
 -11-13T14:43:15 [app] [I]   Rendered hosts/_interfaces_tab.html.erb (49.7ms)
 -11-13T14:43:15 [app] [I] Completed 200 OK in 78.3ms (Views: 51.8ms | ActiveRecord: 5.2ms)
 -11-13T14:43:16 [app] [I] Started POST "/subnets/freeip" for 172.20.8.22 at 2015-11-13 14:43:16 +1300
 -11-13T14:43:16 [app] [I] Processing by SubnetsController#freeip as JSON
 -11-13T14:43:16 [app] [I]   Parameters: {"subnet_id"=>"13", "host_mac"=>"", "taken_ips"=>["", ""]}
 -11-13T14:43:18 [app] [I] Completed 200 OK in 2100.3ms (Views: 0.4ms | ActiveRecord: 4.8ms)
 -11-13T14:43:24 [app] [I] Started POST "/hosts/compute_resource_selected" for 172.20.8.22 at 2015-11-13 14:43:24 +1300
 -11-13T14:43:24 [app] [I] Processing by HostsController#compute_resource_selected as */*
 -11-13T14:43:24 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"192.168.250.3", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
 -11-13T14:43:27 [app] [I]   Rendered compute_resources_vms/form/vmware/_base.html.erb (878.6ms)
 -11-13T14:43:28 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (1187.4ms)
 -11-13T14:43:29 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (1169.2ms)
 -11-13T14:43:29 [app] [I]   Rendered compute_resources_vms/form/_volumes.html.erb (2363.9ms)
 -11-13T14:43:29 [app] [I]   Rendered hosts/_compute_detail.html.erb (3252.9ms)
 -11-13T14:43:29 [app] [I]   Rendered hosts/_compute.html.erb (5411.3ms)
 -11-13T14:43:29 [app] [I] Completed 200 OK in 5440.0ms (Views: 5398.8ms | ActiveRecord: 20.6ms)
 -11-13T14:43:29 [app] [I] Started GET "/compute_resources/4/images?search=operatingsystem%3D5%20architecture%3D1" for 172.20.8.22 at 2015-11-13 14:43:29 +1300
 -11-13T14:43:29 [app] [I] Processing by ImagesController#index as JSON
 -11-13T14:43:29 [app] [I]   Parameters: {"search"=>"operatingsystem=5 architecture=1", "compute_resource_id"=>"4"}
 -11-13T14:43:29 [app] [I] Completed 200 OK in 43.7ms (Views: 4.9ms | ActiveRecord: 17.0ms)
 -11-13T14:43:30 [app] [I] Started POST "/hosts/interfaces" for 172.20.8.22 at 2015-11-13 14:43:30 +1300
 -11-13T14:43:30 [app] [I] Processing by HostsController#interfaces as */*
 -11-13T14:43:30 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"192.168.250.3", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"1024", "cluster"=>"Palmerston North HA", "path"=>"/Datacenters/Palmerston North/vm/Informatics VM's", "guest_id"=>"ubuntu64Guest", "scsi_controller_type"=>"VirtualLsiLogicController", "hardware_version"=>"Default", "start"=>"1", "volumes_attributes"=>{"new_volumes"=>{"_delete"=>"", "datastore"=>"3Par_AO_1", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}, "0"=>{"_delete"=>"", "datastore"=>"PN_IBM_SAN_VM03", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "capabilities"=>"build image", "provider"=>"Vmware", "fakepassword"=>"[FILTERED]"}
 -11-13T14:43:30 [app] [I]   Rendered nic/_base_form.html.erb (24.5ms)
 -11-13T14:43:30 [app] [I]   Rendered nic/_virtual_form.html.erb (3.2ms)
 -11-13T14:43:33 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (3677.3ms)
 -11-13T14:43:33 [app] [I]   Rendered nic/_provider_specific_form.html.erb (3686.9ms)
 -11-13T14:43:33 [app] [I]   Rendered nic/manageds/_managed.html.erb (3728.3ms)
 -11-13T14:43:33 [app] [I]   Rendered nic/_base_form.html.erb (15.4ms)
 -11-13T14:43:33 [app] [I]   Rendered nic/_virtual_form.html.erb (1.5ms)
 -11-13T14:43:34 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (171.7ms)
 -11-13T14:43:34 [app] [I]   Rendered nic/_provider_specific_form.html.erb (173.4ms)
 -11-13T14:43:34 [app] [I]   Rendered nic/manageds/_managed.html.erb (193.0ms)
 -11-13T14:43:34 [app] [I]   Rendered nic/_base_form.html.erb (14.5ms)
 -11-13T14:43:34 [app] [I]   Rendered nic/_virtual_form.html.erb (1.4ms)
 -11-13T14:43:34 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (368.5ms)
 -11-13T14:43:34 [app] [I]   Rendered nic/_provider_specific_form.html.erb (370.0ms)
 -11-13T14:43:34 [app] [I]   Rendered nic/manageds/_managed.html.erb (393.1ms)
 -11-13T14:43:34 [app] [I]   Rendered hosts/_interfaces.html.erb (4324.3ms)
 -11-13T14:43:34 [app] [I]   Rendered hosts/_interfaces_tab.html.erb (4327.9ms)
 -11-13T14:43:34 [app] [I] Completed 200 OK in 4372.9ms (Views: 4329.1ms | ActiveRecord: 7.2ms)
 -11-13T14:43:51 [app] [I] Started POST "/hosts/template_used?provisioning=image" for 172.20.8.22 at 2015-11-13 14:43:51 +1300
 -11-13T14:43:51 [app] [I] Processing by HostsController#template_used as */*
 -11-13T14:43:51 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"eth0", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"192.168.250.3", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"VM_Config"}}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"eth1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"0", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"LAN172"}}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualE1000", "network"=>"Backup"}}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"1024", "cluster"=>"Palmerston North HA", "path"=>"/Datacenters/Palmerston North/vm/Informatics VM's", "guest_id"=>"ubuntu64Guest", "scsi_controller_type"=>"VirtualLsiLogicController", "hardware_version"=>"Default", "start"=>"1", "volumes_attributes"=>{"new_volumes"=>{"_delete"=>"", "datastore"=>"3Par_AO_1", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}, "0"=>{"_delete"=>"", "datastore"=>"PN_IBM_SAN_VM03", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}}, "image_id"=>"Informatics VM's/Ubuntu 14.04.1 Template"}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"image", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "capabilities"=>"build image", "provider"=>"Vmware", "fakepassword"=>"[FILTERED]", "provisioning"=>"image"}
 -11-13T14:43:51 [app] [I]   Rendered hosts/_provisioning.html.erb (5.3ms)
 -11-13T14:43:51 [app] [I] Completed 200 OK in 108.1ms (Views: 9.0ms | ActiveRecord: 21.2ms)
 -11-13T14:44:02 [app] [I] Started POST "/hosts" for 172.20.8.22 at 2015-11-13 14:44:02 +1300
 -11-13T14:44:03 [app] [I] Processing by HostsController#create as */*
 -11-13T14:44:03 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"eth0", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"192.168.250.3", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"VM_Config"}}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"eth1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"0", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"LAN172"}}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"1024", "cluster"=>"Palmerston North HA", "path"=>"/Datacenters/Palmerston North/vm/Informatics VM's", "guest_id"=>"ubuntu64Guest", "scsi_controller_type"=>"VirtualLsiLogicController", "hardware_version"=>"Default", "start"=>"1", "volumes_attributes"=>{"0"=>{"_delete"=>"", "datastore"=>"3Par_NL_RAID6_3", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}}, "image_id"=>"Informatics VM's/Ubuntu 14.04.1 Template"}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"image", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "capabilities"=>"build image", "provider"=>"Vmware"}
 -11-13T14:44:04 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:04 +1300
 -11-13T14:44:04 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:04 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:04 [app] [I]   Rendered tasks/_list.html.erb (5.5ms)
 -11-13T14:44:04 [app] [I] Completed 200 OK in 39.0ms (Views: 16.3ms | ActiveRecord: 7.8ms)
 -11-13T14:44:06 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:06 +1300
 -11-13T14:44:06 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:06 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:06 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:06 [app] [I] Completed 200 OK in 23.2ms (Views: 1.7ms | ActiveRecord: 5.9ms)
 -11-13T14:44:08 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:08 +1300
 -11-13T14:44:08 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:08 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:08 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:08 [app] [I] Completed 200 OK in 11.0ms (Views: 1.8ms | ActiveRecord: 1.5ms)
 -11-13T14:44:10 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:10 +1300
 -11-13T14:44:10 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:10 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:10 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:10 [app] [I] Completed 200 OK in 10.6ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:11 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:11 +1300
 -11-13T14:44:11 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:11 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:11 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:11 [app] [I] Completed 200 OK in 11.7ms (Views: 1.9ms | ActiveRecord: 1.6ms)
 -11-13T14:44:13 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:13 +1300
 -11-13T14:44:13 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:13 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:13 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:13 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:15 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:15 +1300
 -11-13T14:44:15 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:15 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:15 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:15 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:17 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:17 +1300
 -11-13T14:44:17 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:17 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:17 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:17 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:18 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:18 +1300
 -11-13T14:44:18 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:18 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:18 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:18 [app] [I] Completed 200 OK in 11.2ms (Views: 1.7ms | ActiveRecord: 1.7ms)
 -11-13T14:44:20 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:20 +1300
 -11-13T14:44:20 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:20 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:20 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:20 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:22 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:22 +1300
 -11-13T14:44:22 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:22 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:22 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:22 [app] [I] Completed 200 OK in 10.6ms (Views: 1.6ms | ActiveRecord: 1.6ms)
 -11-13T14:44:23 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:23 +1300
 -11-13T14:44:23 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:23 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:23 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:23 [app] [I] Completed 200 OK in 10.4ms (Views: 1.6ms | ActiveRecord: 1.5ms)
 -11-13T14:44:25 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:44:25 +1300
 -11-13T14:44:25 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:44:25 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:44:25 [app] [I] processing report for mapfactory
 -11-13T14:44:25 [app] [I] Imported report for mapfactory in 0.05 seconds
 -11-13T14:44:25 [app] [I]   Rendered api/v2/reports/create.json.rabl (10.7ms)
 -11-13T14:44:25 [app] [I] Completed 201 Created in 93.0ms (Views: 10.8ms | ActiveRecord: 35.5ms)
 -11-13T14:44:25 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:25 +1300
 -11-13T14:44:25 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:25 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:25 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:25 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:27 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:27 +1300
 -11-13T14:44:27 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:27 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:27 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:27 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.6ms)
 -11-13T14:44:29 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:29 +1300
 -11-13T14:44:29 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:29 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:29 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:29 [app] [I] Completed 200 OK in 20.8ms (Views: 1.7ms | ActiveRecord: 10.8ms)
 -11-13T14:44:30 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:30 +1300
 -11-13T14:44:30 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:30 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:30 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:30 [app] [I] Completed 200 OK in 10.4ms (Views: 1.6ms | ActiveRecord: 1.5ms)
 -11-13T14:44:32 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:32 +1300
 -11-13T14:44:32 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:32 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:32 [app] [I]   Rendered tasks/_list.html.erb (1.0ms)
 -11-13T14:44:32 [app] [I] Completed 200 OK in 11.1ms (Views: 1.9ms | ActiveRecord: 1.5ms)
 -11-13T14:44:34 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:34 +1300
 -11-13T14:44:34 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:34 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:34 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:34 [app] [I] Completed 200 OK in 11.3ms (Views: 1.9ms | ActiveRecord: 1.5ms)
 -11-13T14:44:36 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:36 +1300
 -11-13T14:44:36 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:36 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:36 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:36 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:37 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:37 +1300
 -11-13T14:44:37 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:37 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:37 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:37 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:39 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:39 +1300
 -11-13T14:44:39 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:39 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:39 [app] [I]   Rendered tasks/_list.html.erb (1.0ms)
 -11-13T14:44:39 [app] [I] Completed 200 OK in 10.7ms (Views: 1.8ms | ActiveRecord: 1.5ms)
 -11-13T14:44:41 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:44:41 +1300
 -11-13T14:44:41 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:44:41 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:44:41 [app] [I] processing report for zen
 -11-13T14:44:41 [app] [I] Imported report for zen in 0.04 seconds
 -11-13T14:44:41 [app] [I]   Rendered api/v2/reports/create.json.rabl (10.6ms)
 -11-13T14:44:41 [app] [I] Completed 201 Created in 80.4ms (Views: 11.2ms | ActiveRecord: 25.0ms)
 -11-13T14:44:41 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:41 +1300
 -11-13T14:44:41 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:41 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:41 [app] [I]   Rendered tasks/_list.html.erb (1.7ms)
 -11-13T14:44:41 [app] [I] Completed 200 OK in 18.0ms (Views: 5.8ms | ActiveRecord: 1.8ms)
 -11-13T14:44:42 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:44:42 +1300
 -11-13T14:44:42 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:44:42 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:44:42 [app] [I] processing report for sandbox2
 -11-13T14:44:42 [app] [I] Imported report for sandbox2 in 0.06 seconds
 -11-13T14:44:43 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:43 +1300
 -11-13T14:44:43 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:43 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:43 [app] [I]   Rendered api/v2/reports/create.json.rabl (42.1ms)
 -11-13T14:44:43 [app] [I] Completed 201 Created in 575.4ms (Views: 41.1ms | ActiveRecord: 41.5ms)
 -11-13T14:44:44 [app] [I]   Rendered tasks/_list.html.erb (26.2ms)
 -11-13T14:44:44 [app] [I] Completed 200 OK in 792.7ms (Views: 56.6ms | ActiveRecord: 23.0ms)
 -11-13T14:44:46 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:46 +1300
 -11-13T14:44:46 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:46 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:46 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:46 [app] [I] Completed 200 OK in 23.0ms (Views: 1.8ms | ActiveRecord: 5.3ms)
 -11-13T14:44:48 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:48 +1300
 -11-13T14:44:48 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:48 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:48 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:48 [app] [I] Completed 200 OK in 33.4ms (Views: 1.9ms | ActiveRecord: 15.0ms)
 -11-13T14:44:49 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:49 +1300
 -11-13T14:44:49 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:49 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:49 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:49 [app] [I] Completed 200 OK in 17.7ms (Views: 1.7ms | ActiveRecord: 8.0ms)
 -11-13T14:44:50 [app] [I] Started GET "/smart_proxies" for 172.20.8.22 at 2015-11-13 14:44:50 +1300
 -11-13T14:44:50 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:44:50 +1300
 -11-13T14:44:50 [app] [I] Processing by SmartProxiesController#index as HTML
 -11-13T14:44:50 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:44:50 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:44:50 [app] [I] processing report for helpdesk
 -11-13T14:44:50 [app] [I] Imported report for helpdesk in 0.05 seconds
 -11-13T14:44:50 [app] [I]   Rendered api/v2/reports/create.json.rabl (22.7ms)
 -11-13T14:44:50 [app] [I] Completed 201 Created in 125.5ms (Views: 20.8ms | ActiveRecord: 52.1ms)
 -11-13T14:44:50 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:44:50 +1300
 -11-13T14:44:50 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:44:50 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:44:50 [app] [I] processing report for openldap
 -11-13T14:44:50 [app] [I] Imported report for openldap in 0.13 seconds
 -11-13T14:44:50 [app] [I]   Rendered api/v2/reports/create.json.rabl (33.1ms)
 -11-13T14:44:50 [app] [I] Completed 201 Created in 229.0ms (Views: 25.1ms | ActiveRecord: 136.6ms)
 -11-13T14:44:51 [app] [I]   Rendered smart_proxies/index.html.erb within layouts/application (356.6ms)
 -11-13T14:44:51 [app] [I]   Rendered common/_searchbar.html.erb (10.6ms)
 -11-13T14:44:51 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:44:51 +1300
 -11-13T14:44:51 [app] [I]   Rendered home/_user_dropdown.html.erb (2.2ms)
 -11-13T14:44:51 [app] [I] Read fragment views/tabs_and_title_records-4 0.1ms
 -11-13T14:44:51 [app] [I]   Rendered home/_topbar.html.erb (7.7ms)
 -11-13T14:44:51 [app] [I]   Rendered layouts/base.html.erb (9.9ms)
 -11-13T14:44:51 [app] [I] Completed 200 OK in 913.1ms (Views: 381.7ms | ActiveRecord: 10.4ms)
 -11-13T14:44:51 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:44:51 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:44:51 [app] [I] processing report for dev-snowflake
 -11-13T14:44:51 [app] [I] Imported report for dev-snowflake in 0.03 seconds
 -11-13T14:44:51 [app] [I]   Rendered api/v2/reports/create.json.rabl (14.3ms)
 -11-13T14:44:51 [app] [I] Completed 201 Created in 100.2ms (Views: 14.2ms | ActiveRecord: 29.5ms)
 -11-13T14:44:52 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:52 +1300
 -11-13T14:44:52 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:52 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:52 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:52 [app] [I] Completed 200 OK in 10.4ms (Views: 1.7ms | ActiveRecord: 1.6ms)
 -11-13T14:44:53 [app] [I] Started GET "/smart_proxies/2-puppet%20master%203-2/edit" for 172.20.8.22 at 2015-11-13 14:44:53 +1300
 -11-13T14:44:53 [app] [I] Processing by SmartProxiesController#edit as */*
 -11-13T14:44:53 [app] [I]   Parameters: {"id"=>"2-puppet master 3-2"}
 -11-13T14:44:53 [app] [I]   Rendered taxonomies/_loc_org_tabs.html.erb (229.8ms)
 -11-13T14:44:53 [app] [I]   Rendered smart_proxies/_form.html.erb (240.4ms)
 -11-13T14:44:53 [app] [I]   Rendered smart_proxies/edit.html.erb (242.6ms)
 -11-13T14:44:53 [app] [I] Completed 200 OK in 263.4ms (Views: 248.5ms | ActiveRecord: 2.5ms)
 -11-13T14:44:54 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:54 +1300
 -11-13T14:44:54 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:54 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:54 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:44:54 [app] [I] Completed 200 OK in 11.0ms (Views: 1.8ms | ActiveRecord: 1.6ms)
 -11-13T14:44:56 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:56 +1300
 -11-13T14:44:56 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:56 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:56 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:56 [app] [I] Completed 200 OK in 10.8ms (Views: 1.8ms | ActiveRecord: 1.5ms)
 -11-13T14:44:58 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:44:58 +1300
 -11-13T14:44:58 [app] [I] Processing by TasksController#show as */*
 -11-13T14:44:58 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:44:58 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:44:58 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:44:58 [app] [I] Started PUT "/smart_proxies/2-puppet%20master%203-2/refresh" for 172.20.8.22 at 2015-11-13 14:44:58 +1300
 -11-13T14:44:58 [app] [I] Processing by SmartProxiesController#refresh as HTML
 -11-13T14:44:58 [app] [I]   Parameters: {"authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "id"=>"2-puppet master 3-2"}
 -11-13T14:44:58 [app] [I] Redirected to https://foreman.landcareresearch.co.nz/smart_proxies
 -11-13T14:44:58 [app] [I] Completed 302 Found in 285.6ms (ActiveRecord: 5.7ms)
 -11-13T14:44:59 [app] [I] Started GET "/smart_proxies" for 172.20.8.22 at 2015-11-13 14:44:59 +1300
 -11-13T14:44:59 [app] [I] Processing by SmartProxiesController#index as HTML
 -11-13T14:45:00 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:00 +1300
 -11-13T14:45:00 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:00 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:00 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:00 [app] [I] Completed 200 OK in 20.6ms (Views: 1.8ms | ActiveRecord: 7.1ms)
 -11-13T14:45:02 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:02 +1300
 -11-13T14:45:02 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:02 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:02 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:02 [app] [I] Completed 200 OK in 17.6ms (Views: 1.7ms | ActiveRecord: 8.1ms)
 -11-13T14:45:04 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:04 +1300
 -11-13T14:45:04 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:04 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:04 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:04 [app] [I] Completed 200 OK in 17.6ms (Views: 1.7ms | ActiveRecord: 8.0ms)
 -11-13T14:45:06 [app] [W] Failed to create a compute vSphere-PN (VMware) instance foreman-test-16.config.landcareresearch.co.nz: FileLocked: Unable to access file [PN_IBM_SAN_VM03] Ubuntu 14.04.1 Template/Ubuntu 14.04.1 Template.vmdk since it is locked
+       |
        | RbVmomi::Fault: FileLocked: Unable to access file [PN_IBM_SAN_VM03] Ubuntu 14.04.1 Template/Ubuntu 14.04.1 Template.vmdk since it is locked
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rbvmomi-1.8.2/lib/rbvmomi/vim/Task.rb:11:in `wait_for_completion'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/fog-1.34.0/lib/fog/vsphere/requests/compute/vm_clone.rb:596:in `vm_clone'
        | /usr/share/foreman/app/models/compute_resources/foreman/model/vmware.rb:374:in `clone_vm'
        | /usr/share/foreman/app/models/compute_resources/foreman/model/vmware.rb:323:in `create_vm'
        | /usr/share/foreman/app/models/concerns/orchestration/compute.rb:76:in `setCompute'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:168:in `execute'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:113:in `block in process'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:105:in `each'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:105:in `process'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `on_save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:671:in `_run__239469300626994092__save__1623790315542536772__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_save_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/callbacks.rb:264:in `create_or_update'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/persistence.rb:84:in `save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/validations.rb:50:in `save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/attribute_methods/dirty.rb:22:in `save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:259:in `block (2 levels) in save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:313:in `block in with_transaction_returning_status'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:208:in `transaction'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:311:in `with_transaction_returning_status'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:259:in `block in save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:270:in `rollback_active_record_state!'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:258:in `save'
        | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type'
        | /usr/share/foreman/app/controllers/hosts_controller.rb:85:in `create'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/base.rb:167:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/rendering.rb:10:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/callbacks.rb:18:in `block in process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:627:in `block (4 levels) in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7603'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:326:in `around'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:310:in `_callback_around_2491'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7603'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:626:in `block (3 levels) in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7602'
        | /usr/share/foreman/app/controllers/concerns/application_shared.rb:13:in `set_timezone'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7602'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:625:in `block (2 levels) in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7601'
        | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7601'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:448:in `block in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7600'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:326:in `around'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:310:in `_callback_around_13'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7600'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:414:in `_run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/callbacks.rb:17:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/rescue.rb:29:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/notifications.rb:123:in `block in instrument'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/notifications.rb:123:in `instrument'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/base.rb:121:in `process'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/rendering.rb:45:in `process'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal.rb:203:in `dispatch'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal.rb:246:in `block in action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:73:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:36:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:608:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/apipie-rails-0.2.6/lib/apipie/static_dispatcher.rb:65:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/etag.rb:23:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/conditionalget.rb:35:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/head.rb:14:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
        | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/flash.rb:242:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/session/abstract/id.rb:210:in `context'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/session/abstract/id.rb:205:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/cookies.rb:341:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/query_cache.rb:64:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/connection_pool.rb:479:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `_run__3326018171392106250__call__1623790315542536772__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/rack/logger.rb:32:in `call_app'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/rack/logger.rb:18:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/request_id.rb:22:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/methodoverride.rb:21:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/runtime.rb:17:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/lock.rb:15:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/static.rb:83:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/engine.rb:484:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/application.rb:231:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/railtie/configurable.rb:30:in `method_missing'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/builder.rb:134:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/urlmap.rb:64:in `block in call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/urlmap.rb:49:in `each'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/urlmap.rb:49:in `call'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:142:in `accept_and_process_next_request'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:448:in `block (3 levels) in start_threads'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/logging-2.0.0/lib/logging/diagnostic_context.rb:448:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/logging-2.0.0/lib/logging/diagnostic_context.rb:448:in `block in create_with_logging_context'
 -11-13T14:45:06 [app] [I] Failed to save: Failed to create a compute vSphere-PN (VMware) instance foreman-test-16.config.landcareresearch.co.nz: FileLocked: Unable to access file [PN_IBM_SAN_VM03] Ubuntu 14.04.1 Template/Ubuntu 14.04.1 Template.vmdk since it is locked
+       |
 -11-13T14:45:06 [app] [I]   Rendered hosts/_progress.html.erb (0.4ms)
 -11-13T14:45:06 [app] [I]   Rendered puppetclasses/_selectedClasses.html.erb (0.0ms)
 -11-13T14:45:06 [app] [I]   Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms)
 -11-13T14:45:06 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:06 +1300
 -11-13T14:45:06 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:06 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:06 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:45:06 [app] [I] Completed 200 OK in 31.9ms (Views: 1.8ms | ActiveRecord: 11.5ms)
 -11-13T14:45:07 [app] [I]   Rendered puppetclasses/_classes.html.erb (944.0ms)
 -11-13T14:45:07 [app] [I]   Rendered puppetclasses/_class_selection.html.erb (1276.1ms)
 -11-13T14:45:07 [app] [I]   Rendered nic/_base_form.html.erb (36.2ms)
 -11-13T14:45:07 [app] [I]   Rendered nic/_virtual_form.html.erb (1.6ms)
 -11-13T14:45:08 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (742.9ms)
 -11-13T14:45:08 [app] [I]   Rendered nic/_provider_specific_form.html.erb (745.4ms)
 -11-13T14:45:08 [app] [I]   Rendered nic/manageds/_managed.html.erb (790.3ms)
 -11-13T14:45:08 [app] [I]   Rendered nic/_base_form.html.erb (31.8ms)
 -11-13T14:45:08 [app] [I]   Rendered nic/_virtual_form.html.erb (1.6ms)
 -11-13T14:45:09 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:09 +1300
 -11-13T14:45:09 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:09 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:09 [app] [I]   Rendered tasks/_list.html.erb (9.5ms)
 -11-13T14:45:09 [app] [I] Completed 200 OK in 31.9ms (Views: 10.4ms | ActiveRecord: 3.2ms)
 -11-13T14:45:09 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (672.9ms)
 -11-13T14:45:09 [app] [I]   Rendered nic/_provider_specific_form.html.erb (678.9ms)
 -11-13T14:45:09 [app] [I]   Rendered nic/manageds/_managed.html.erb (719.4ms)
 -11-13T14:45:09 [app] [I]   Rendered nic/_base_form.html.erb (46.2ms)
 -11-13T14:45:09 [app] [I]   Rendered nic/_virtual_form.html.erb (9.8ms)
 -11-13T14:45:09 [app] [I]   Rendered compute_resources_vms/form/vmware/_network.html.erb (676.0ms)
 -11-13T14:45:09 [app] [I]   Rendered nic/_provider_specific_form.html.erb (677.5ms)
 -11-13T14:45:09 [app] [I]   Rendered nic/manageds/_managed.html.erb (744.3ms)
 -11-13T14:45:09 [app] [I]   Rendered hosts/_interfaces.html.erb (2266.2ms)
 -11-13T14:45:11 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:11 +1300
 -11-13T14:45:11 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:11 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:11 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:11 [app] [I] Completed 200 OK in 26.5ms (Views: 1.7ms | ActiveRecord: 16.9ms)
 -11-13T14:45:12 [app] [I]   Rendered compute_resources_vms/form/vmware/_base.html.erb (2136.7ms)
 -11-13T14:45:13 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:13 +1300
 -11-13T14:45:13 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:13 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:13 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:45:13 [app] [I] Completed 200 OK in 51.9ms (Views: 2.0ms | ActiveRecord: 14.3ms)
 -11-13T14:45:14 [app] [I]   Rendered smart_proxies/index.html.erb within layouts/application (15082.8ms)
 -11-13T14:45:14 [app] [I]   Rendered common/_searchbar.html.erb (34.5ms)
 -11-13T14:45:14 [app] [I]   Rendered home/_user_dropdown.html.erb (36.6ms)
 -11-13T14:45:14 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:45:14 [app] [I]   Rendered home/_topbar.html.erb (40.9ms)
 -11-13T14:45:14 [app] [I]   Rendered layouts/base.html.erb (55.0ms)
 -11-13T14:45:14 [app] [I] Completed 200 OK in 15198.3ms (Views: 15178.7ms | ActiveRecord: 6.3ms)
 -11-13T14:45:14 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (2451.6ms)
 -11-13T14:45:15 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:15 +1300
 -11-13T14:45:15 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:15 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:15 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:45:15 [app] [I] Completed 200 OK in 21.3ms (Views: 1.9ms | ActiveRecord: 9.7ms)
 -11-13T14:45:16 [app] [I]   Rendered compute_resources_vms/form/vmware/_volume.html.erb (1645.8ms)
 -11-13T14:45:16 [app] [I]   Rendered compute_resources_vms/form/_volumes.html.erb (4102.3ms)
 -11-13T14:45:16 [app] [I]   Rendered hosts/_compute_detail.html.erb (6246.8ms)
 -11-13T14:45:16 [app] [I]   Rendered hosts/_compute.html.erb (6260.8ms)
 -11-13T14:45:16 [app] [I]   Rendered common/os_selection/_architecture.html.erb (290.5ms)
 -11-13T14:45:16 [app] [I]   Rendered common/os_selection/_operatingsystem.html.erb (39.2ms)
 -11-13T14:45:16 [app] [I]   Rendered hosts/_operating_system.html.erb (339.3ms)
 -11-13T14:45:16 [app] [I]   Rendered hosts/_unattended.html.erb (6601.8ms)
 -11-13T14:45:16 [app] [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
 -11-13T14:45:16 [app] [I]   Rendered puppetclasses/_classes_parameters.html.erb (15.6ms)
 -11-13T14:45:16 [app] [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (3.9ms)
 -11-13T14:45:16 [app] [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (26.5ms)
 -11-13T14:45:16 [app] [I]   Rendered common_parameters/_inherited_parameters.html.erb (2.2ms)
 -11-13T14:45:16 [app] [I]   Rendered common_parameters/_parameter.html.erb (2.1ms)
 -11-13T14:45:16 [app] [I]   Rendered common_parameters/_parameters.html.erb (5.4ms)
 -11-13T14:45:16 [app] [I]   Rendered hosts/_form.html.erb (10423.4ms)
 -11-13T14:45:16 [app] [I]   Rendered hosts/new.html.erb within layouts/application (10425.0ms)
 -11-13T14:45:16 [app] [I]   Rendered home/_user_dropdown.html.erb (1.9ms)
 -11-13T14:45:16 [app] [I] Read fragment views/tabs_and_title_records-4 0.1ms
 -11-13T14:45:16 [app] [I]   Rendered home/_topbar.html.erb (3.1ms)
 -11-13T14:45:16 [app] [I]   Rendered layouts/base.html.erb (5.3ms)
 -11-13T14:45:16 [app] [I] Completed 200 OK in 73602.5ms (Views: 10253.2ms | ActiveRecord: 280.3ms)
 -11-13T14:45:17 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:17 +1300
 -11-13T14:45:17 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:17 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:17 [app] [I]   Rendered tasks/_list.html.erb (1.4ms)
 -11-13T14:45:17 [app] [I] Completed 200 OK in 16.9ms (Views: 5.3ms | ActiveRecord: 1.6ms)
 -11-13T14:45:33 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:45:33 +1300
 -11-13T14:45:33 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:45:33 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:45:33 [app] [I] processing report for proxy
 -11-13T14:45:34 [app] [I] Imported report for proxy in 0.26 seconds
 -11-13T14:45:34 [app] [I]   Rendered api/v2/reports/create.json.rabl (18.8ms)
 -11-13T14:45:34 [app] [I] Completed 201 Created in 338.1ms (Views: 20.5ms | ActiveRecord: 18.4ms)
 -11-13T14:45:39 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:45:39 +1300
 -11-13T14:45:39 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:45:39 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:45:39 [app] [I] processing report for git
 -11-13T14:45:39 [app] [I] Imported report for git in 0.02 seconds
 -11-13T14:45:39 [app] [I]   Rendered api/v2/reports/create.json.rabl (11.2ms)
 -11-13T14:45:39 [app] [I] Completed 201 Created in 64.6ms (Views: 11.2ms | ActiveRecord: 12.0ms)
 -11-13T14:45:40 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:45:40 +1300
 -11-13T14:45:40 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:45:40 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:45:40 [app] [I] processing report for test-snowflake
 -11-13T14:45:40 [app] [I] Imported report for test-snowflake in 0.02 seconds
 -11-13T14:45:40 [app] [I]   Rendered api/v2/reports/create.json.rabl (10.8ms)
 -11-13T14:45:40 [app] [I] Completed 201 Created in 64.2ms (Views: 10.8ms | ActiveRecord: 12.2ms)
 -11-13T14:45:41 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:45:41 +1300
 -11-13T14:45:41 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:45:41 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:45:41 [app] [I] processing report for antarctic-data
 -11-13T14:45:41 [app] [I] Imported report for antarctic-data in 0.02 seconds
 -11-13T14:45:41 [app] [I]   Rendered api/v2/reports/create.json.rabl (10.8ms)
 -11-13T14:45:41 [app] [I] Completed 201 Created in 497.0ms (Views: 10.9ms | ActiveRecord: 12.5ms)
 -11-13T14:45:49 [app] [I] Started POST "/hosts" for 172.20.8.22 at 2015-11-13 14:45:49 +1300
 -11-13T14:45:49 [app] [I] Processing by HostsController#create as */*
 -11-13T14:45:49 [app] [I]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"ooZz/2EXEJge/nzDC9kXDLWMjGc3kXSCBEOoQ5PBiHw=", "host"=>{"name"=>"foreman-test-16", "hostgroup_id"=>"2", "compute_resource_id"=>"4", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"eth0", "name"=>"foreman-test-16", "domain_id"=>"9", "subnet_id"=>"13", "ip"=>"192.168.250.3", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"VM_Config"}}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"eth1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "managed"=>"0", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"LAN172"}}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"1024", "cluster"=>"Palmerston North HA", "path"=>"/Datacenters/Palmerston North/vm/Informatics VM's", "guest_id"=>"ubuntu64Guest", "scsi_controller_type"=>"VirtualLsiLogicController", "hardware_version"=>"Default", "start"=>"1", "volumes_attributes"=>{"0"=>{"_delete"=>"", "datastore"=>"3Par_NL_RAID6_3", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}}, "image_id"=>"Informatics VM's/Ubuntu 14.04.1 Template"}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"image", "build"=>"1", "medium_id"=>"", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "comment"=>"", "overwrite"=>"false"}, "capabilities"=>"build image", "provider"=>"Vmware"}
 -11-13T14:45:51 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:51 +1300
 -11-13T14:45:51 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:51 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:51 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:51 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:45:53 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:53 +1300
 -11-13T14:45:53 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:53 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:53 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:53 [app] [I] Completed 200 OK in 19.3ms (Views: 1.7ms | ActiveRecord: 7.4ms)
 -11-13T14:45:54 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:54 +1300
 -11-13T14:45:54 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:54 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:54 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:45:54 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.8ms)
 -11-13T14:45:56 [app] [I] Started POST "/api/reports" for 172.20.88.174 at 2015-11-13 14:45:56 +1300
 -11-13T14:45:56 [app] [I] Processing by Api::V2::ReportsController#create as JSON
 -11-13T14:45:56 [app] [I]   Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
 -11-13T14:45:56 [app] [I] processing report for soils-test-01.config.landcareresearch.co.nz
 -11-13T14:45:56 [app] [I] Imported report for soils-test-01.config.landcareresearch.co.nz in 0.09 seconds
 -11-13T14:45:56 [app] [I]   Rendered api/v2/reports/create.json.rabl (29.4ms)
 -11-13T14:45:56 [app] [I] Completed 201 Created in 410.6ms (Views: 17.8ms | ActiveRecord: 79.5ms)
 -11-13T14:45:56 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:56 +1300
 -11-13T14:45:56 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:56 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:56 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:45:56 [app] [I] Completed 200 OK in 10.8ms (Views: 1.8ms | ActiveRecord: 1.5ms)
 -11-13T14:45:58 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:45:58 +1300
 -11-13T14:45:58 [app] [I] Processing by TasksController#show as */*
 -11-13T14:45:58 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:45:58 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:45:58 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:00 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:00 +1300
 -11-13T14:46:00 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:00 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:00 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:00 [app] [I] Completed 200 OK in 10.6ms (Views: 1.8ms | ActiveRecord: 1.5ms)
 -11-13T14:46:01 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:01 +1300
 -11-13T14:46:01 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:01 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:01 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:01 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:03 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:03 +1300
 -11-13T14:46:03 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:03 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:03 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:03 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:05 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:05 +1300
 -11-13T14:46:05 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:05 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:05 [app] [I]   Rendered tasks/_list.html.erb (3.5ms)
 -11-13T14:46:05 [app] [I] Completed 200 OK in 23.7ms (Views: 4.3ms | ActiveRecord: 8.1ms)
 -11-13T14:46:06 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:06 +1300
 -11-13T14:46:06 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:06 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:07 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:07 [app] [I] Completed 200 OK in 10.8ms (Views: 1.7ms | ActiveRecord: 1.6ms)
 -11-13T14:46:08 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:08 +1300
 -11-13T14:46:08 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:08 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:08 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:08 [app] [I] Completed 200 OK in 10.4ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:10 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:10 +1300
 -11-13T14:46:10 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:10 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:10 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:10 [app] [I] Completed 200 OK in 10.3ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:12 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:12 +1300
 -11-13T14:46:12 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:12 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:12 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:12 [app] [I] Completed 200 OK in 11.0ms (Views: 1.9ms | ActiveRecord: 1.5ms)
 -11-13T14:46:13 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:13 +1300
 -11-13T14:46:13 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:13 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:13 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:13 [app] [I] Completed 200 OK in 10.6ms (Views: 1.7ms | ActiveRecord: 1.6ms)
 -11-13T14:46:15 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:15 +1300
 -11-13T14:46:15 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:15 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:15 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:15 [app] [I] Completed 200 OK in 11.0ms (Views: 1.8ms | ActiveRecord: 1.5ms)
 -11-13T14:46:17 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:17 +1300
 -11-13T14:46:17 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:17 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:17 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:17 [app] [I] Completed 200 OK in 11.0ms (Views: 1.7ms | ActiveRecord: 1.6ms)
 -11-13T14:46:19 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:19 +1300
 -11-13T14:46:19 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:19 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:19 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:19 [app] [I] Completed 200 OK in 21.9ms (Views: 4.1ms | ActiveRecord: 9.9ms)
 -11-13T14:46:21 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:21 +1300
 -11-13T14:46:21 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:21 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:21 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:21 [app] [I] Completed 200 OK in 10.6ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:22 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:22 +1300
 -11-13T14:46:22 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:22 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:22 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:22 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:24 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:24 +1300
 -11-13T14:46:24 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:24 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:24 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:24 [app] [I] Completed 200 OK in 10.6ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:26 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:26 +1300
 -11-13T14:46:26 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:26 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:26 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:26 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:27 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:27 +1300
 -11-13T14:46:27 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:27 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:27 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:27 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:29 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:29 +1300
 -11-13T14:46:29 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:29 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:29 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:29 [app] [I] Completed 200 OK in 10.9ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:31 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:31 +1300
 -11-13T14:46:31 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:31 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:31 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:31 [app] [I] Completed 200 OK in 18.4ms (Views: 1.7ms | ActiveRecord: 6.1ms)
 -11-13T14:46:33 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:33 +1300
 -11-13T14:46:33 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:33 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:33 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:33 [app] [I] Completed 200 OK in 19.6ms (Views: 1.8ms | ActiveRecord: 10.0ms)
 -11-13T14:46:34 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:34 +1300
 -11-13T14:46:34 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:34 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:34 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:34 [app] [I] Completed 200 OK in 10.6ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:36 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:36 +1300
 -11-13T14:46:36 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:36 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:36 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:36 [app] [I] Completed 200 OK in 11.1ms (Views: 1.8ms | ActiveRecord: 1.6ms)
 -11-13T14:46:38 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:38 +1300
 -11-13T14:46:38 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:38 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:38 [app] [I]   Rendered tasks/_list.html.erb (1.0ms)
 -11-13T14:46:38 [app] [I] Completed 200 OK in 11.7ms (Views: 2.1ms | ActiveRecord: 1.7ms)
 -11-13T14:46:40 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:40 +1300
 -11-13T14:46:40 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:40 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:40 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:40 [app] [I] Completed 200 OK in 10.8ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:41 [app] [I] Create DHCP reservation for foreman-test-16.config.landcareresearch.co.nz-00:50:56:8a:6e:cf/192.168.250.3
 -11-13T14:46:41 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:41 +1300
 -11-13T14:46:41 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:41 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:41 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:41 [app] [I] Completed 200 OK in 10.8ms (Views: 1.8ms | ActiveRecord: 1.6ms)
 -11-13T14:46:43 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:43 +1300
 -11-13T14:46:43 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:43 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:43 [app] [I]   Rendered tasks/_list.html.erb (1.1ms)
 -11-13T14:46:43 [app] [I] Completed 200 OK in 11.7ms (Views: 2.0ms | ActiveRecord: 1.9ms)
 -11-13T14:46:45 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:45 +1300
 -11-13T14:46:45 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:45 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:45 [app] [I]   Rendered tasks/_list.html.erb (13.1ms)
 -11-13T14:46:45 [app] [I] Completed 200 OK in 40.2ms (Views: 14.1ms | ActiveRecord: 10.0ms)
 -11-13T14:46:47 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:47 +1300
 -11-13T14:46:47 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:47 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:47 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:47 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:48 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:48 +1300
 -11-13T14:46:48 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:48 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:48 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:48 [app] [I] Completed 200 OK in 11.0ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:50 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:50 +1300
 -11-13T14:46:50 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:50 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:50 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:50 [app] [I] Completed 200 OK in 10.5ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:52 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:52 +1300
 -11-13T14:46:52 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:52 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:52 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:52 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:53 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:53 +1300
 -11-13T14:46:53 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:53 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:53 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:46:53 [app] [I] Completed 200 OK in 10.7ms (Views: 1.7ms | ActiveRecord: 1.5ms)
 -11-13T14:46:55 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:55 +1300
 -11-13T14:46:55 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:55 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:55 [app] [I]   Rendered tasks/_list.html.erb (6.1ms)
 -11-13T14:46:55 [app] [I] Completed 200 OK in 249.1ms (Views: 7.2ms | ActiveRecord: 1.5ms)
 -11-13T14:46:57 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:57 +1300
 -11-13T14:46:57 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:57 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:57 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:57 [app] [I] Completed 200 OK in 11.6ms (Views: 2.1ms | ActiveRecord: 1.6ms)
 -11-13T14:46:59 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:46:59 +1300
 -11-13T14:46:59 [app] [I] Processing by TasksController#show as */*
 -11-13T14:46:59 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:46:59 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:46:59 [app] [I] Completed 200 OK in 11.5ms (Views: 2.0ms | ActiveRecord: 1.6ms)
 -11-13T14:47:01 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:47:01 +1300
 -11-13T14:47:01 [app] [I] Processing by TasksController#show as */*
 -11-13T14:47:01 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:47:01 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:47:01 [app] [I] Completed 200 OK in 11.2ms (Views: 2.0ms | ActiveRecord: 1.6ms)
 -11-13T14:47:02 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:47:02 +1300
 -11-13T14:47:02 [app] [I] Processing by TasksController#show as */*
 -11-13T14:47:02 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:47:02 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:47:02 [app] [I] Completed 200 OK in 11.1ms (Views: 2.0ms | ActiveRecord: 1.6ms)
 -11-13T14:47:04 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:47:04 +1300
 -11-13T14:47:04 [app] [I] Processing by TasksController#show as */*
 -11-13T14:47:04 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:47:04 [app] [I]   Rendered tasks/_list.html.erb (0.9ms)
 -11-13T14:47:04 [app] [I] Completed 200 OK in 11.0ms (Views: 2.0ms | ActiveRecord: 1.5ms)
 -11-13T14:47:06 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:47:06 +1300
 -11-13T14:47:06 [app] [I] Processing by TasksController#show as */*
 -11-13T14:47:06 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:47:06 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:47:06 [app] [I] Completed 200 OK in 10.9ms (Views: 2.0ms | ActiveRecord: 1.5ms)
 -11-13T14:47:07 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:47:07 +1300
 -11-13T14:47:07 [app] [I] Processing by TasksController#show as */*
 -11-13T14:47:07 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:47:07 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:47:07 [app] [I] Completed 200 OK in 10.9ms (Views: 1.9ms | ActiveRecord: 1.5ms)
 -11-13T14:47:09 [app] [I] negotiating protocol version
 -11-13T14:47:09 [app] [I] got KEXINIT from server
 -11-13T14:47:09 [app] [I] sending KEXINIT
 -11-13T14:47:09 [app] [I] negotiating algorithms
 -11-13T14:47:09 [app] [I] Started GET "/tasks/90c245f5-949f-4407-bb9e-b19e0fe229f4" for 172.20.8.22 at 2015-11-13 14:47:09 +1300
 -11-13T14:47:09 [app] [I] Processing by TasksController#show as */*
 -11-13T14:47:09 [app] [I]   Parameters: {"id"=>"90c245f5-949f-4407-bb9e-b19e0fe229f4"}
 -11-13T14:47:09 [app] [I]   Rendered tasks/_list.html.erb (0.8ms)
 -11-13T14:47:09 [app] [I] Completed 200 OK in 10.9ms (Views: 1.9ms | ActiveRecord: 1.5ms)
 -11-13T14:47:09 [app] [I] channel_open_confirmation: 0 0 0 32768
 -11-13T14:47:09 [app] [I] sending channel request "pty-req"
 -11-13T14:47:09 [app] [I] sending channel request "exec"
 -11-13T14:47:09 [app] [I] channel_window_adjust: 0 +2097152
 -11-13T14:47:09 [app] [I] channel_success: 0
 -11-13T14:47:09 [app] [I] channel_request: 0 exit-status false
 -11-13T14:47:09 [app] [I] channel_data: 0 21b
 -11-13T14:47:09 [app] [I] channel_eof: 0
 -11-13T14:47:09 [app] [I] channel_close: 0
 -11-13T14:47:09 [app] [I] closing remaining channels (0 open)
 -11-13T14:47:09 [app] [W] Enable certificate generation for foreman-test-16.config.landcareresearch.co.nz task failed with the following error: ERF12-7740 [ProxyAPI::ProxyException]: Unable to delete PuppetCA certificate for foreman-test-16.config.landcareresearch.co.nz ([RestClient::Forbidden]: 403 Forbidden) for proxy http://puppet.zen.landcareresearch.co.nz:8000/puppet/ca
        | ProxyAPI::ProxyException: ERF12-7740 [ProxyAPI::ProxyException]: Unable to delete PuppetCA certificate for foreman-test-16.config.landcareresearch.co.nz ([RestClient::Forbidden]: 403 Forbidden) for proxy http://puppet.zen.landcareresearch.co.nz:8000/puppet/ca
        | /usr/share/foreman/lib/proxy_api/puppetca.rb:41:in `rescue in del_certificate'
        | /usr/share/foreman/lib/proxy_api/puppetca.rb:36:in `del_certificate'
        | /usr/share/foreman/app/models/concerns/orchestration/puppetca.rb:24:in `delCertificate'
        | /usr/share/foreman/app/models/host/managed.rb:299:in `handle_ca'
        | /usr/share/foreman/app/models/concerns/orchestration/ssh_provision.rb:64:in `setSSHCert'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:168:in `execute'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:113:in `block in process'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:105:in `each'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:105:in `process'
        | /usr/share/foreman/app/models/concerns/orchestration.rb:39:in `post_commit'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `_run__239469300626994092__commit__1623790315542536772__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_commit_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:281:in `committed!'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/database_statements.rb:372:in `block in commit_transaction_records'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/database_statements.rb:370:in `each'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/database_statements.rb:370:in `commit_transaction_records'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/database_statements.rb:218:in `transaction'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:208:in `transaction'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:311:in `with_transaction_returning_status'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:259:in `block in save'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:270:in `rollback_active_record_state!'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/transactions.rb:258:in `save'
        | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type'
        | /usr/share/foreman/app/controllers/hosts_controller.rb:85:in `create'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/base.rb:167:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/rendering.rb:10:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/callbacks.rb:18:in `block in process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:627:in `block (4 levels) in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7603'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:326:in `around'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:310:in `_callback_around_2491'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7603'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:626:in `block (3 levels) in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7602'
        | /usr/share/foreman/app/controllers/concerns/application_shared.rb:13:in `set_timezone'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7602'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:625:in `block (2 levels) in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7601'
        | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7601'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:448:in `block in _run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7600'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:326:in `around'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:310:in `_callback_around_13'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7600'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:414:in `_run__2218685797928224935__process_action__2119658614368751041__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/callbacks.rb:17:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/rescue.rb:29:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/notifications.rb:123:in `block in instrument'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/notifications.rb:123:in `instrument'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/base.rb:121:in `process'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/abstract_controller/rendering.rb:45:in `process'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal.rb:203:in `dispatch'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_controller/metal.rb:246:in `block in action'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:73:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:36:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/routing/route_set.rb:608:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/apipie-rails-0.2.6/lib/apipie/static_dispatcher.rb:65:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/etag.rb:23:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/conditionalget.rb:35:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/head.rb:14:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
        | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/flash.rb:242:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/session/abstract/id.rb:210:in `context'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/session/abstract/id.rb:205:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/cookies.rb:341:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/query_cache.rb:64:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activerecord-3.2.21/lib/active_record/connection_adapters/abstract/connection_pool.rb:479:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `_run__3326018171392106250__call__1623790315542536772__callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/rack/logger.rb:32:in `call_app'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/rack/logger.rb:18:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/request_id.rb:22:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/methodoverride.rb:21:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/runtime.rb:17:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/activesupport-3.2.21/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/lock.rb:15:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/actionpack-3.2.21/lib/action_dispatch/middleware/static.rb:83:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/engine.rb:484:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/application.rb:231:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/railties-3.2.21/lib/rails/railtie/configurable.rb:30:in `method_missing'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/builder.rb:134:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/urlmap.rb:64:in `block in call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/urlmap.rb:49:in `each'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/rack-1.4.7/lib/rack/urlmap.rb:49:in `call'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:142:in `accept_and_process_next_request'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
        | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:448:in `block (3 levels) in start_threads'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/logging-2.0.0/lib/logging/diagnostic_context.rb:448:in `call'
        | /usr/share/foreman/vendor/ruby/1.9.1/gems/logging-2.0.0/lib/logging/diagnostic_context.rb:448:in `block in create_with_logging_context'
 -11-13T14:47:10 [app] [I] Redirected to https://foreman.landcareresearch.co.nz/hosts/foreman-test-16.config.landcareresearch.co.nz
 -11-13T14:47:10 [app] [I] Completed 302 Found in 80106.8ms (ActiveRecord: 259.1ms)
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:10 [app] [I] Processing by HostsController#show as */*
 -11-13T14:47:10 [app] [I]   Parameters: {"id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:10 [app] [I] [1;32mDeface: [WARNING][0m No :original defined for 'add_load_partials_js', you should change its definition to include:
        |  :original => 'e1525ef1577082e8f5d01ca3c9c7df1ceaab80ae'
 -11-13T14:47:10 [app] [E] [1;32mDeface:[0m 'add_load_partials_js_legacy' matched 0 times with 'code:contains("javascript")'
 -11-13T14:47:10 [app] [E] [1;32mDeface: [WARNING][0m Override 'add_load_partials_js_legacy' may be using an invalid selector of 'code:contains("javascript")', <code erb-loud|silent> tags are now <erb loud|silent>
 -11-13T14:47:10 [app] [I]   Rendered hosts/show.html.erb within layouts/application (67.0ms)
 -11-13T14:47:10 [app] [I]   Rendered home/_user_dropdown.html.erb (2.0ms)
 -11-13T14:47:10 [app] [I] Read fragment views/tabs_and_title_records-4 0.2ms
 -11-13T14:47:10 [app] [I]   Rendered home/_topbar.html.erb (3.8ms)
 -11-13T14:47:10 [app] [I]   Rendered layouts/base.html.erb (6.0ms)
 -11-13T14:47:10 [app] [I] Completed 200 OK in 410.7ms (Views: 355.4ms | ActiveRecord: 33.0ms)
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz/overview" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz/resources?range=7" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz/vm" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz/runtime?range=7" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:10 [app] [I] Processing by HostsController#vm as HTML
 -11-13T14:47:10 [app] [I] Processing by HostsController#resources as HTML
 -11-13T14:47:10 [app] [I] Processing by HostsController#overview as HTML
 -11-13T14:47:10 [app] [I]   Parameters: {"range"=>"7", "id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:10 [app] [I]   Parameters: {"id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:10 [app] [I]   Parameters: {"id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:10 [app] [I] Processing by HostsController#runtime as HTML
 -11-13T14:47:10 [app] [I]   Parameters: {"range"=>"7", "id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:10 [app] [I]   Rendered hosts/_resources.html.erb (38.8ms)
 -11-13T14:47:10 [app] [I] Completed 200 OK in 150.7ms (Views: 66.7ms | ActiveRecord: 48.4ms)
 -11-13T14:47:10 [app] [I]   Rendered hosts/_runtime.html.erb (39.9ms)
 -11-13T14:47:10 [app] [I] Completed 200 OK in 148.6ms (Views: 62.7ms | ActiveRecord: 56.5ms)
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz/templates" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:10 [app] [I] Started GET "/hosts/foreman-test-16.config.landcareresearch.co.nz/nics" for 172.20.8.22 at 2015-11-13 14:47:10 +1300
 -11-13T14:47:11 [app] [I]   Rendered hosts/_overview.html.erb (125.7ms)
 -11-13T14:47:11 [app] [I] Completed 200 OK in 232.6ms (Views: 91.5ms | ActiveRecord: 109.7ms)
 -11-13T14:47:11 [app] [I] Processing by HostsController#nics as HTML
 -11-13T14:47:11 [app] [I]   Parameters: {"id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:11 [app] [I]   Rendered hosts/_nics.html.erb (24.7ms)
 -11-13T14:47:11 [app] [I] Completed 200 OK in 101.8ms (Views: 26.6ms | ActiveRecord: 49.5ms)
 -11-13T14:47:11 [app] [I] Processing by HostsController#templates as HTML
 -11-13T14:47:11 [app] [I]   Parameters: {"id"=>"foreman-test-16.config.landcareresearch.co.nz"}
 -11-13T14:47:12 [app] [I]   Rendered text template (0.0ms)
 -11-13T14:47:12 [app] [I] Completed 200 OK in 471.1ms (Views: 35.5ms | ActiveRecord: 248.4ms)
 -11-13T14:47:17 [app] [I]   Rendered compute_resources_vms/show/_vmware.html.erb (302.8ms)
 -11-13T14:47:17 [app] [I]   Rendered compute_resources_vms/_details.html.erb (314.6ms)
 -11-13T14:47:17 [app] [I] Completed 200 OK in 6716.3ms (Views: 332.6ms | ActiveRecord: 48.2ms)

« Previous
1
2
3
Next »

(3-3/3)

Project

General

Profile

Bug #12487 » foreman.log