Project

General

Profile

Bug #13004 » computeresource debug.txt

Chris Pisano, 01/13/2016 09:20 AM

 
2016-01-13 08:18:31 [app] [D] Cache read: https://atxentlfor-d01.advisory.com/hosts/compute_resource_selected?
2016-01-13 08:18:31 [app] [I]
|
| Started POST "/hosts/compute_resource_selected" for 10.10.153.104 at 2016-01-13 08:18:31 -0600
2016-01-13 08:18:31 [app] [I] Processing by HostsController#compute_resource_selected as */*
2016-01-13 08:18:31 [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"6CX3PeBY+sfx8Vp091r+p/59sMPYTMUkv/OPSnC9OcU=", "host"=>{"name"=>"foremanbug", "organization_id"=>"3", "location_id"=>"4", "hostgroup_id"=>"92", "compute_resource_id"=>"1", "config_group_ids"=>[""], "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foremanbug", "domain_id"=>"1", "subnet_id"=>"7", "ip"=>"10.160.192.161", "managed"=>"1", "primary"=>"1", "provision"=>"1", "execution"=>"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", "execution"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"33-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]"}
2016-01-13 08:18:31 [sql] [D] User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1 [["id", 33]]
2016-01-13 08:18:31 [app] [D] Setting current user thread-local variable to pisanoc
2016-01-13 08:18:31 [app] [D] Cache read: authorize_login_delegation
2016-01-13 08:18:31 [app] [D] Cache read: authorize_login_delegation
2016-01-13 08:18:31 [app] [D] Cache read: idle_timeout
2016-01-13 08:18:31 [sql] [D] (0.6ms) SELECT COUNT(*) FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization')
2016-01-13 08:18:31 [app] [D] Setting current organization thread-local variable to none
2016-01-13 08:18:31 [sql] [D] (0.5ms) SELECT COUNT(*) FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location')
2016-01-13 08:18:31 [app] [D] Setting current location thread-local variable to none
2016-01-13 08:18:31 [sql] [D] AuthSource Load (0.7ms) SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 5 LIMIT 1
2016-01-13 08:18:31 [sql] [D] (0.5ms) SELECT id FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') LIMIT 1
2016-01-13 08:18:31 [sql] [D] (0.5ms) SELECT id FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') LIMIT 1
2016-01-13 08:18:31 [sql] [D] Organization Load (0.7ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" = 3 ORDER BY title LIMIT 1
2016-01-13 08:18:31 [sql] [D] Location Load (0.6ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" = 4 ORDER BY title LIMIT 1
2016-01-13 08:18:31 [app] [D] Setting current organization thread-local variable to ent
2016-01-13 08:18:31 [app] [D] Setting current location thread-local variable to austin
2016-01-13 08:18:31 [sql] [D] Taxonomy Load (0.6ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 4 or taxonomies.ancestry like '4/%' or taxonomies.ancestry = '4') ORDER BY title
2016-01-13 08:18:31 [sql] [D] (0.7ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'Hostgroup' AND "taxable_taxonomies"."taxonomy_id" IN (4)
2016-01-13 08:18:31 [sql] [D] Taxonomy Load (0.6ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 3 or taxonomies.ancestry like '3/%' or taxonomies.ancestry = '3') ORDER BY title
2016-01-13 08:18:31 [sql] [D] (0.7ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'Hostgroup' AND "taxable_taxonomies"."taxonomy_id" IN (3)
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 4 or taxonomies.ancestry like '4/%' or taxonomies.ancestry = '4') ORDER BY title
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'Hostgroup' AND "taxable_taxonomies"."taxonomy_id" IN (4)
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 3 or taxonomies.ancestry like '3/%' or taxonomies.ancestry = '3') ORDER BY title
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'Hostgroup' AND "taxable_taxonomies"."taxonomy_id" IN (3)
2016-01-13 08:18:31 [sql] [D] Hostgroup Load (0.8ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = 92 ORDER BY hostgroups.title LIMIT 1
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 4 or taxonomies.ancestry like '4/%' or taxonomies.ancestry = '4') ORDER BY title
2016-01-13 08:18:31 [sql] [D] (0.7ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'ComputeResource' AND "taxable_taxonomies"."taxonomy_id" IN (4)
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 3 or taxonomies.ancestry like '3/%' or taxonomies.ancestry = '3') ORDER BY title
2016-01-13 08:18:31 [sql] [D] (0.7ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'ComputeResource' AND "taxable_taxonomies"."taxonomy_id" IN (3)
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 4 or taxonomies.ancestry like '4/%' or taxonomies.ancestry = '4') ORDER BY title
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'ComputeResource' AND "taxable_taxonomies"."taxonomy_id" IN (4)
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT id FROM "taxonomies" WHERE (taxonomies.id = 3 or taxonomies.ancestry like '3/%' or taxonomies.ancestry = '3') ORDER BY title
2016-01-13 08:18:31 [sql] [D] CACHE (0.0ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'ComputeResource' AND "taxable_taxonomies"."taxonomy_id" IN (3)
2016-01-13 08:18:31 [sql] [D] ComputeResource Load (0.7ms) SELECT "compute_resources".* FROM "compute_resources" WHERE "compute_resources"."id" = 1 ORDER BY compute_resources.name LIMIT 1
2016-01-13 08:18:31 [sql] [D] ComputeAttribute Load (0.7ms) SELECT "compute_attributes".* FROM "compute_attributes" WHERE "compute_attributes"."compute_resource_id" = 1 AND "compute_attributes"."compute_profile_id" IS NULL LIMIT 1
2016-01-13 08:18:31 [sql] [I] Successfully decrypted field for Foreman::Model::Vmware ATX_Devel_ESX
2016-01-13 08:18:34 [sql] [D] (1.1ms) SELECT COUNT(*) FROM "images" WHERE "images"."compute_resource_id" = 1 AND "images"."architecture_id" = 1 AND "images"."operatingsystem_id" = 5
2016-01-13 08:18:34 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "images" WHERE "images"."compute_resource_id" = 1 AND "images"."architecture_id" = 1 AND "images"."operatingsystem_id" = 5
2016-01-13 08:18:34 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "images" WHERE "images"."compute_resource_id" = 1 AND "images"."architecture_id" = 1 AND "images"."operatingsystem_id" = 5
2016-01-13 08:18:34 [sql] [D] Image Load (0.6ms) SELECT "images".* FROM "images" WHERE "images"."compute_resource_id" = 1 AND "images"."architecture_id" = 1 AND "images"."operatingsystem_id" = 5
2016-01-13 08:18:34 [app] [I] Rendered compute_resources_vms/form/vmware/_base.html.erb (2326.7ms)
2016-01-13 08:18:36 [app] [I] Rendered compute_resources_vms/form/vmware/_volume.html.erb (2124.3ms)
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = 1 ORDER BY domains.name LIMIT 1
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = 7 ORDER BY vlanid LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache read: token_duration
2016-01-13 08:18:36 [sql] [D] Using host queue
2016-01-13 08:18:36 [sql] [D] (1.7ms) UPDATE "nics" SET "updated_at" = '2016-01-13 14:18:36.924423', "attrs" = '--- !ruby/hash:ActiveSupport::HashWithIndifferentAccess
| mtu: ''1500''
| network: 10.160.192.0
| netmask: 255.255.255.0
| ', "compute_attributes" = '--- !ruby/hash:ActiveSupport::HashWithIndifferentAccess
| type: VirtualVmxnet3
| network: VLAN_192_Green_Testing
| ' WHERE "nics"."type" IN ('Nic::Managed', 'Nic::BMC', 'Nic::Bond', 'Nic::Bootable') AND "nics"."id" = 270
2016-01-13 08:18:36 [sql] [D] (1.1ms) COMMIT
2016-01-13 08:18:36 [sql] [D] Nic::Base Load (0.8ms) SELECT "nics".* FROM "nics" WHERE "nics"."host_id" = 419 ORDER BY identifier
2016-01-13 08:18:36 [app] [D] Cache read: update_environment_from_facts
2016-01-13 08:18:36 [app] [D] Cache read: default_puppet_environment
2016-01-13 08:18:36 [sql] [D] Environment Load (0.5ms) SELECT "environments".* FROM "environments" WHERE "environments"."name" = '' ORDER BY environments.name LIMIT 1
2016-01-13 08:18:36 [sql] [D] (0.2ms) BEGIN
2016-01-13 08:18:36 [sql] [D] Environment Exists (0.5ms) SELECT 1 AS one FROM "environments" WHERE "environments"."name" = '' LIMIT 1
2016-01-13 08:18:36 [sql] [D] (0.2ms) ROLLBACK
2016-01-13 08:18:36 [sql] [D] Environment Load (0.6ms) SELECT "environments".* FROM "environments" WHERE "environments"."id" = 3 ORDER BY environments.name LIMIT 1
2016-01-13 08:18:36 [sql] [D] Architecture Exists (0.7ms) SELECT 1 AS one FROM "architectures" INNER JOIN "architectures_operatingsystems" ON "architectures"."id" = "architectures_operatingsystems"."architecture_id" WHERE "architectures_operatingsystems"."operatingsystem_id" = 5 AND "architectures"."id" = 1 LIMIT 1
2016-01-13 08:18:36 [sql] [D] (0.2ms) BEGIN
2016-01-13 08:18:36 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] Setting Load (0.6ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [sql] [D] Domain Load (0.6ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = 1 ORDER BY domains.name LIMIT 1
2016-01-13 08:18:36 [sql] [D] (0.3ms) COMMIT
2016-01-13 08:18:36 [app] [D] Cache read: location_fact
2016-01-13 08:18:36 [sql] [D] Location Load (0.6ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."title" = 'austin' ORDER BY title LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache read: organization_fact
2016-01-13 08:18:36 [app] [D] Cache read: default_organization
2016-01-13 08:18:36 [sql] [D] Organization Load (0.7ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."title" = '' ORDER BY title LIMIT 1
2016-01-13 08:18:36 [sql] [D] (0.3ms) BEGIN
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [sql] [D] (0.3ms) COMMIT
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Cache read: root_pass
2016-01-13 08:18:36 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:36 [app] [D] Cache write: root_pass
2016-01-13 08:18:36 [app] [D] Body: {"architecture_id":1,"build":false,"certname":"baeb652e-6627-485f-b248-d0c9e179743a","comment":"Node in ISC DHCP server cluster","compute_profile_id":1,"compute_resource_id":1,"created_at":"2015-10-13T21:05:22Z","disk":"","enabled":true,"environment_id":3,"global_status":0,"grub_pass":"","hostgroup_id":91,"id":419,"image_file":"","image_id":null,"installed_at":"2015-10-13T21:08:54Z","last_compile":"2016-01-13T14:18:18Z","last_report":"2016-01-13T13:48:10Z","location_id":4,"lookup_value_matcher":"fqdn=atxentlapp-d22.advisory.com","managed":true,"medium_id":null,"model_id":1,"name":"atxentlapp-d22.advisory.com","operatingsystem_id":5,"organization_id":3,"otp":null,"owner_id":33,"owner_type":"User","provision_method":"image","ptable_id":null,"puppet_ca_proxy_id":5,"puppet_proxy_id":4,"realm_id":null,"root_pass":null,"updated_at":"2016-01-13T14:18:19Z","use_image":null,"uuid":"50031018-cdc4-3c0e-abf1-cd8b680bf31f"}
2016-01-13 08:18:36 [app] [I] Completed 201 Created in 17800ms (Views: 8.4ms | ActiveRecord: 0.0ms)
2016-01-13 08:18:37 [app] [D] Cache read: https://foreman-dev.advisory.com/node/baeb652e-6627-485f-b248-d0c9e179743a?format=yml
2016-01-13 08:18:37 [app] [I]
|
| Started GET "/node/baeb652e-6627-485f-b248-d0c9e179743a?format=yml" for 10.160.192.239 at 2016-01-13 08:18:37 -0600
2016-01-13 08:18:37 [app] [I] Processing by HostsController#externalNodes as YML
2016-01-13 08:18:37 [app] [I] Parameters: {"name"=>"baeb652e-6627-485f-b248-d0c9e179743a"}
2016-01-13 08:18:37 [app] [D] Cache read: restrict_registered_smart_proxies
2016-01-13 08:18:37 [app] [D] Cache read: require_ssl_smart_proxies
2016-01-13 08:18:37 [app] [D] Cache read: ssl_client_dn_env
2016-01-13 08:18:37 [app] [D] Cache read: ssl_client_verify_env
2016-01-13 08:18:37 [sql] [D] SmartProxy Load (1.1ms) SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet') ORDER BY smart_proxies.name
2016-01-13 08:18:37 [app] [D] Cache read: trusted_puppetmaster_hosts
2016-01-13 08:18:37 [app] [D] Verifying request from ["vtlpuppetserver.advisory.com"] against ["vtlpuppetserver.advisory.com", "vtlforeman.advisory.com", "vtlpuppetserver.advisory.com", "vtlpuppetca.advisory.com", "atxentlfor-d01.advisory.com"]
2016-01-13 08:18:37 [sql] [D] User Load (0.7ms) SELECT "users".* FROM "users" WHERE "users"."lower_login" = 'foreman_api_admin' LIMIT 1
2016-01-13 08:18:37 [app] [D] Setting current user thread-local variable to foreman_api_admin
2016-01-13 08:18:37 [sql] [D] Host::Managed Load (1.1ms) SELECT "hosts".* FROM "hosts" WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."certname" = 'baeb652e-6627-485f-b248-d0c9e179743a' LIMIT 1
2016-01-13 08:18:37 [sql] [D] SmartProxy Load (0.6ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 4 ORDER BY smart_proxies.name LIMIT 1
2016-01-13 08:18:37 [app] [D] Cache read: legacy_puppet_hostname
2016-01-13 08:18:37 [sql] [D] Nic::Base Load (0.8ms) SELECT "nics".* FROM "nics" WHERE "nics"."host_id" = 419 ORDER BY identifier
2016-01-13 08:18:37 [sql] [D] Domain Load (0.6ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = 1 ORDER BY domains.name LIMIT 1
2016-01-13 08:18:37 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = 91 ORDER BY hostgroups.title LIMIT 1
2016-01-13 08:18:37 [sql] [D] Location Load (0.7ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" = 4 ORDER BY title LIMIT 1
2016-01-13 08:18:37 [sql] [D] Organization Load (0.6ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" = 3 ORDER BY title LIMIT 1
2016-01-13 08:18:37 [sql] [D] Operatingsystem Load (0.7ms) SELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."id" = 5 ORDER BY title LIMIT 1
2016-01-13 08:18:37 [sql] [D] Hostgroup Load (0.8ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:37 [app] [D] Cache read: root_pass
2016-01-13 08:18:37 [sql] [D] Setting Load (0.6ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:37 [app] [D] Cache write: root_pass
2016-01-13 08:18:37 [app] [D] Cache read: root_pass
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:37 [app] [D] Cache write: root_pass
2016-01-13 08:18:37 [app] [D] Cache read: root_pass
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-13 08:18:37 [app] [D] Cache write: root_pass
2016-01-13 08:18:37 [sql] [D] SmartProxy Load (0.6ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 5 ORDER BY smart_proxies.name LIMIT 1
2016-01-13 08:18:37 [app] [D] Cache read: legacy_puppet_hostname
2016-01-13 08:18:37 [sql] [D] Environment Load (0.6ms) SELECT "environments".* FROM "environments" WHERE "environments"."id" = 3 ORDER BY environments.name LIMIT 1
2016-01-13 08:18:37 [sql] [D] User Load (0.7ms) SELECT "users".* FROM "users" WHERE "users"."id" = 33 ORDER BY firstname LIMIT 1
2016-01-13 08:18:37 [app] [D] Cache read: ignore_puppet_facts_for_provisioning
2016-01-13 08:18:37 [sql] [D] Subnet Load (0.7ms) SELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = 7 ORDER BY vlanid LIMIT 1
2016-01-13 08:18:37 [sql] [D] CommonParameter Load (1.1ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('CommonParameter') ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] Taxonomy Load (0.6ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."id" IN (NULL) ORDER BY (case when taxonomies.ancestry is null then 0 else 1 end), taxonomies.ancestry
2016-01-13 08:18:37 [sql] [D] OrganizationParameter Load (0.7ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OrganizationParameter') AND "parameters"."reference_id" = 3 ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."id" IN (NULL) ORDER BY (case when taxonomies.ancestry is null then 0 else 1 end), taxonomies.ancestry
2016-01-13 08:18:37 [sql] [D] LocationParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('LocationParameter') AND "parameters"."reference_id" = 4 ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] DomainParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('DomainParameter') AND "parameters"."reference_id" = 1 ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] OsParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OsParameter') AND "parameters"."reference_id" = 5 ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:37 [sql] [D] GroupParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('GroupParameter') AND "parameters"."reference_id" = 50 ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] GroupParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('GroupParameter') AND "parameters"."reference_id" = 91 ORDER BY parameters.name
2016-01-13 08:18:37 [sql] [D] HostParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('HostParameter') AND "parameters"."reference_id" = 419 ORDER BY parameters.name
2016-01-13 08:18:37 [app] [D] Cache read: Enable_Smart_Variables_in_ENC
2016-01-13 08:18:37 [sql] [D] Hostgroup Load (0.8ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50, 91) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:37 [sql] [D] (0.8ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 50 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] (0.8ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 91 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] (0.7ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 419 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] (0.4ms) SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (24)
2016-01-13 08:18:37 [sql] [D] (0.5ms) SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (50, 91)
2016-01-13 08:18:37 [sql] [D] HostClass Load (0.4ms) SELECT "host_classes".* FROM "host_classes" WHERE "host_classes"."host_id" = 419
2016-01-13 08:18:37 [sql] [D] (0.7ms) SELECT DISTINCT puppetclasses.id FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 AND "puppetclasses"."id" IN (521)
2016-01-13 08:18:37 [sql] [D] VariableLookupKey Load (0.7ms) SELECT "lookup_keys".* FROM "lookup_keys" WHERE "lookup_keys"."type" IN ('VariableLookupKey') AND "lookup_keys"."puppetclass_id" IN (521) ORDER BY lookup_keys.key
2016-01-13 08:18:37 [sql] [D] SQL (1.2ms) SELECT "lookup_values"."id" AS t0_r0, "lookup_values"."match" AS t0_r1, "lookup_values"."value" AS t0_r2, "lookup_values"."lookup_key_id" AS t0_r3, "lookup_values"."created_at" AS t0_r4, "lookup_values"."updated_at" AS t0_r5, "lookup_values"."use_puppet_default" AS t0_r6, "lookup_keys"."id" AS t1_r0, "lookup_keys"."key" AS t1_r1, "lookup_keys"."created_at" AS t1_r2, "lookup_keys"."updated_at" AS t1_r3, "lookup_keys"."puppetclass_id" AS t1_r4, "lookup_keys"."default_value" AS t1_r5, "lookup_keys"."path" AS t1_r6, "lookup_keys"."description" AS t1_r7, "lookup_keys"."validator_type" AS t1_r8, "lookup_keys"."validator_rule" AS t1_r9, "lookup_keys"."key_type" AS t1_r10, "lookup_keys"."override" AS t1_r11, "lookup_keys"."required" AS t1_r12, "lookup_keys"."lookup_values_count" AS t1_r13, "lookup_keys"."merge_overrides" AS t1_r14, "lookup_keys"."avoid_duplicates" AS t1_r15, "lookup_keys"."use_puppet_default" AS t1_r16, "lookup_keys"."type" AS t1_r17, "lookup_keys"."merge_default" AS t1_r18 FROM "lookup_values" LEFT OUTER JOIN "lookup_keys" ON "lookup_keys"."id" = "lookup_values"."lookup_key_id" WHERE "lookup_values"."match" IN (NULL) AND "lookup_values"."lookup_key_id" IN (SELECT "lookup_keys"."id" FROM "lookup_keys" WHERE "lookup_keys"."type" IN ('VariableLookupKey') AND "lookup_keys"."puppetclass_id" IN (521) ORDER BY lookup_keys.key) AND "lookup_values"."use_puppet_default" = 'f'
2016-01-13 08:18:37 [app] [D] Cache read: remote_execution_fallback_proxy
2016-01-13 08:18:37 [app] [D] Cache read: remote_execution_global_proxy
2016-01-13 08:18:37 [sql] [D] (0.7ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'SmartProxy' AND "taxable_taxonomies"."taxonomy_id" IN (4)
2016-01-13 08:18:37 [sql] [D] (0.6ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'SmartProxy' AND "taxable_taxonomies"."taxonomy_id" IN (3)
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'SmartProxy' AND "taxable_taxonomies"."taxonomy_id" IN (4)
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT DISTINCT taxable_id FROM "taxable_taxonomies" WHERE "taxable_taxonomies"."taxable_type" = 'SmartProxy' AND "taxable_taxonomies"."taxonomy_id" IN (3)
2016-01-13 08:18:37 [sql] [D] SmartProxy Load (1.5ms) SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" INNER JOIN "target_remote_execution_proxies" ON "smart_proxies"."id" = "target_remote_execution_proxies"."remote_execution_proxy_id" WHERE "target_remote_execution_proxies"."target_id" = 7 AND "target_remote_execution_proxies"."target_type" = 'Subnet' AND "features"."name" IN ('Ssh') ORDER BY smart_proxies.name
2016-01-13 08:18:37 [sql] [D] SmartProxy Load (0.9ms) SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "smart_proxies"."id" IN (5, 6, 3, 4) AND "features"."name" IN ('Ssh') AND (1=1)
2016-01-13 08:18:37 [app] [D] Cache read: remote_execution_ssh_user
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: interpolate_erb_in_parameters
2016-01-13 08:18:37 [app] [D] Cache read: safemode_render
2016-01-13 08:18:37 [app] [D] Cache read: Parametrized_Classes_in_ENC
2016-01-13 08:18:37 [app] [D] Cache read: Enable_Smart_Variables_in_ENC
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50, 91) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 50 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 91 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 419 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (24)
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (50, 91)
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT DISTINCT puppetclasses.id FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 AND "puppetclasses"."id" IN (521)
2016-01-13 08:18:37 [sql] [D] SQL (1.3ms) SELECT "lookup_keys"."id" AS t0_r0, "lookup_keys"."key" AS t0_r1, "lookup_keys"."created_at" AS t0_r2, "lookup_keys"."updated_at" AS t0_r3, "lookup_keys"."puppetclass_id" AS t0_r4, "lookup_keys"."default_value" AS t0_r5, "lookup_keys"."path" AS t0_r6, "lookup_keys"."description" AS t0_r7, "lookup_keys"."validator_type" AS t0_r8, "lookup_keys"."validator_rule" AS t0_r9, "lookup_keys"."key_type" AS t0_r10, "lookup_keys"."override" AS t0_r11, "lookup_keys"."required" AS t0_r12, "lookup_keys"."lookup_values_count" AS t0_r13, "lookup_keys"."merge_overrides" AS t0_r14, "lookup_keys"."avoid_duplicates" AS t0_r15, "lookup_keys"."use_puppet_default" AS t0_r16, "lookup_keys"."type" AS t0_r17, "lookup_keys"."merge_default" AS t0_r18, "environment_classes"."id" AS t1_r0, "environment_classes"."puppetclass_id" AS t1_r1, "environment_classes"."environment_id" AS t1_r2, "environment_classes"."puppetclass_lookup_key_id" AS t1_r3 FROM "lookup_keys" INNER JOIN "environment_classes" ON "environment_classes"."puppetclass_lookup_key_id" = "lookup_keys"."id" WHERE "lookup_keys"."override" = 't' AND "lookup_keys"."type" IN ('PuppetclassLookupKey') AND "environment_classes"."puppetclass_id" IN (521) AND "environment_classes"."environment_id" = 3 ORDER BY lookup_keys.key
2016-01-13 08:18:37 [sql] [D] SQL (1.6ms) SELECT "lookup_values"."id" AS t0_r0, "lookup_values"."match" AS t0_r1, "lookup_values"."value" AS t0_r2, "lookup_values"."lookup_key_id" AS t0_r3, "lookup_values"."created_at" AS t0_r4, "lookup_values"."updated_at" AS t0_r5, "lookup_values"."use_puppet_default" AS t0_r6, "lookup_keys"."id" AS t1_r0, "lookup_keys"."key" AS t1_r1, "lookup_keys"."created_at" AS t1_r2, "lookup_keys"."updated_at" AS t1_r3, "lookup_keys"."puppetclass_id" AS t1_r4, "lookup_keys"."default_value" AS t1_r5, "lookup_keys"."path" AS t1_r6, "lookup_keys"."description" AS t1_r7, "lookup_keys"."validator_type" AS t1_r8, "lookup_keys"."validator_rule" AS t1_r9, "lookup_keys"."key_type" AS t1_r10, "lookup_keys"."override" AS t1_r11, "lookup_keys"."required" AS t1_r12, "lookup_keys"."lookup_values_count" AS t1_r13, "lookup_keys"."merge_overrides" AS t1_r14, "lookup_keys"."avoid_duplicates" AS t1_r15, "lookup_keys"."use_puppet_default" AS t1_r16, "lookup_keys"."type" AS t1_r17, "lookup_keys"."merge_default" AS t1_r18 FROM "lookup_values" LEFT OUTER JOIN "lookup_keys" ON "lookup_keys"."id" = "lookup_values"."lookup_key_id" WHERE "lookup_values"."match" IN (NULL) AND "lookup_values"."lookup_key_id" IN (SELECT "lookup_keys"."id" FROM "lookup_keys" INNER JOIN "environment_classes" ON "environment_classes"."puppetclass_lookup_key_id" = "lookup_keys"."id" WHERE "lookup_keys"."override" = 't' AND "lookup_keys"."type" IN ('PuppetclassLookupKey') AND "environment_classes"."puppetclass_id" IN (521) AND "environment_classes"."environment_id" = 3 ORDER BY lookup_keys.key) AND "lookup_values"."use_puppet_default" = 'f'
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50, 91) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 50 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 91 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" = 419 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (24)
2016-01-13 08:18:37 [sql] [D] CACHE (0.0ms) SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (50, 91)
2016-01-13 08:18:37 [sql] [D] Puppetclass Load (1.1ms) SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 AND "puppetclasses"."id" IN (521) ORDER BY puppetclasses.name
2016-01-13 08:18:37 [app] [D] Cache read: enc_environment
2016-01-13 08:18:37 [app] [I] Rendered text template (0.0ms)
2016-01-13 08:18:37 [app] [I] Completed 200 OK in 318ms (Views: 1.0ms | ActiveRecord: 32.3ms)
2016-01-13 08:18:38 [app] [I] Rendered compute_resources_vms/form/vmware/_volume.html.erb (2231.7ms)
2016-01-13 08:18:38 [app] [I] Rendered compute_resources_vms/form/_volumes.html.erb (4358.2ms)
2016-01-13 08:18:38 [app] [I] Rendered hosts/_compute_detail.html.erb (6686.3ms)
2016-01-13 08:18:38 [app] [I] Rendered hosts/_compute.html.erb (7093.1ms)
2016-01-13 08:18:38 [app] [D] Setting current location thread-local variable to none
2016-01-13 08:18:38 [app] [D] Setting current organization thread-local variable to none
2016-01-13 08:18:38 [app] [I] Completed 200 OK in 7135ms (Views: 7092.4ms | ActiveRecord: 12.6ms)
2016-01-13 08:18:39 [app] [D] Cache read: https://atxentlfor-d01.advisory.com/compute_resources/1/images?search=operatingsystem%3D5+architecture%3D1
2016-01-13 08:18:39 [app] [I]
|
| Started GET "/compute_resources/1/images?search=operatingsystem%3D5%20architecture%3D1" for 10.10.153.104 at 2016-01-13 08:18:39 -0600
2016-01-13 08:18:39 [app] [I] Processing by ImagesController#index as JSON
2016-01-13 08:18:39 [app] [I] Parameters: {"search"=>"operatingsystem=5 architecture=1", "compute_resource_id"=>"1"}
2016-01-13 08:18:39 [sql] [D] User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1 [["id", 33]]
2016-01-13 08:18:39 [app] [D] Setting current user thread-local variable to pisanoc
2016-01-13 08:18:39 [app] [D] Cache read: authorize_login_delegation
2016-01-13 08:18:39 [app] [D] Cache read: authorize_login_delegation
2016-01-13 08:18:39 [sql] [D] (0.6ms) SELECT COUNT(*) FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization')
2016-01-13 08:18:39 [app] [D] Setting current organization thread-local variable to none
2016-01-13 08:18:39 [sql] [D] (0.6ms) SELECT COUNT(*) FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location')
2016-01-13 08:18:39 [app] [D] Setting current location thread-local variable to none
2016-01-13 08:18:39 [sql] [D] AuthSource Load (0.7ms) SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 5 LIMIT 1
2016-01-13 08:18:39 [sql] [D] (0.5ms) SELECT id FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') LIMIT 1
2016-01-13 08:18:39 [sql] [D] (0.5ms) SELECT id FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') LIMIT 1
2016-01-13 08:18:39 [sql] [D] ComputeResource Load (0.6ms) SELECT "compute_resources".* FROM "compute_resources" WHERE "compute_resources"."id" = $1 ORDER BY compute_resources.name LIMIT 1 [["id", "1"]]
2016-01-13 08:18:39 [sql] [D] SQL (1.5ms) SELECT "images"."id" AS t0_r0, "images"."operatingsystem_id" AS t0_r1, "images"."compute_resource_id" AS t0_r2, "images"."architecture_id" AS t0_r3, "images"."uuid" AS t0_r4, "images"."username" AS t0_r5, "images"."name" AS t0_r6, "images"."created_at" AS t0_r7, "images"."updated_at" AS t0_r8, "images"."iam_role" AS t0_r9, "images"."user_data" AS t0_r10, "images"."password" AS t0_r11, "operatingsystems"."id" AS t1_r0, "operatingsystems"."major" AS t1_r1, "operatingsystems"."name" AS t1_r2, "operatingsystems"."minor" AS t1_r3, "operatingsystems"."nameindicator" AS t1_r4, "operatingsystems"."created_at" AS t1_r5, "operatingsystems"."updated_at" AS t1_r6, "operatingsystems"."release_name" AS t1_r7, "operatingsystems"."type" AS t1_r8, "operatingsystems"."description" AS t1_r9, "operatingsystems"."hosts_count" AS t1_r10, "operatingsystems"."hostgroups_count" AS t1_r11, "operatingsystems"."password_hash" AS t1_r12, "operatingsystems"."title" AS t1_r13, "architectures"."id" AS t2_r0, "architectures"."name" AS t2_r1, "architectures"."created_at" AS t2_r2, "architectures"."updated_at" AS t2_r3, "architectures"."hosts_count" AS t2_r4, "architectures"."hostgroups_count" AS t2_r5 FROM "images" LEFT OUTER JOIN "operatingsystems" ON "operatingsystems"."id" = "images"."operatingsystem_id" LEFT OUTER JOIN "architectures" ON "architectures"."id" = "images"."architecture_id" WHERE "images"."compute_resource_id" = 1 AND ((("operatingsystems"."id" = '5') AND ("architectures"."id" = '1')))
2016-01-13 08:18:39 [app] [I] Completed 200 OK in 21ms (Views: 3.1ms | ActiveRecord: 5.5ms)
2016-01-13 08:18:39 [app] [D] Cache read: https://atxentlfor-d01.advisory.com/hosts/interfaces?
2016-01-13 08:18:39 [app] [I]
|
| Started POST "/hosts/interfaces" for 10.10.153.104 at 2016-01-13 08:18:39 -0600
2016-01-13 08:18:39 [app] [I] Processing by HostsController#interfaces as */*
2016-01-13 08:18:39 [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"6CX3PeBY+sfx8Vp091r+p/59sMPYTMUkv/OPSnC9OcU=", "host"=>{"name"=>"foremanbug", "organization_id"=>"3", "location_id"=>"4", "hostgroup_id"=>"92", "compute_resource_id"=>"1", "config_group_ids"=>[""], "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"foremanbug", "domain_id"=>"1", "subnet_id"=>"7", "ip"=>"10.160.192.161", "managed"=>"1", "primary"=>"1", "provision"=>"1", "execution"=>"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", "execution"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "compute_attributes"=>{"cpus"=>"1", "corespersocket"=>"1", "memory_mb"=>"768", "cluster"=>"ATXDEV01", "path"=>"/Datacenters/Austin_Dev/vm", "guest_id"=>"otherGuest", "scsi_controller_type"=>"VirtualLsiLogicController", "hardware_version"=>"Default", "start"=>"1", "volumes_attributes"=>{"new_volumes"=>{"_delete"=>"", "datastore"=>"17_98_LOCAL (2)", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}, "0"=>{"_delete"=>"", "datastore"=>"17_98_LOCAL (2)", "name"=>"Hard disk", "size_gb"=>"10", "thin"=>"true", "eager_zero"=>"false"}}}, "architecture_id"=>"1", "operatingsystem_id"=>"5", "provision_method"=>"build", "build"=>"1", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"33-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "capabilities"=>"build image", "provider"=>"Vmware", "fakepassword"=>"[FILTERED]"}
2016-01-13 08:18:39 [sql] [D] User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1 [["id", 33]]
2016-01-13 08:18:39 [app] [D] Setting current user thread-local variable to pisanoc
2016-01-13 08:18:39 [app] [D] Cache read: authorize_login_delegation
2016-01-13 08:18:39 [app] [D] Cache read: authorize_login_delegation
2016-01-13 08:18:39 [app] [D] Cache read: idle_timeout
2016-01-13 08:18:39 [sql] [D] (0.6ms) SELECT COUNT(*) FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization')
2016-01-13 08:18:39 [app] [D] Setting current organization thread-local variable to none
2016-01-13 08:18:39 [sql] [D] (0.5ms) SELECT COUNT(*) FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location')
2016-01-13 08:18:39 [app] [D] Setting current location thread-local variable to none
2016-01-13 08:18:39 [sql] [D] AuthSource Load (0.6ms) SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 5 LIMIT 1
2016-01-13 08:18:39 [sql] [D] (0.5ms) SELECT id FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') LIMIT 1
2016-01-13 08:18:39 [sql] [D] (0.5ms) SELECT id FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') LIMIT 1
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.6ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."title" = '92' ORDER BY hostgroups.title LIMIT 1
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.6ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = $1 ORDER BY hostgroups.title LIMIT 1 [["id", "92"]]
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) AND (puppet_proxy_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) AND (puppet_ca_proxy_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.9ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) AND (environment_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) AND (compute_profile_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:39 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (50) AND (realm_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-01-13 08:18:39 [sql] [D] User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY firstname LIMIT 1 [["id", 33]]
2016-01-13 08:18:39 [sql] [D] ComputeResource Load (0.7ms) SELECT "compute_resources".* FROM "compute_resources" WHERE "compute_resources"."id" = 1 ORDER BY compute_resources.name LIMIT 1
2016-01-13 08:18:39 [sql] [D] ComputeAttribute Load (0.6ms) SELECT "compute_attributes".* FROM "compute_attributes" WHERE "compute_attributes"."compute_resource_id" = 1 AND "compute_attributes"."compute_profile_id" = 1 LIMIT 1
2016-01-13 08:18:39 [sql] [D] CACHE (0.0ms) SELECT "compute_resources".* FROM "compute_resources" WHERE "compute_resources"."id" = 1 ORDER BY compute_resources.name LIMIT 1
2016-01-13 08:18:39 [sql] [D] ComputeProfile Load (0.6ms) SELECT "compute_profiles".* FROM "compute_profiles" WHERE "compute_profiles"."id" = 1 ORDER BY compute_profiles.name LIMIT 1
2016-01-13 08:18:39 [sql] [D] Domain Load (0.6ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = 1 ORDER BY domains.name LIMIT 1
2016-01-13 08:18:39 [sql] [D] (0.4ms) SELECT COUNT(*) FROM "domains" WHERE (1=1)
2016-01-13 08:18:39 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "domains" WHERE (1=1)
2016-01-13 08:18:39 [sql] [D] Domain Load (0.5ms) SELECT "domains".* FROM "domains" WHERE (1=1) ORDER BY name
2016-01-13 08:18:39 [sql] [D] (0.5ms) SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2016-01-13 08:18:39 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2016-01-13 08:18:39 [sql] [D] Subnet Load (0.7ms) SELECT "subnets".* FROM "subnets" WHERE (1=1) ORDER BY name
2016-01-13 08:18:39 [app] [I] Rendered nic/_base_form.html.erb (17.9ms)
2016-01-13 08:18:39 [app] [I] Rendered nic/_virtual_form.html.erb (1.3ms)
2016-01-13 08:18:39 [sql] [I] Successfully decrypted field for Foreman::Model::Vmware ATX_Devel_ESX
2016-01-13 08:18:40 [app] [I] Rendered compute_resources_vms/form/vmware/_network.html.erb (1010.0ms)
2016-01-13 08:18:40 [app] [I] Rendered nic/_provider_specific_form.html.erb (1011.4ms)
2016-01-13 08:18:40 [app] [I] Rendered nic/manageds/_managed.html.erb (1033.1ms)
2016-01-13 08:18:40 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "domains" WHERE (1=1)
2016-01-13 08:18:40 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "domains" WHERE (1=1)
2016-01-13 08:18:40 [sql] [D] CACHE (0.0ms) SELECT "domains".* FROM "domains" WHERE (1=1) ORDER BY name
2016-01-13 08:18:40 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2016-01-13 08:18:40 [sql] [D] CACHE (0.0ms) SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2016-01-13 08:18:40 [sql] [D] CACHE (0.0ms) SELECT "subnets".* FROM "subnets" WHERE (1=1) ORDER BY name
2016-01-13 08:18:40 [app] [I] Rendered nic/_base_form.html.erb (13.9ms)
2016-01-13 08:18:40 [app] [I] Rendered nic/_virtual_form.html.erb (1.3ms)
2016-01-13 08:18:40 [app] [I] Rendered compute_resources_vms/form/vmware/_network.html.erb (559.0ms)
2016-01-13 08:18:40 [app] [I] Rendered nic/_provider_specific_form.html.erb (560.2ms)
2016-01-13 08:18:40 [app] [I] Rendered nic/manageds/_managed.html.erb (578.0ms)
2016-01-13 08:18:40 [app] [I] Rendered hosts/_interfaces.html.erb (1613.9ms)
2016-01-13 08:18:40 [app] [I] Rendered hosts/_interfaces_tab.html.erb (1614.7ms)
2016-01-13 08:18:40 [app] [I] Completed 200 OK in 1656ms (Views: 1612.8ms | ActiveRecord: 13.1ms)
(3-3/3)