Project

General

Profile

Bug #31518

foreman_hooks: create hook fails to render host with "You cannot call create unless the parent is saved"

Added by Koen Torfs 3 months ago. Updated about 2 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Host registration
Target version:
Difficulty:
Triaged:
No
Bugzilla link:
Fixed in Releases:
Found in Releases:

Description

The issue only seems present during the create hook, other hooks (update, destroy, before_update, ...) have a correct json representation of the hook object.
I upgraded from 2.2.1 (which works fine) directly to 2.3.1 (have not tested this behavior on 2.3.0).

limited / incorrect json of the host object provided during create hook:

{
  "id": null,
  "name": "testhost.lan",
  "last_compile": null,
  "last_report": null,
  "updated_at": null,
  "created_at": null,
  "root_pass": "< removed >",
  "architecture_id": 1,
  "operatingsystem_id": 7,
  "environment_id": 32,
  "ptable_id": 143,
  "medium_id": 18,
  "build": true,
  "comment": "testhost install",
  "disk": "",
  "installed_at": null,
  "model_id": null,
  "hostgroup_id": 3,
  "owner_id": 7,
  "owner_type": "User",
  "enabled": true,
  "puppet_ca_proxy_id": 3,
  "managed": true,
  "use_image": null,
  "image_file": "",
  "uuid": null,
  "compute_resource_id": 7,
  "puppet_proxy_id": 2,
  "certname": "testhost.lan",
  "image_id": null,
  "organization_id": 1,
  "location_id": 2,
  "otp": null,
  "realm_id": null,
  "compute_profile_id": 4,
  "provision_method": "build",
  "grub_pass": "< removed >",
  "global_status": 0,
  "lookup_value_matcher": "fqdn=testhost.lan",
  "pxe_loader": "PXELinux BIOS",
  "initiated_at": null,
  "build_errors": null
}

full / correct json of the host object provided during other hooks:

{
  "host": {
    "ip": "< removed >",
    "ip6": "",
    "environment_id": 32,
    "environment_name": "< removed >",
    "last_report": "2020-12-16 09:15:48 +0100",
    "mac": "< removed >",
    "realm_id": null,
    "realm_name": null,
    "sp_mac": null,
    "sp_ip": null,
    "sp_name": null,
    "domain_id": 1,
    "domain_name": "< removed >",
    "architecture_id": 1,
    "architecture_name": "x86_64",
    "operatingsystem_id": 7,
    "operatingsystem_name": "RHEL 7.8",
    "subnet_id": 1,
    "subnet_name": "< removed >",
    "subnet6_id": null,
    "subnet6_name": null,
    "sp_subnet_id": null,
    "ptable_id": 143,
    "ptable_name": "< removed >",
    "medium_id": 18,
    "medium_name": "< removed >",
    "pxe_loader": "PXELinux BIOS",
    "build": false,
    "comment": "testhost update",
    "disk": "",
    "installed_at": "2020-12-15 13:40:04 +0100",
    "model_id": 1,
    "hostgroup_id": 3,
    "owner_id": 7,
    "owner_name": "< removed >",
    "owner_type": "User",
    "enabled": true,
    "managed": true,
    "use_image": null,
    "image_file": "",
    "uuid": "< removed >",
    "compute_resource_id": 7,
    "compute_resource_name": "< removed >",
    "compute_profile_id": 4,
    "compute_profile_name": "< removed >",
    "capabilities": [
      "build",
      "image",
      "snapshots",
      "snapshot_include_ram",
      "editable_snapshot_name" 
    ],
    "provision_method": "build",
    "certname": "testhost.lan",
    "image_id": null,
    "image_name": null,
    "created_at": "2020-12-15 13:29:33 +0100",
    "updated_at": "2020-12-16 09:16:53 +0100",
    "last_compile": null,
    "global_status": 0,
    "global_status_label": "OK",
    "uptime_seconds": 71759,
    "organization_id": 1,
    "organization_name": "< removed >",
    "location_id": 2,
    "location_name": "< removed >",
    "puppet_status": 0,
    "model_name": "VMware Virtual Platform",
    "configuration_status": 0,
    "configuration_status_label": "No changes",
    "build_status": 0,
    "build_status_label": "Installed",
    "name": "testhost.lan",
    "id": 184,
    "puppet_proxy_id": 2,
    "puppet_proxy_name": "< removed >",
    "puppet_ca_proxy_id": 3,
    "puppet_ca_proxy_name": "< removed >",
    "puppet_proxy": {
      "name": "< removed >",
      "id": 2,
      "url": "< removed >" 
    },
    "puppet_ca_proxy": {
      "name": "< removed >",
      "id": 3,
      "url": "< removed >" 
    },
    "registration_token": "< removed >",
    "hostgroup_name": "< removed >",
    "hostgroup_title": "< removed >",
    "parameters": [],
    "all_parameters": [
      {
        "priority": 60,
        "created_at": "2020-08-27 13:02:49 +0200",
        "updated_at": "2020-08-27 13:02:49 +0200",
        "id": 15,
        "name": "< removed >",
        "parameter_type": "string",
        "value": "< removed >" 
      },
      {
        "priority": 60,
        "created_at": "2020-08-27 13:02:49 +0200",
        "updated_at": "2020-08-27 13:02:49 +0200",
        "id": 13,
        "name": "< removed >",
        "parameter_type": "string",
        "value": "417" 
      },
      {
        "priority": 60,
        "created_at": "2020-08-27 13:02:49 +0200",
        "updated_at": "2020-08-27 13:02:49 +0200",
        "id": 14,
        "name": "< removed >",
        "parameter_type": "string",
        "value": "418" 
      },
      {
        "priority": 60,
        "created_at": "2020-08-27 13:02:49 +0200",
        "updated_at": "2020-08-28 17:24:05 +0200",
        "id": 12,
        "name": "< removed >",
        "parameter_type": "string",
        "value": "333" 
      },
      {
        "priority": 60,
        "created_at": "2020-08-27 13:02:49 +0200",
        "updated_at": "2020-08-27 13:02:49 +0200",
        "id": 11,
        "name": "< removed >",
        "parameter_type": "string",
        "value": "< removed >" 
      },
      {
        "priority": 0,
        "created_at": "2020-12-15 17:02:58 +0100",
        "updated_at": "2020-12-15 17:02:58 +0100",
        "id": 56,
        "name": "host_registration_remote_execution",
        "parameter_type": "boolean",
        "value": true
      },
      {
        "priority": 0,
        "created_at": "2020-12-15 17:02:58 +0100",
        "updated_at": "2020-12-15 17:02:58 +0100",
        "id": 55,
        "name": "host_registration_insights",
        "parameter_type": "boolean",
        "value": false
      }
    ],
    "interfaces": [
      {
        "subnet_id": 1,
        "subnet_name": "< removed >",
        "subnet6_id": null,
        "subnet6_name": null,
        "domain_id": 1,
        "domain_name": "< removed >",
        "created_at": "2020-12-15 13:29:42 +0100",
        "updated_at": "2020-12-15 14:15:59 +0100",
        "managed": true,
        "identifier": "eth0",
        "id": 222,
        "name": "testhost.lan",
        "ip": "< removed >",
        "ip6": "",
        "mac": "< removed >",
        "mtu": 1500,
        "fqdn": "testhost.lan",
        "primary": true,
        "provision": true,
        "type": "interface",
        "virtual": false
      },
      {
        "subnet_id": null,
        "subnet_name": null,
        "subnet6_id": null,
        "subnet6_name": null,
        "domain_id": null,
        "domain_name": null,
        "created_at": "2020-12-15 13:29:42 +0100",
        "updated_at": "2020-12-15 14:15:59 +0100",
        "managed": true,
        "identifier": "eth1",
        "id": 223,
        "name": "",
        "ip": "< removed >",
        "ip6": "",
        "mac": "< removed >",
        "mtu": 1500,
        "fqdn": "",
        "primary": false,
        "provision": false,
        "type": "interface",
        "virtual": false
      },
      {
        "subnet_id": null,
        "subnet_name": null,
        "subnet6_id": null,
        "subnet6_name": null,
        "domain_id": null,
        "domain_name": null,
        "created_at": "2020-12-15 13:29:42 +0100",
        "updated_at": "2020-12-15 14:15:59 +0100",
        "managed": true,
        "identifier": "eth2",
        "id": 224,
        "name": "",
        "ip": "< removed >",
        "ip6": "",
        "mac": "< removed >",
        "mtu": 1500,
        "fqdn": "",
        "primary": false,
        "provision": false,
        "type": "interface",
        "virtual": false
      }
    ],
    "puppetclasses": [],
    "config_groups": [],
    "all_puppetclasses": [],
    "permissions": {
      "view_hosts": true,
      "create_hosts": true,
      "edit_hosts": true,
      "destroy_hosts": true,
      "build_hosts": true,
      "power_hosts": true,
      "console_hosts": true,
      "ipmi_boot_hosts": true,
      "forget_status_hosts": true,
      "view_snapshots": true,
      "create_snapshots": true,
      "edit_snapshots": true,
      "destroy_snapshots": true,
      "revert_snapshots": true
    }
  }
}

Related logs:

2020-12-16T09:33:35 [I|app|3932de9d] Started POST "/hosts" for 127.0.0.1 at 2020-12-16 09:33:35 +0100
2020-12-16T09:33:35 [I|app|3932de9d] Processing by HostsController#create as */*
2020-12-16T09:33:35 [I|app|3932de9d]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"NeXp8srqIdh1D/bri8ZKG8rucFMtbjI9zVVvZBsmHIUZ9oDAwfCU/fXe1Jd03B1Ywf6CgYNkTNgzreUy7RVBAA==", "host"=>{"name"=>"testhost", "organization_id"=>"1", "location_id"=>"2", "hostgroup_id"=>"3", "compute_resource_id"=>"7", "environment_id"=>"32", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "identifier"=>"", "name"=>"testhost", "domain_id"=>"1", "subnet_id"=>"1", "ip"=>"< removed >", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"< removed >"}}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"< removed >"}}, "2"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>"", "compute_attributes"=>{"type"=>"VirtualVmxnet3", "network"=>"< removed >"}}}, "compute_attributes"=>{"cpus"=>"2", "corespersocket"=>"1", "memory_mb"=>"2048", "firmware"=>"bios", "cluster"=>"< removed >", "resource_pool"=>"Resources", "path"=>"< removed >", "guest_id"=>"rhel7_64Guest", "hardware_version"=>"Default", "memoryHotAddEnabled"=>"1", "cpuHotAddEnabled"=>"1", "add_cdrom"=>"0", "boot_order"=>["network", "disk"], "start"=>"1", "annotation"=>"", "scsi_controllers"=>"{\"scsiControllers\":[{\"type\":\"ParaVirtualSCSIController\",\"key\":1000}],\"volumes\":[{\"thin\":\"false\",\"name\":\"sda\",\"mode\":\"persistent\",\"controllerKey\":1000,\"datastore\":\"< removed >\",\"sizeGb\":1,\"eagerZero\":\"false\",\"storagePod\":null},{\"thin\":\"false\",\"name\":\"sdb\",\"mode\":\"persistent\",\"controllerKey\":1000,\"datastore\":\"< removed >\",\"sizeGb\":40,\"eagerZero\":\"false\",\"storagePod\":null}]}"}, "architecture_id"=>"1", "operatingsystem_id"=>"7", "provision_method"=>"build", "build"=>"1", "medium_id"=>"18", "ptable_id"=>"143", "pxe_loader"=>"PXELinux BIOS", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"7-Users", "enabled"=>"1", "comment"=>"testhost install", "overwrite"=>"false"}}
2020-12-16T09:33:35 [D|tax|3932de9d] Current location set to none
2020-12-16T09:33:35 [D|tax|3932de9d] Current organization set to none
2020-12-16T09:33:35 [D|app|3932de9d] Scheduling new DHCP reservations for testhost.lan
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'dhcp_create_10.122.84.48' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Scheduling new DNS entries
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Create IPv4 DNS record for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Create Reverse IPv4 DNS record for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|tax|3932de9d] Current organization set to < removed >
2020-12-16T09:33:35 [D|tax|3932de9d] Current location set to < removed >
2020-12-16T09:33:35 [D|tax|3932de9d] Current location set to none
2020-12-16T09:33:35 [D|tax|3932de9d] Current organization set to none
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Deploy TFTP PXELinux config for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Deploy TFTP PXEGrub2 config for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Deploy TFTP PXEGrub config for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Deploy TFTP iPXE config for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Fetch TFTP boot files for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Set up compute instance testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Query instance details for testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Power up compute instance testhost.lan' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Observed create hook on testhost.lan
2020-12-16T09:33:35 [D|app|3932de9d] Queuing 2 hooks for Host::Managed#create
2020-12-16T09:33:35 [D|app|3932de9d] Queuing hook /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions for Host::Managed#create at priority 0
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Queuing hook /usr/share/foreman/config/hooks/host/managed/create/5_create-custom_hook_actions for Host::Managed#create at priority 5
2020-12-16T09:33:35 [D|app|3932de9d] Enqueued task 'Hook: /usr/share/foreman/config/hooks/host/managed/create/5_create-custom_hook_actions' to 'Host::Managed Main' queue
2020-12-16T09:33:35 [D|app|3932de9d] Observed postcreate hook on testhost.lan
2020-12-16T09:33:35 [D|app|3932de9d] Processing task 'Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions' from 'Host::Managed Main'
2020-12-16T09:33:35 [D|app|3932de9d] Running hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions create testhost.lan
2020-12-16T09:33:35 [W|app|3932de9d] Unable to render testhost.lan (Host::Managed) using RABL: You cannot call create unless the parent is saved
2020-12-16T09:33:35 [D|app|3932de9d] /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/associations/has_one_association.rb:111:in `_create_record'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/associations/association.rb:199:in `create!'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/associations/builder/singular_association.rb:37:in `create_registration_facet!'
 3932de9d | /usr/share/foreman/app/models/concerns/foreman_register/host_extensions.rb:8:in `registration_facet!'
 3932de9d | /usr/share/foreman/app/models/concerns/foreman_register/host_extensions.rb:12:in `registration_token'
 3932de9d | /usr/share/foreman/app/views/api/v2/hosts/main.json.rabl:37:in `block in cached_source_2132320255127778590'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:157:in `node'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:116:in `block in compile_settings'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:115:in `each'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:115:in `compile_settings'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:60:in `block in to_hash'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:252:in `cache_results'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:51:in `to_hash'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:90:in `to_hash'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:50:in `block in render'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:385:in `cache_results'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:49:in `render'
 3932de9d | /usr/share/foreman/config/initializers/rabl_init.rb:49:in `render'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:129:in `block in merge_engines_into_result'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:121:in `each'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:121:in `merge_engines_into_result'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:57:in `block in to_hash'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:252:in `cache_results'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/builder.rb:51:in `to_hash'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:90:in `to_hash'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:103:in `to_dumpable'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:112:in `to_json'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:50:in `block in render'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:385:in `cache_results'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/engine.rb:49:in `render'
 3932de9d | /usr/share/foreman/config/initializers/rabl_init.rb:49:in `render'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl/renderer.rb:54:in `render'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rabl-0.14.3/lib/rabl.rb:77:in `render'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_hooks-0.3.17/lib/foreman_hooks/util.rb:27:in `render_hook_json'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_hooks-0.3.17/lib/foreman_hooks/util.rb:44:in `block in exec_hook'
 3932de9d | /opt/rh/rh-ruby25/root/usr/share/gems/gems/bundler-1.16.1/lib/bundler.rb:297:in `block in with_clean_env'
 3932de9d | /opt/rh/rh-ruby25/root/usr/share/gems/gems/bundler-1.16.1/lib/bundler.rb:540:in `with_env'
 3932de9d | /opt/rh/rh-ruby25/root/usr/share/gems/gems/bundler-1.16.1/lib/bundler.rb:297:in `with_clean_env'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_hooks-0.3.17/lib/foreman_hooks/util.rb:44:in `exec_hook'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_hooks-0.3.17/lib/foreman_hooks/orchestration_hook.rb:58:in `hook_execute_set'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:227:in `execute'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:152:in `block in process'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `each'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `process'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:44:in `around_save_orchestration'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:139:in `run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:825:in `_run_save_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/callbacks.rb:327:in `create_or_update'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/timestamp.rb:128:in `create_or_update'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/persistence.rb:470:in `save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/validations.rb:47:in `save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:314:in `block in save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:375:in `block in with_transaction_returning_status'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `block in transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:212:in `transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:366:in `with_transaction_returning_status'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:314:in `save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/suppressor.rb:44:in `save'
 3932de9d | /usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save'
 3932de9d | /usr/share/foreman/app/controllers/hosts_controller.rb:98:in `create'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/base.rb:195:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/rendering.rb:30:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:112:in `block in run_callbacks'
 3932de9d | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:139:in `run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/callbacks.rb:41:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/rescue.rb:22:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/notifications.rb:180:in `block in instrument'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/notifications.rb:180:in `instrument'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/base.rb:136:in `process'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionview-6.0.3.4/lib/action_view/rendering.rb:39:in `process'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal.rb:190:in `dispatch'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal.rb:254:in `dispatch'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/routing/route_set.rb:33:in `serve'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/journey/router.rb:49:in `block in serve'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/journey/router.rb:32:in `each'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/journey/router.rb:32:in `serve'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/routing/route_set.rb:834:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.3.0/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/static_dispatcher.rb:66:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/extractor/recorder.rb:137:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/catch_json_parse_errors.rb:9:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/conditional_get.rb:40:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/cookies.rb:648:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:101:in `run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/rack/logger.rb:37:in `call_app'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/rack/logger.rb:28:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/request_id.rb:27:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/executor.rb:14:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/static.rb:126:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/host_authorization.rb:76:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-6.3.0/lib/secure_headers/middleware.rb:11:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/engine.rb:527:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/railtie.rb:190:in `public_send'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/railtie.rb:190:in `method_missing'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:74:in `block in call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `each'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/configuration.rb:228:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/server.rb:713:in `handle_request'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/server.rb:472:in `process_client'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/server.rb:328:in `block in run'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/thread_pool.rb:134:in `block in spawn_thread'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2020-12-16T09:33:36 [I|app|eb41e8b4] Started GET "/tasks/1746e212-fb37-4f13-b48a-0cf961ba3005" for 127.0.0.1 at 2020-12-16 09:33:36 +0100
2020-12-16T09:33:36 [I|app|eb41e8b4] Processing by TasksController#show as */*
2020-12-16T09:33:36 [I|app|eb41e8b4]   Parameters: {"id"=>"1746e212-fb37-4f13-b48a-0cf961ba3005"}
2020-12-16T09:33:36 [I|app|eb41e8b4]   Rendered tasks/_list.html.erb (Duration: 0.9ms | Allocations: 689)
2020-12-16T09:33:36 [I|app|eb41e8b4] Completed 200 OK in 8ms (Views: 2.2ms | ActiveRecord: 1.0ms | Allocations: 3269)
2020-12-16T09:33:38 [I|app|1af756af] Started GET "/users/login" for 127.0.0.1 at 2020-12-16 09:33:38 +0100
2020-12-16T09:33:38 [I|app|5cdeac80] Started GET "/users/login" for 127.0.0.1 at 2020-12-16 09:33:38 +0100
2020-12-16T09:33:38 [I|app|1af756af] Processing by UsersController#login as HTML
2020-12-16T09:33:38 [I|app|5cdeac80] Processing by UsersController#login as HTML
2020-12-16T09:33:38 [I|app|df1ab7b3] Started GET "/users/login" for 127.0.0.1 at 2020-12-16 09:33:38 +0100
2020-12-16T09:33:38 [I|app|df1ab7b3] Processing by UsersController#login as HTML
2020-12-16T09:33:38 [I|app|5cdeac80]   Rendering users/login.html.erb within layouts/login
2020-12-16T09:33:38 [I|app|1af756af]   Rendering users/login.html.erb within layouts/login
2020-12-16T09:33:38 [I|app|5cdeac80]   Rendered common/_login.html.erb (Duration: 2.7ms | Allocations: 5081)
2020-12-16T09:33:38 [I|app|5cdeac80]   Rendered users/login.html.erb within layouts/login (Duration: 7.4ms | Allocations: 10220)
2020-12-16T09:33:38 [I|app|5cdeac80]   Rendering layouts/base.html.erb
2020-12-16T09:33:38 [I|app|1af756af]   Rendered common/_login.html.erb (Duration: 3.2ms | Allocations: 5120)
2020-12-16T09:33:38 [I|app|1af756af]   Rendered users/login.html.erb within layouts/login (Duration: 7.9ms | Allocations: 10295)
2020-12-16T09:33:38 [I|app|5cdeac80]   Rendered layouts/base.html.erb (Duration: 4.3ms | Allocations: 6120)
2020-12-16T09:33:38 [I|app|1af756af]   Rendering layouts/base.html.erb
2020-12-16T09:33:38 [I|app|5cdeac80] Completed 200 OK in 26ms (Views: 15.0ms | ActiveRecord: 4.2ms | Allocations: 23007)
2020-12-16T09:33:38 [I|app|df1ab7b3]   Rendering users/login.html.erb within layouts/login
2020-12-16T09:33:38 [I|app|1af756af]   Rendered layouts/base.html.erb (Duration: 6.3ms | Allocations: 6689)
2020-12-16T09:33:38 [I|app|df1ab7b3]   Rendered common/_login.html.erb (Duration: 2.6ms | Allocations: 5120)
2020-12-16T09:33:38 [I|app|df1ab7b3]   Rendered users/login.html.erb within layouts/login (Duration: 6.6ms | Allocations: 10369)
2020-12-16T09:33:38 [I|app|df1ab7b3]   Rendering layouts/base.html.erb
2020-12-16T09:33:38 [I|app|df1ab7b3]   Rendered layouts/base.html.erb (Duration: 3.7ms | Allocations: 6155)
2020-12-16T09:33:38 [I|app|1af756af] Completed 200 OK in 47ms (Views: 23.7ms | ActiveRecord: 4.3ms | Allocations: 48026)
2020-12-16T09:33:38 [I|app|df1ab7b3] Completed 200 OK in 45ms (Views: 14.0ms | ActiveRecord: 7.4ms | Allocations: 46361)
2020-12-16T09:33:38 [I|app|45235c27] Started GET "/tasks/1746e212-fb37-4f13-b48a-0cf961ba3005" for 127.0.0.1 at 2020-12-16 09:33:38 +0100
2020-12-16T09:33:38 [I|app|45235c27] Processing by TasksController#show as */*
2020-12-16T09:33:38 [I|app|45235c27]   Parameters: {"id"=>"1746e212-fb37-4f13-b48a-0cf961ba3005"}
2020-12-16T09:33:38 [I|app|45235c27]   Rendered tasks/_list.html.erb (Duration: 3.9ms | Allocations: 5388)
2020-12-16T09:33:38 [I|app|45235c27] Completed 200 OK in 10ms (Views: 4.5ms | ActiveRecord: 1.1ms | Allocations: 7196)
2020-12-16T09:33:40 [I|app|7fe6cc67] Started GET "/tasks/1746e212-fb37-4f13-b48a-0cf961ba3005" for 127.0.0.1 at 2020-12-16 09:33:40 +0100
2020-12-16T09:33:40 [I|app|7fe6cc67] Processing by TasksController#show as */*
2020-12-16T09:33:40 [I|app|7fe6cc67]   Parameters: {"id"=>"1746e212-fb37-4f13-b48a-0cf961ba3005"}
2020-12-16T09:33:40 [I|app|7fe6cc67]   Rendered tasks/_list.html.erb (Duration: 3.8ms | Allocations: 5388)
2020-12-16T09:33:40 [I|app|7fe6cc67] Completed 200 OK in 9ms (Views: 4.2ms | ActiveRecord: 1.0ms | Allocations: 7194)
2020-12-16T09:33:41 [D|app|3932de9d] Hook output: ✘✘✘ HOOK SCRIPT OUTPUT ✘✘✘ please select a puppet environment (required by nsx-t) ✘✘✘
 3932de9d |
2020-12-16T09:33:41 [W|app|3932de9d] Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions task failed with the following error: Hook failure running `/usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions create testhost.lan`:  ✘✘✘ HOOK SCRIPT OUTPUT ✘✘✘ please select a puppet environment (required by nsx-t) ✘✘✘
 3932de9d |
2020-12-16T09:33:41 [I|app|3932de9d] Backtrace for 'Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions task failed with the following error: Hook failure running `/usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions create testhost.lan`:  ✘✘✘ HOOK SCRIPT OUTPUT ✘✘✘ please select a puppet environment (required by nsx-t) ✘✘✘
 3932de9d | ' error (ForemanHooks::Error): Hook failure running `/usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions create testhost.lan`:  ✘✘✘ HOOK SCRIPT OUTPUT ✘✘✘ please select a puppet environment (required by nsx-t) ✘✘✘
 3932de9d |
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_hooks-0.3.17/lib/foreman_hooks/util.rb:49:in `exec_hook'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_hooks-0.3.17/lib/foreman_hooks/orchestration_hook.rb:58:in `hook_execute_set'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:227:in `execute'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:152:in `block in process'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `each'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `process'
 3932de9d | /usr/share/foreman/app/models/concerns/orchestration.rb:44:in `around_save_orchestration'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:139:in `run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:825:in `_run_save_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/callbacks.rb:327:in `create_or_update'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/timestamp.rb:128:in `create_or_update'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/persistence.rb:470:in `save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/validations.rb:47:in `save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:314:in `block in save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:375:in `block in with_transaction_returning_status'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `block in transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:212:in `transaction'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:366:in `with_transaction_returning_status'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/transactions.rb:314:in `save'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/suppressor.rb:44:in `save'
 3932de9d | /usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save'
 3932de9d | /usr/share/foreman/app/controllers/hosts_controller.rb:98:in `create'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/base.rb:195:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/rendering.rb:30:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:112:in `block in run_callbacks'
 3932de9d | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:139:in `run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/callbacks.rb:41:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/rescue.rb:22:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/notifications.rb:180:in `block in instrument'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/notifications.rb:180:in `instrument'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.4/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/abstract_controller/base.rb:136:in `process'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionview-6.0.3.4/lib/action_view/rendering.rb:39:in `process'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal.rb:190:in `dispatch'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_controller/metal.rb:254:in `dispatch'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/routing/route_set.rb:33:in `serve'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/journey/router.rb:49:in `block in serve'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/journey/router.rb:32:in `each'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/journey/router.rb:32:in `serve'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/routing/route_set.rb:834:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.3.0/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/static_dispatcher.rb:66:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/extractor/recorder.rb:137:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/catch_json_parse_errors.rb:9:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/conditional_get.rb:40:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/cookies.rb:648:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/callbacks.rb:101:in `run_callbacks'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/rack/logger.rb:37:in `call_app'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/rack/logger.rb:28:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
 3932de9d | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/request_id.rb:27:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.4/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/executor.rb:14:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/static.rb:126:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.4/lib/action_dispatch/middleware/host_authorization.rb:76:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-6.3.0/lib/secure_headers/middleware.rb:11:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/engine.rb:527:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/railtie.rb:190:in `public_send'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.4/lib/rails/railtie.rb:190:in `method_missing'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:74:in `block in call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `each'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/configuration.rb:228:in `call'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/server.rb:713:in `handle_request'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/server.rb:472:in `process_client'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/server.rb:328:in `block in run'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/puma-4.3.6/lib/puma/thread_pool.rb:134:in `block in spawn_thread'
 3932de9d | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2020-12-16T09:33:41 [W|app|3932de9d] Rolling back due to a problem: [#<Orchestration::Task:0x00007f4aefa6e168 @name="Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions", @id="Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions", @status="failed", @priority=0, @action=[#<ForemanHooks::OrchestrationHook::HookRunner:0x00007f4aefa6e230 @filename="/usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions", @obj=#<Host::Managed id: nil, name: "testhost.lan", last_compile: nil, last_report: nil, updated_at: nil, created_at: nil, root_pass: [FILTERED], architecture_id: 1, operatingsystem_id: 7, environment_id: 32, ptable_id: 143, medium_id: 18, build: true, comment: "koen test", disk: "", installed_at: nil, model_id: nil, hostgroup_id: 3, owner_id: 7, owner_type: "User", enabled: true, puppet_ca_proxy_id: 3, managed: true, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: 7, puppet_proxy_id: 2, certname: nil, image_id: nil, organization_id: 1, location_id: 2, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "$6$iWfTJ2QjaBoiDuFU$FSLrqUFXvMZB8EwsMjrN7/VEBMK5DW...", global_status: 0, lookup_value_matcher: [FILTERED], pxe_loader: "PXELinux BIOS", initiated_at: nil, build_errors: nil>, @event="create">, :hook_execute_set], @created=1608107615.3711407, @timestamp=2020-12-16 08:33:41 UTC>]
2020-12-16T09:33:41 [E|app|3932de9d] Failed to save: Hook: /usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions task failed with the following error: Hook failure running `/usr/share/foreman/config/hooks/host/managed/create/0_create-custom_hook_actions create testhost.lan`:  ✘✘✘ HOOK SCRIPT OUTPUT ✘✘✘ please select a puppet environment (required by nsx-t) ✘✘✘
 3932de9d |
2020-12-16T09:33:41 [I|app|3932de9d]   Rendering hosts/new.html.erb within layouts/application
2020-12-16T09:33:41 [I|app|3932de9d]   Rendered hosts/_progress.html.erb (Duration: 4.2ms | Allocations: 5054)


Related issues

Related to Foreman - Bug #31163: Registration facet does not reload properly when code changesResolved

Associated revisions

Revision 0301a534 (diff)
Added by Ondřej Ezr about 2 months ago

Fixes #31518 - remove unused registration_token from API

In f981d43bc2b2b3e18281ccab28074d0570db7867 we've introduced a registration_token in host API.
This token is not used in final design and is causing issues during orchestration.

History

#1 Updated by Koen Torfs 3 months ago

  • Priority changed from High to Normal

#2 Updated by Tomer Brisker 3 months ago

  • Status changed from New to Rejected

Looks like this issue is in the hooks plugin which tracks it's issues at https://github.com/theforeman/foreman_hooks/issues

#3 Updated by Koen Torfs 3 months ago

I check https://github.com/theforeman/foreman_hooks/commits/master already and don't see any recent commits which could explain why it works on 2.2.1 and not on 2.3.1
Also tested already with removing the line Shimon added https://github.com/theforeman/foreman_hooks/commit/f3b092e145eb18e579883ff67fdeb0672134d05b but no change
So to me it seems to be outside of foreman_hooks otherwise I would have logged the issue there

#4 Updated by Tomer Brisker 3 months ago

  • Status changed from Rejected to New
  • Category changed from Host creation to Host registration

Sorry, on deeper look it seems like an issue caused by the host registration facet.

#5 Updated by Tomer Brisker 3 months ago

  • Target version set to 2.3.2

#6 Updated by Lukas Zapletal 3 months ago

For the record, foreman_webhooks plugin which we are planning to release in few weeks is gonna solve this problem for once. Take a look.

#7 Updated by Koen Torfs 3 months ago

Hi Lukas, during my investigation I indeed came across the thread about the webhooks plugin from Timo. But since I did not find a package yet in a release repo nor found any documentation, guessed it was not useable yet at the moment.
Have not read the whole thread yet but somewhere at the start there was a discussion about rollbacks. This is something I use often in case people don't specify all necessary data or when other checks in my hooks fail. I think it was Timo who mentioned something about triggers.
Hope this made it to the first release. I am however curious but I also wonder how the different steps in each action in the Foreman code (create/update/...) can wait for my bash scripts to execute and give a trigger back. I also need a trigger for my bash script to know when to execute.

#8 Updated by Lukas Zapletal 3 months ago

I am currently working on packaging, documentation is up next. But you are right it is in yearly stage of development, I just wanted to drop this comment beacuse this is exactly one of these regressions we wanted to get rid of in the new design.

Something changed internally and since hooks is not well defined and documented interface that is being tracked and tested, it broke up. It could be anything in core, not just a change in hooks plugin itself.

#9 Updated by The Foreman Bot about 2 months ago

  • Assignee set to Ondřej Ezr
  • Status changed from New to Ready For Testing
  • Pull request https://github.com/theforeman/foreman/pull/8233 added

#10 Updated by The Foreman Bot about 2 months ago

  • Pull request https://github.com/theforeman/foreman/pull/8234 added

#11 Updated by Ondřej Ezr about 2 months ago

  • Pull request deleted (https://github.com/theforeman/foreman/pull/8234)

#12 Updated by Tomer Brisker about 2 months ago

  • Bugzilla link set to 1915342

#13 Updated by Koen Torfs about 2 months ago

tested the fix successfully, thanks !

#14 Updated by The Foreman Bot about 2 months ago

  • Fixed in Releases 2.4.0 added

#15 Updated by Tomer Brisker about 2 months ago

  • Fixed in Releases 2.3.2 added

#16 Updated by Ondřej Ezr about 2 months ago

  • Status changed from Ready For Testing to Closed

#17 Updated by Tomer Brisker about 2 months ago

  • Subject changed from foreman_hooks: json representation of the hook object is limited / incorrect during create hook to foreman_hooks: create hook fails to render host with "You cannot call create unless the parent is saved"

#18 Updated by Tomer Brisker about 2 months ago

  • Related to Bug #31163: Registration facet does not reload properly when code changes added

Also available in: Atom PDF