Actions
Refactor #16767
open
Domain appended to hostname twice, causing PTR record conflicts
Status:
New
Priority:
Low
Assignee:
-
Category:
Unattended installations
Target version:
-
Description
After upgrading to 1.12 series, I get stuck in endless install loop for deploying new servers.
I can do host -> new just fine as before, and everything seems normal until reboot. At reboot it does PXE boot again, as it hasn't been cleaned up properly.
I found this in logs:
2016-10-03T10:33:41 [app] [I] Started POST "/api/reports" for 127.0.0.1 at 2016-10-03 10:33:41 +0200
2016-10-03T10:33:41 [app] [I] Processing by Api::V2::ReportsController#create as JSON
2016-10-03T10:33:41 [app] [I] Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
2016-10-03T10:33:41 [app] [I] processing report for fqdn.domain.com
2016-10-03T10:33:44 [app] [I] Imported report for fqdn.domain.com in 3.18 seconds
2016-10-03T10:33:46 [app] [I] Rendered api/v2/reports/create.json.rabl (1298.7ms)
2016-10-03T10:33:46 [app] [I] Completed 201 Created in 4528ms (Views: 1115.8ms | ActiveRecord: 1465.5ms)
2016-10-03T10:33:46 [app] [I] Started GET "/unattended/built?token=6a578cf0-b2a6-45c3-8220-39ce8940ea1c" for 10.0.0.36 at 2016-10-03 10:33:46 +0200
2016-10-03T10:33:46 [app] [I] Processing by UnattendedController#built as TEXT
2016-10-03T10:33:46 [app] [I] Parameters: {"token"=>"6a578cf0-b2a6-45c3-8220-39ce8940ea1c"}
2016-10-03T10:33:46 [app] [I] unattended: fqdn.domain.com is Built!
2016-10-03T10:34:06 [app] [I] Completed 409 Conflict in 19459ms (ActiveRecord: 20.3ms)
There's no additional information about what this "Conflict" might be. But I've consistently reproduced this issue on the creation of 8 different hosts
I believe this might be related to: Bug #16701
Updated by Jon Skarpeteig about 8 years ago
(Unable to properly install any hosts at the moment)
Updated by Dominic Cleal about 8 years ago
- Category set to Unattended installations
Cancelling the build through the UI should log the full error, as you did in #16701.
Updated by Jon Skarpeteig about 8 years ago
When attempting to manually cancel build, I find the following in logs:
2016-10-03T11:03:32 [app] [I] Started GET "/hosts/fqdn.sub.domain.com/cancelBuild" for 10.0.0.142 at 2016-10-03 11:03:32 +0200
2016-10-03T11:03:32 [app] [I] Processing by HostsController#cancelBuild as HTML
2016-10-03T11:03:32 [app] [I] Parameters: {"id"=>"fqdn.sub.domain.com"}
2016-10-03T11:03:50 [app] [I] Failed to save: Conflict DNS PTR Records 10.0.0.36/fqdn.sub.domain.com.sub.domain.com already exists
(Notice how sub.domain.com is appended twice)
I might add that I have both domain.com and sub.domain.com in my domains list
Updated by Dominic Cleal about 8 years ago
- Subject changed from Endless install loop to Domain appended to hostname twice, causing PTR record conflicts
If the host wasn't created with a second domain appended, a process must be changing it. Enabling debug SQL logs may show which operation, e.g. fact imports (which may indicate an incorrect configuration on the host itself): https://theforeman.org/manuals/1.12/index.html#7.2Debugging
Updated by Jon Skarpeteig about 8 years ago
Why does it do such validation checks at all, at that point? It was already verified during host creation
Updated by Dominic Cleal about 8 years ago
- Status changed from New to Need more information
That isn't a validation of the host, it's probably a failure to create a new PTR record with a different name to the existing record.
Updated by Jon Skarpeteig about 8 years ago
Why create a new PTR record on unattended/built or cancelBuild?!
Updated by Jon Skarpeteig about 8 years ago
Not sure if this helps, but here goes.
Creation time:
2016-10-03T11:35:25 [app] [I] Create DHCP reservation for hostname2.sub.domain.com-00:50:56:bc:b9:21/10.0.0.10
2016-10-03T11:35:25 [app] [D] DHCP reservation on net 10.0.0.0 with attrs: {:hostname=>"hostname2.sub.domain.com", :mac=>"00:50:56:bc:xx:21", :ip=>"10.0.0.10", :network=>"10.0.0.0", :nextServer=>"10.47.24.10", :filename=>"pxelinux.0"}
2016-10-03T11:35:34 [app] [I] Add DNS A record for hostname2.sub.domain.com/10.0.0.10
2016-10-03T11:35:35 [app] [I] Add DNS PTR record for 10.0.0.10/hostname2.sub.domain.com
2016-10-03T11:35:40 [sql] [I] Add the TFTP configuration for hostname2.sub.domain.com
2016-10-03T11:35:40 [sql] [I] Fetching required TFTP boot files for hostname2.sub.domain.com
2016-10-03T11:35:41 [sql] [I] Add realm entry for new host hostname2.sub.domain.com
2016-10-03T11:35:51 [sql] [I] Powering up Compute instance for hostname2.sub.domain.com
2016-10-03T11:35:53 [sql] [D] SQL (3.3ms) INSERT INTO "hosts" ("type", "hostgroup_id", "compute_resource_id", "managed", "architecture_id", "operatingsystem_id", "provision_method", "build", "medium_id", "ptable_id", "disk", "root_pass", "owner_id", "owner_type", "comment", "puppet_proxy_id", "puppet_ca_proxy_id", "environment_id", "compute_profile_id", "realm_id", "name", "grub_pass", "lookup_value_matcher", "uuid", "otp", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $27) RETURNING "id" [["type", "Host::Managed"], ["hostgroup_id", 8], ["compute_resource_id", 1], ["managed", "t"], ["architecture_id", 1], ["operatingsystem_id", 1], ["provision_method", "build"], ["build", "t"], ["medium_id", 6], ["ptable_id", 63], ["disk", ""], ["root_pass", "x"], ["owner_id", 2], ["owner_type", "User"], ["comment", ""], ["puppet_proxy_id", 1], ["puppet_ca_proxy_id", 1], ["environment_id", 1], ["compute_profile_id", 6], ["realm_id", 1], ["name", "hostname2.sub.domain.com"], ["grub_pass", "x"], ["lookup_value_matcher", "fqdn=hostname2.sub.domain.com"], ["uuid", "x"], ["otp", "x"], ["created_at", "2016-10-03 09:35:53.483457"], ["updated_at", "2016-10-03 09:35:53.483457"]]
2016-10-03T11:35:53 [sql] [D] SQL (1.4ms) INSERT INTO "nics" ("type", "identifier", "name", "domain_id", "subnet_id", "ip", "primary", "provision", "compute_attributes", "mac", "host_id", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13) RETURNING "id" [["type", "Nic::Managed"], ["identifier", ""], ["name", "hostname2.sub.domain.com"], ["domain_id", 4], ["subnet_id", 4], ["ip", "10.0.0.10"], ["primary", "t"], ["provision", "t"], ["compute_attributes", "--- !ruby/hash-with-ivars:ActionController::Parameters\nelements:\n type: VirtualVmxnet3\n network: 10.0.0-Labserver-525\nivars:\n :@permitted: false\n"], ["mac", "00:50:56:bc:xx:21"], ["host_id", 678], ["created_at", "2016-10-03 09:35:53.507303"], ["updated_at", "2016-10-03 09:35:53.507303"]]
After built:
2016-10-03T11:58:27 [app] [I] Started GET "/unattended/built?token=aebfe139-57f1-4781-90ee-d9828dbc9213" for 10.0.0.10 at 2016-10-03 11:58:27 +0200
2016-10-03T11:58:27 [app] [I] Processing by UnattendedController#built as TEXT
2016-10-03T11:58:27 [app] [I] Parameters: {"token"=>"aebfe139-57f1-4781-90ee-d9828dbc9213"}
2016-10-03T11:58:27 [sql] [D] Host::Managed Load (2.5ms) SELECT hosts.* FROM "hosts" INNER JOIN "tokens" ON "tokens"."host_id" = "hosts"."id" WHERE "hosts"."type" IN ('Host::Managed') AND "tokens"."value" = $1 AND (expires >= '2016-10-03 09:58:27') ORDER BY "hosts"."id" ASC LIMIT 1 [["value", "aebfe139-57f1-4781-90ee-d9828dbc9213"]]
2016-10-03T11:58:27 [sql] [D] Operatingsystem Load (0.3ms) SELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."id" = $1 ORDER BY "operatingsystems"."title" ASC LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [app] [D] Found hostname2.sub.domain.com
2016-10-03T11:58:27 [sql] [D] User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."lower_login" = $1 LIMIT 1 [["lower_login", "foreman_api_admin"]]
2016-10-03T11:58:27 [app] [D] Setting current user thread-local variable to foreman_api_admin
2016-10-03T11:58:27 [app] [I] unattended: hostname2.sub.domain.com is Built!
2016-10-03T11:58:27 [sql] [D] (0.2ms) BEGIN
2016-10-03T11:58:27 [sql] [D] Nic::Base Load (0.4ms) SELECT "nics".* FROM "nics" WHERE "nics"."host_id" = $1 ORDER BY "nics"."identifier" ASC [["host_id", 678]]
2016-10-03T11:58:27 [sql] [D] HostStatus::Status Load (0.5ms) SELECT "host_status".* FROM "host_status" WHERE "host_status"."host_id" = $1 [["host_id", 678]]
2016-10-03T11:58:27 [sql] [D] Hostgroup Load (0.9ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = $1 ORDER BY hostgroups.title LIMIT 1 [["id", 8]]
2016-10-03T11:58:27 [sql] [D] ComputeResource Load (0.4ms) SELECT "compute_resources".* FROM "compute_resources" WHERE "compute_resources"."id" = $1 ORDER BY compute_resources.name LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [sql] [D] Hostgroup Load (0.8ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (11, 5) AND (operatingsystem_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:58:27 [sql] [D] Hostgroup Load (0.6ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (11, 5) AND (architecture_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:58:27 [sql] [D] Hostgroup Load (0.5ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (11, 5) AND (medium_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:58:27 [sql] [D] Hostgroup Load (0.5ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (11, 5) AND (ptable_id is not NULL) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:58:27 [sql] [D] Subnet Load (0.4ms) SELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = $1 ORDER BY vlanid LIMIT 1 [["id", 4]]
2016-10-03T11:58:27 [sql] [D] Host::Base Exists (0.6ms) SELECT 1 AS one FROM "hosts" WHERE ("hosts"."name" = 'hostname2.sub.domain.com' AND "hosts"."id" != 678) LIMIT 1
2016-10-03T11:58:27 [sql] [D] HostParameter Load (0.3ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('HostParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 678]]
2016-10-03T11:58:27 [sql] [D] SmartProxy Load (0.3ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = $1 ORDER BY smart_proxies.name LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [sql] [D] Feature Load (0.5ms) SELECT "features".* FROM "features" INNER JOIN "features_smart_proxies" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features_smart_proxies"."smart_proxy_id" = $1 [["smart_proxy_id", 1]]
2016-10-03T11:58:27 [sql] [D] CACHE (0.0ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = $1 ORDER BY smart_proxies.name LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [sql] [D] CACHE (0.0ms) SELECT "features".* FROM "features" INNER JOIN "features_smart_proxies" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features_smart_proxies"."smart_proxy_id" = $1 [["smart_proxy_id", 1]]
2016-10-03T11:58:27 [sql] [D] Domain Load (0.3ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = $1 ORDER BY domains.name LIMIT 1 [["id", 4]]
2016-10-03T11:58:27 [sql] [D] Token Load (0.4ms) SELECT "tokens".* FROM "tokens" WHERE "tokens"."host_id" = $1 LIMIT 1 [["host_id", 678]]
2016-10-03T11:58:27 [sql] [D] SQL (0.3ms) DELETE FROM "tokens" WHERE "tokens"."id" = $1 [["id", 518]]
2016-10-03T11:58:27 [sql] [D] Queueing Realm
2016-10-03T11:58:27 [sql] [D] Realm Load (0.3ms) SELECT "realms".* FROM "realms" WHERE "realms"."id" = $1 ORDER BY realms.name LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [sql] [D] Ptable Load (0.7ms) SELECT "templates".* FROM "templates" WHERE "templates"."type" IN ('Ptable') AND "templates"."id" = $1 ORDER BY templates.name LIMIT 1 [["id", 63]]
2016-10-03T11:58:27 [sql] [D] Ptable Exists (0.7ms) SELECT 1 AS one FROM "templates" INNER JOIN "operatingsystems_ptables" ON "templates"."id" = "operatingsystems_ptables"."ptable_id" WHERE "templates"."type" IN ('Ptable') AND "operatingsystems_ptables"."operatingsystem_id" = $1 AND "templates"."id" = $2 LIMIT 1 [["operatingsystem_id", 1], ["id", 63]]
2016-10-03T11:58:27 [sql] [D] Medium Load (0.4ms) SELECT "media".* FROM "media" WHERE "media"."id" = $1 ORDER BY media.name LIMIT 1 [["id", 6]]
2016-10-03T11:58:27 [sql] [D] Medium Exists (0.4ms) SELECT 1 AS one FROM "media" INNER JOIN "media_operatingsystems" ON "media"."id" = "media_operatingsystems"."medium_id" WHERE "media_operatingsystems"."operatingsystem_id" = $1 AND "media"."id" = $2 LIMIT 1 [["operatingsystem_id", 1], ["id", 6]]
2016-10-03T11:58:27 [sql] [D] Architecture Load (0.3ms) SELECT "architectures".* FROM "architectures" WHERE "architectures"."id" = $1 LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [sql] [D] Architecture Exists (0.4ms) SELECT 1 AS one FROM "architectures" INNER JOIN "architectures_operatingsystems" ON "architectures"."id" = "architectures_operatingsystems"."architecture_id" WHERE "architectures_operatingsystems"."operatingsystem_id" = $1 AND "architectures"."id" = $2 LIMIT 1 [["operatingsystem_id", 1], ["id", 1]]
2016-10-03T11:58:27 [sql] [D] Environment Load (0.2ms) SELECT "environments".* FROM "environments" WHERE "environments"."id" = $1 ORDER BY environments.name LIMIT 1 [["id", 1]]
2016-10-03T11:58:27 [sql] [D] Puppetclass Load (0.8ms) SELECT DISTINCT puppetclasses.id,puppetclasses.name FROM "puppetclasses" INNER JOIN "host_classes" ON "puppetclasses"."id" = "host_classes"."puppetclass_id" WHERE "host_classes"."host_id" = $1 ORDER BY puppetclasses.name [["host_id", 678]]
2016-10-03T11:58:27 [sql] [D] User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY firstname LIMIT 1 [["id", 2]]
2016-10-03T11:58:27 [sql] [D] String does not start with the prefix 'encrypted-', so Nic::Managed hostname2.sub.domain.com was not decrypted
2016-10-03T11:58:27 [sql] [D] Domain Load (0.5ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = $1 ORDER BY domains.name LIMIT 1 [["id", 4]]
2016-10-03T11:58:27 [sql] [D] Nic::Base Load (0.6ms) SELECT "nics".* FROM "nics" WHERE "nics"."ip" = $1 [["ip", "10.0.0.10"]]
2016-10-03T11:58:27 [sql] [D] Nic::Base Load (0.7ms) SELECT "nics".* FROM "nics" WHERE "nics"."domain_id" = $1 AND "nics"."name" = $2 [["domain_id", 4], ["name", "hostname2.sub.domain.com"]]
--
2016-10-03T11:59:22 [sql] [D] Realm Load (0.3ms) SELECT "realms".* FROM "realms" WHERE "realms"."id" = $1 ORDER BY realms.name LIMIT 1 [["id", 1]]
2016-10-03T11:59:22 [sql] [D] Hostgroup Load (0.4ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = $1 ORDER BY hostgroups.title LIMIT 1 [["id", 4]]
2016-10-03T11:59:22 [sql] [D] Operatingsystem Load (0.3ms) SELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."id" = $1 ORDER BY "operatingsystems"."title" ASC LIMIT 1 [["id", 1]]
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = $1 ORDER BY smart_proxies.name LIMIT 1 [["id", 1]]
2016-10-03T11:59:22 [sql] [D] Environment Load (0.3ms) SELECT "environments".* FROM "environments" WHERE "environments"."id" = $1 ORDER BY environments.name LIMIT 1 [["id", 1]]
2016-10-03T11:59:22 [sql] [D] User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY firstname LIMIT 1 [["id", 2]]
2016-10-03T11:59:22 [sql] [D] Subnet Load (0.6ms) SELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = $1 ORDER BY vlanid LIMIT 1 [["id", 3]]
2016-10-03T11:59:22 [sql] [D] CommonParameter Load (0.6ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('CommonParameter') ORDER BY parameters.name
2016-10-03T11:59:22 [sql] [D] DomainParameter Load (0.3ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('DomainParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 4]]
2016-10-03T11:59:22 [sql] [D] SubnetParameter Load (0.3ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('SubnetParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 3]]
2016-10-03T11:59:22 [sql] [D] OsParameter Load (0.2ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OsParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 1]]
2016-10-03T11:59:22 [sql] [D] Hostgroup Load (0.7ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:59:22 [sql] [D] GroupParameter Load (0.3ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('GroupParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 3]]
2016-10-03T11:59:22 [sql] [D] GroupParameter Load (0.3ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('GroupParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 4]]
2016-10-03T11:59:22 [sql] [D] HostParameter Load (0.3ms) SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('HostParameter') AND "parameters"."reference_id" = $1 ORDER BY parameters.name [["reference_id", 142]]
2016-10-03T11:59:22 [sql] [D] Hostgroup Load (0.8ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3, 4) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:59:22 [sql] [D] (0.3ms) 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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 3], ["host_type", "Hostgroup"]]
2016-10-03T11:59:22 [sql] [D] (0.3ms) 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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 4], ["host_type", "Hostgroup"]]
2016-10-03T11:59:22 [sql] [D] (0.2ms) 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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 142], ["host_type", "Host::Base"]]
2016-10-03T11:59:22 [sql] [D] (0.3ms) SELECT "config_group_classes"."puppetclass_id" FROM "config_group_classes" WHERE 1=0
2016-10-03T11:59:22 [sql] [D] (0.6ms) SELECT "hostgroup_classes"."puppetclass_id" FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3, 4)
2016-10-03T11:59:22 [sql] [D] HostClass Load (0.2ms) SELECT "host_classes".* FROM "host_classes" WHERE "host_classes"."host_id" = $1 [["host_id", 142]]
2016-10-03T11:59:22 [sql] [D] (2.7ms) SELECT DISTINCT puppetclasses.id FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = $1 AND "puppetclasses"."id" IN (239, 993, 581, 1080, 1071, 317, 787, 809, 902, 264, 960, 1263, 650, 983) [["environment_id", 1]]
2016-10-03T11:59:22 [sql] [D] VariableLookupKey Load (0.6ms) SELECT "lookup_keys".* FROM "lookup_keys" WHERE "lookup_keys"."type" IN ('VariableLookupKey') AND "lookup_keys"."puppetclass_id" IN (960, 787, 809, 993, 1071, 264, 239, 902, 983, 317, 1263, 581, 650, 1080) ORDER BY lookup_keys.key
2016-10-03T11:59:22 [sql] [D] LookupValue Load (0.6ms) SELECT "lookup_values".* FROM "lookup_values" WHERE 1=0 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 (960, 787, 809, 993, 1071, 264, 239, 902, 983, 317, 1263, 581, 650, 1080) ORDER BY lookup_keys.key)
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3, 4) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:59:22 [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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 3], ["host_type", "Hostgroup"]]
2016-10-03T11:59:22 [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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 4], ["host_type", "Hostgroup"]]
2016-10-03T11:59:22 [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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 142], ["host_type", "Host::Base"]]
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "config_group_classes"."puppetclass_id" FROM "config_group_classes" WHERE 1=0
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "hostgroup_classes"."puppetclass_id" FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3, 4)
2016-10-03T11:59:22 [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" = $1 AND "puppetclasses"."id" IN (239, 993, 581, 1080, 1071, 317, 787, 809, 902, 264, 960, 1263, 650, 983) [["environment_id", 1]]
2016-10-03T11:59:22 [sql] [D] SQL (3.8ms) 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, "lookup_keys"."hidden_value" AS t0_r19, "environment_classes"."puppetclass_id" AS t1_r0, "environment_classes"."environment_id" AS t1_r1, "environment_classes"."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"."type" IN ('PuppetclassLookupKey') AND "lookup_keys"."override" = $1 AND "environment_classes"."environment_id" = $2 AND "environment_classes"."puppetclass_id" IN (960, 787, 809, 993, 1071, 264, 239, 902, 983, 317, 1263, 581, 650, 1080) ORDER BY lookup_keys.key [["override", "t"], ["environment_id", 1]]
2016-10-03T11:59:22 [sql] [D] LookupValue Load (5.8ms) SELECT "lookup_values".* FROM "lookup_values" WHERE "lookup_values"."match" IN ('fqdn=adam.sub.domain.com', 'hostgroup=Engineering Infrastructure/Management', 'hostgroup=Engineering Infrastructure', 'os=Ubuntu 14.04', 'domain=sub.domain.com') 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"."type" IN ('PuppetclassLookupKey') AND "lookup_keys"."override" = $1 AND "environment_classes"."environment_id" = $2 AND "environment_classes"."puppetclass_id" IN (960, 787, 809, 993, 1071, 264, 239, 902, 983, 317, 1263, 581, 650, 1080) ORDER BY lookup_keys.key) [["override", "t"], ["environment_id", 1]]
2016-10-03T11:59:22 [sql] [D] LookupKey Load (0.8ms) SELECT "lookup_keys".* FROM "lookup_keys" WHERE "lookup_keys"."id" IN (2986, 2597, 2987, 2988, 2596) ORDER BY lookup_keys.key
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3, 4) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
2016-10-03T11:59:22 [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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 3], ["host_type", "Hostgroup"]]
2016-10-03T11:59:22 [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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 4], ["host_type", "Hostgroup"]]
2016-10-03T11:59:22 [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" = $1 AND "host_config_groups"."host_type" = $2 ORDER BY config_groups.name [["host_id", 142], ["host_type", "Host::Base"]]
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "config_group_classes"."puppetclass_id" FROM "config_group_classes" WHERE 1=0
2016-10-03T11:59:22 [sql] [D] CACHE (0.0ms) SELECT "hostgroup_classes"."puppetclass_id" FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3, 4)
2016-10-03T11:59:22 [sql] [D] Puppetclass Load (2.5ms) SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = $1 AND "puppetclasses"."id" IN (239, 993, 581, 1080, 1071, 317, 787, 809, 902, 264, 960, 1263, 650, 983) ORDER BY puppetclasses.name [["environment_id", 1]]
2016-10-03T11:59:22 [app] [I] Rendered text template (0.0ms)
2016-10-03T11:59:22 [app] [I] Completed 200 OK in 434ms (Views: 0.8ms | ActiveRecord: 28.8ms)
2016-10-03T11:59:22 [sql] [D] (0.3ms) BEGIN
2016-10-03T11:59:22 [sql] [D] SQL (0.5ms) INSERT INTO "sessions" ("session_id", "data", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["session_id", "32ae6ec10598658f44fe2d4450752a08"], ["data", "BAh7BkkiC2xvY2FsZQY6BkVGSSIHZW4GOwBG\n"], ["created_at", "2016-10-03 09:59:22.492073"], ["updated_at", "2016-10-03 09:59:22.492073"]]
2016-10-03T11:59:22 [sql] [D] (2.1ms) COMMIT
2016-10-03T11:59:24 [sql] [D] CACHE (0.1ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = $1 ORDER BY domains.name LIMIT 1 [["id", 4]]
2016-10-03T11:59:24 [sql] [D] Subnet Load (0.5ms) SELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = $1 ORDER BY vlanid LIMIT 1 [["id", 14]]
2016-10-03T11:59:24 [sql] [D] CACHE (0.1ms) SELECT "domains".* FROM "domains" WHERE "domains"."id" = $1 ORDER BY domains.name LIMIT 1 [["id", 4]]
2016-10-03T11:59:24 [sql] [D] CACHE (0.0ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = $1 ORDER BY smart_proxies.name LIMIT 1 [["id", 5]]
2016-10-03T11:59:24 [sql] [D] Subnet Load (0.5ms) SELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = $1 ORDER BY vlanid LIMIT 1 [["id", 4]]
2016-10-03T11:59:24 [sql] [D] Setting Load (3.0ms) SELECT "settings".* FROM "settings" WHERE "settings"."name" = $1 ORDER BY "settings"."name" ASC LIMIT 1 [["name", "query_local_nameservers"]]
2016-10-03T11:59:24 [sql] [D] SmartProxy Load (0.6ms) SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = $1 ORDER BY smart_proxies.name LIMIT 1 [["id", 5]]
2016-10-03T11:59:24 [sql] [W] DNS PTR Records 10.0.0.31/hostname1.sub.domain.com.sub.domain.com already exists
2016-10-03T11:59:24 [sql] [W] DNS PTR Records 10.0.0.10/hostname2.sub.domain.com.sub.domain.com already exists
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.8ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "template_combinations" ON "template_combinations"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 30 AND "template_kinds"."name" = 'PXELinux' AND "template_combinations"."hostgroup_id" = 10 AND "template_combinations"."environment_id" = 1 ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (2.2ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "template_combinations" ON "template_combinations"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 1 AND "template_kinds"."name" = 'PXELinux' AND "template_combinations"."hostgroup_id" = 8 AND "template_combinations"."environment_id" = 1 ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.4ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "template_combinations" ON "template_combinations"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 30 AND "template_kinds"."name" = 'PXELinux' AND "template_combinations"."hostgroup_id" = 10 AND "template_combinations"."environment_id" IS NULL ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.3ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "template_combinations" ON "template_combinations"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 30 AND "template_kinds"."name" = 'PXELinux' AND "template_combinations"."hostgroup_id" IS NULL AND "template_combinations"."environment_id" = 1 ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.9ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "template_combinations" ON "template_combinations"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 1 AND "template_kinds"."name" = 'PXELinux' AND "template_combinations"."hostgroup_id" = 8 AND "template_combinations"."environment_id" IS NULL ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.4ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "os_default_templates" ON "os_default_templates"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 30 AND "template_kinds"."name" = 'PXELinux' AND "os_default_templates"."operatingsystem_id" = 30 ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] (0.7ms) ROLLBACK
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.2ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "template_combinations" ON "template_combinations"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 1 AND "template_kinds"."name" = 'PXELinux' AND "template_combinations"."hostgroup_id" IS NULL AND "template_combinations"."environment_id" = 1 ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [W] Failed to set Build on hostname1.sub.domain.com: ["Conflict DNS PTR Records 10.0.0.31/hostname1.sub.domain.com.sub.domain.com already exists"]
2016-10-03T11:59:24 [app] [I] Completed 409 Conflict in 58280ms (ActiveRecord: 25.8ms)
2016-10-03T11:59:24 [sql] [D] ProvisioningTemplate Load (1.2ms) SELECT "templates".* FROM "templates" INNER JOIN "operatingsystems_provisioning_templates" ON "operatingsystems_provisioning_templates"."provisioning_template_id" = "templates"."id" INNER JOIN "operatingsystems" ON "operatingsystems"."id" = "operatingsystems_provisioning_templates"."operatingsystem_id" INNER JOIN "template_kinds" ON "template_kinds"."id" = "templates"."template_kind_id" INNER JOIN "os_default_templates" ON "os_default_templates"."provisioning_template_id" = "templates"."id" WHERE "templates"."type" IN ('ProvisioningTemplate') AND "operatingsystems"."id" = 1 AND "template_kinds"."name" = 'PXELinux' AND "os_default_templates"."operatingsystem_id" = 1 ORDER BY templates.name LIMIT 1
2016-10-03T11:59:24 [sql] [D] (0.3ms) ROLLBACK
2016-10-03T11:59:24 [sql] [W] Failed to set Build on hostname2.sub.domain.com: ["Conflict DNS PTR Records 10.0.0.10/hostname2.sub.domain.com.sub.domain.com already exists"]
Updated by Jon Skarpeteig about 8 years ago
Found something weird. When provisioning a new server on domain.com, it gets appended sub.domain.com in the built logic somewhere! (sub.domain.com is not specified anywhere on this host during the new host UI operations)
2016-10-03T13:06:18 [app] [D] Found deleteme4321.domain.com
2016-10-03T13:06:18 [app] [I] unattended: deleteme4321.domain.com is Built!
2016-10-03T13:06:18 [sql] [D] Host::Base Exists (0.4ms) SELECT 1 AS one FROM "hosts" WHERE ("hosts"."name" = 'deleteme4321.domain.com' AND "hosts"."id" != 677) LIMIT 1
2016-10-03T13:06:18 [sql] [D] String does not start with the prefix 'encrypted-', so Nic::Managed deleteme4321.domain.com was not decrypted
2016-10-03T13:06:18 [sql] [D] Nic::Base Load (0.5ms) SELECT "nics".* FROM "nics" WHERE "nics"."domain_id" = $1 AND "nics"."name" = $2 [["domain_id", 1], ["name", "deleteme4321.domain.com"]]
2016-10-03T13:06:38 [sql] [W] DNS PTR Records 10.0.0.8/deleteme4321.domain.com.sub.domain.com already exists
2016-10-03T13:06:38 [sql] [W] Failed to set Build on deleteme4321.domain.com: ["Conflict DNS PTR Records 10.0.0.8/deleteme4321.domain.com.sub.domain.com already exists"]
Updated by Jon Skarpeteig about 8 years ago
I finally found the culprit for this issue.
isc-dhcpd-4.3.3 config was set to
update-static-leases on; option domain-name "sub.domain.com";
Apparently, it's adding the ddns-domain to the hostname as seen in the lease file
host hostname.sub.domain.com {
dynamic;
hardware ethernet 00:50:56:bb:xx:05;
fixed-address 10.0.0.106;
supersede server.filename = "pxelinux.0";
supersede server.next-server = 0a:xx:xx:0a;
supersede host-name = "hostname.sub.domain.com";
}
What I still fail to understand though, is why Foreman would crash on this? Why is DNS entry relevant when host is reporting "built"?
Also; Any conflict should really be logged more clearly, as it's not possible to tell from logs currently what went wrong other than "conflict" on the "/built" step
Updated by Eli Landon about 8 years ago
I'm experiencing the same issue in release 1.13.1.
Setup:
ISC-DHCP-Server with Dynamic DNS enabled with the domain set to:
ddns-domainname "ten.den.company.net.";
When the proxy adds the DHCP reservation with the field 'supersede host-name = "test01.ten.den.company.net";' DHCP sends an update to the DNS server when a lease is requested with the hostname test01.ten.den.company.net.ten.den.company.net. DHCP appends the host-name (FQDN) which includes the domain with the DDNS domain resulting in the domain being appended twice. Which is causing the build to fail and is inserting the incorrect PTR and A records into the DNS database.
Is there a way to specify the short name in the DHCP reservation supersede host-name field?
Updated by alvin starr almost 8 years ago
It looks like removing the global
option domain-name "yourdomain.com";
fixes the problem.
I am not sure if this is a ISC issue or if Foreman should just make the address addition request with just the hostname.
Possibly there should be an option to skip attaching the domain to DHCP host add requests.
Updated by Anonymous over 7 years ago
- Tracker changed from Bug to Refactor
- Status changed from Need more information to New
- Priority changed from High to Low
some validation could be made more robust, or docs/error messages extended. But I guess having a DHCP hand out a fixed domain is just not the right configuration for a Foreman-managed setup with the current architecture.
Actions