Bug 1129454 - subscription-manager silently fails to inform about registration failure on RHEL 6.6
Summary: subscription-manager silently fails to inform about registration failure on R...
Keywords:
Status: CLOSED DUPLICATE of bug 1129480
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: subscription-manager
Version: 6.6
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: rc
: 6.6
Assignee: candlepin-bugs
QA Contact: John Sefler
URL: http://projects.theforeman.org/issues...
Whiteboard:
Depends On: 1129480
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-08-12 19:36 UTC by Og Maciel
Modified: 2014-09-09 17:04 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-09-09 17:04:04 UTC


Attachments (Terms of Use)

Description Og Maciel 2014-08-12 19:36:25 UTC
Description of problem:

Noticed that when trying to register a RHEL 6.6 (both i386 and x86_64) client against a Satellite 6 instance using an activationkey, subscription-manager silently fails without displaying that something went wrong.

Looking at rhsm.log I saw the following:

2014-08-12 15:25:58,117 [DEBUG] subscription-manager @connection.py:414 - Loaded CA certificates from /etc/rhsm/ca/: candlepin-local.pem, candlepin-stage.pem, redhat-uep.pem
2014-08-12 15:25:58,118 [DEBUG] subscription-manager @connection.py:446 - Making request: GET /rhsm/owners/Default_Organization/environments
2014-08-12 15:25:58,221 [DEBUG] subscription-manager @connection.py:469 - Response: status=401
2014-08-12 15:25:58,222 [ERROR] subscription-manager @managercli.py:1049 -
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 1038, in _do_command
    self.options.environment)
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 1133, in _get_environment_id
    env_list = cp.getEnvironmentList(owner_key)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 1095, in getEnvironmentList
    results = self.conn.request_get(method)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 550, in request_get
    return self._request("GET", method)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 478, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib/python2.6/site-packages/rhsm/connection.py", line 520, in validateResponse
    raise RestlibException(response['status'], error_msg)
RestlibException


Version-Release number of selected component (if applicable):

Build:
------
* Satellite-6.0.4-RHEL-6-20140806.0

Packages:
---------

* apr-util-ldap-1.3.9-3.el6_0.1.x86_64
* candlepin-0.9.19-1.el6_5.noarch
* candlepin-scl-1-5.el6_4.noarch
* candlepin-scl-quartz-2.1.5-5.el6_4.noarch
* candlepin-scl-rhino-1.7R3-1.el6_4.noarch
* candlepin-scl-runtime-1-5.el6_4.noarch
* candlepin-selinux-0.9.19-1.el6_5.noarch
* candlepin-tomcat6-0.9.19-1.el6_5.noarch
* elasticsearch-0.90.10-4.el6sat.noarch
* foreman-1.6.0.38-1.el6sat.noarch
* foreman-compute-1.6.0.38-1.el6sat.noarch
* foreman-gce-1.6.0.38-1.el6sat.noarch
* foreman-libvirt-1.6.0.38-1.el6sat.noarch
* foreman-ovirt-1.6.0.38-1.el6sat.noarch
* foreman-postgresql-1.6.0.38-1.el6sat.noarch
* foreman-proxy-1.6.0.23-1.el6sat.noarch
* foreman-selinux-1.6.0.4-1.el6sat.noarch
* foreman-vmware-1.6.0.38-1.el6sat.noarch
* katello-1.5.0-28.el6sat.noarch
* katello-ca-1.0-1.noarch
* katello-certs-tools-1.5.6-1.el6sat.noarch
* katello-installer-0.0.57-1.el6sat.noarch
* openldap-2.4.23-32.el6_4.1.x86_64
* pulp-katello-0.3-3.el6sat.noarch
* pulp-nodes-common-2.4.0-0.30.beta.el6sat.noarch
* pulp-nodes-parent-2.4.0-0.30.beta.el6sat.noarch
* pulp-puppet-plugins-2.4.0-0.30.beta.el6sat.noarch
* pulp-puppet-tools-2.4.0-0.30.beta.el6sat.noarch
* pulp-rpm-plugins-2.4.0-0.30.beta.el6sat.noarch
* pulp-selinux-2.4.0-0.30.beta.el6sat.noarch
* pulp-server-2.4.0-0.30.beta.el6sat.noarch
* python-ldap-2.3.10-1.el6.x86_64
* ruby193-rubygem-net-ldap-0.3.1-3.el6sat.noarch
* ruby193-rubygem-runcible-1.1.0-2.el6sat.noarch
* rubygem-hammer_cli-0.1.1-11.el6sat.noarch
* rubygem-hammer_cli_foreman-0.1.1-15.el6sat.noarch
* rubygem-hammer_cli_foreman_tasks-0.0.3-3.el6sat.noarch
* rubygem-hammer_cli_katello-0.0.4-10.el6sat.noarch

How reproducible:


Steps to Reproduce:
1. Register a RHEL 6.6 Server client to a satellite 6 instance using an activationkey
2.
3.

Actual results:

subscription-manager silently fails


Expected results:


Additional info:

==> /var/log/foreman/production.log <==
Processing by Katello::Api::V2::RootController#resource_list as JSON
  Parameters: {"root"=>{}}
Setting locale: en
  Rendered /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/views/katello/api/v2/root/resource_list.json.rabl within katello/api/v2/layouts/collection (2.8ms)
Body: [{"href":"/katello/api/capsules/","rel":"capsules"},{"href":"/katello/api/activation_keys/","rel":"activation_keys"},{"href":"/katello/api/activation_keys/","rel":"activation_keys"},{"href":"/katello/api/activation_keys/","rel":"activation_keys"},{"href":"/katello/api/content_views/","rel":"content_views"},{"href":"/katello/api/content_views/","rel":"content_views"},{"href":"/katello/api/content_views/","rel":"content_views"},{"href":"/katello/api/content_view_filters/","rel":"content_view_filters"},{"href":"/katello/api/content_view_filters/","rel":"content_view_filters"},{"href":"/katello/api/content_view_filters/","rel":"content_view_filters"},{"href":"/katello/api/content_view_versions/","rel":"content_view_versions"},{"href":"/katello/api/content_view_versions/","rel":"content_view_versions"},{"href":"/katello/api/content_view_versions/","rel":"content_view_versions"},{"href":"/katello/api/environments/","rel":"environments"},{"href":"/katello/api/environments/","rel":"environments"},{"href":"/katello/api/environments/","rel":"environments"},{"href":"/katello/api/errata/","rel":"errata"},{"href":"/katello/api/gpg_keys/","rel":"gpg_keys"},{"href":"/katello/api/gpg_keys/","rel":"gpg_keys"},{"href":"/katello/api/gpg_keys/","rel":"gpg_keys"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/packages/","rel":"packages"},{"href":"/katello/api/package_groups/","rel":"package_groups"},{"href":"/katello/api/products/","rel":"products"},{"href":"/katello/api/products/","rel":"products"},{"href":"/katello/api/products/","rel":"products"},{"href":"/katello/api/puppet_modules/","rel":"puppet_modules"},{"href":"/katello/api/repositories/","rel":"repositories"},{"href":"/katello/api/repositories/","rel":"repositories"},{"href":"/katello/api/repositories/","rel":"repositories"},{"href":"/katello/api/repository_sets/","rel":"repository_sets"},{"href":"/katello/api/subscriptions/","rel":"subscriptions"},{"href":"/katello/api/systems/","rel":"systems"},{"href":"/katello/api/systems/","rel":"systems"},{"href":"/katello/api/systems/","rel":"systems"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/distributors/","rel":"distributors"},{"href":"/katello/api/distributors/","rel":"distributors"},{"href":"/katello/api/distributors/","rel":"distributors"},{"href":"/katello/api/users/","rel":"users"},{"href":"/katello/api/users/","rel":"users"},{"href":"/katello/api/users/","rel":"users"},{"href":"/katello/api/sync_plans/","rel":"sync_plans"},{"href":"/katello/api/sync_plans/","rel":"sync_plans"},{"href":"/katello/api/sync_plans/","rel":"sync_plans"},{"href":"/katello/api/tasks/","rel":"tasks"},{"href":"/katello/api/packages/","rel":"packages"},{"href":"/katello/api/status/","rel":"status"},{"href":"/katello/api/guestids","rel":"guestids"},{"href":"/katello/api/content_overrides","rel":"content_overrides"},{"href":"/katello/api/available_releases","rel":"available_releases"}]

Completed 200 OK in 18ms (Views: 3.6ms | ActiveRecord: 0.0ms)
With body: [{"href":"/katello/api/capsules/","rel":"capsules"},{"href":"/katello/api/activation_keys/","rel":"activation_keys"},{"href":"/katello/api/activation_keys/","rel":"activation_keys"},{"href":"/katello/api/activation_keys/","rel":"activation_keys"},{"href":"/katello/api/content_views/","rel":"content_views"},{"href":"/katello/api/content_views/","rel":"content_views"},{"href":"/katello/api/content_views/","rel":"content_views"},{"href":"/katello/api/content_view_filters/","rel":"content_view_filters"},{"href":"/katello/api/content_view_filters/","rel":"content_view_filters"},{"href":"/katello/api/content_view_filters/","rel":"content_view_filters"},{"href":"/katello/api/content_view_versions/","rel":"content_view_versions"},{"href":"/katello/api/content_view_versions/","rel":"content_view_versions"},{"href":"/katello/api/content_view_versions/","rel":"content_view_versions"},{"href":"/katello/api/environments/","rel":"environments"},{"href":"/katello/api/environments/","rel":"environments"},{"href":"/katello/api/environments/","rel":"environments"},{"href":"/katello/api/errata/","rel":"errata"},{"href":"/katello/api/gpg_keys/","rel":"gpg_keys"},{"href":"/katello/api/gpg_keys/","rel":"gpg_keys"},{"href":"/katello/api/gpg_keys/","rel":"gpg_keys"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/packages/","rel":"packages"},{"href":"/katello/api/package_groups/","rel":"package_groups"},{"href":"/katello/api/products/","rel":"products"},{"href":"/katello/api/products/","rel":"products"},{"href":"/katello/api/products/","rel":"products"},{"href":"/katello/api/puppet_modules/","rel":"puppet_modules"},{"href":"/katello/api/repositories/","rel":"repositories"},{"href":"/katello/api/repositories/","rel":"repositories"},{"href":"/katello/api/repositories/","rel":"repositories"},{"href":"/katello/api/repository_sets/","rel":"repository_sets"},{"href":"/katello/api/subscriptions/","rel":"subscriptions"},{"href":"/katello/api/systems/","rel":"systems"},{"href":"/katello/api/systems/","rel":"systems"},{"href":"/katello/api/systems/","rel":"systems"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/organizations/","rel":"organizations"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/host_collections/","rel":"host_collections"},{"href":"/katello/api/distributors/","rel":"distributors"},{"href":"/katello/api/distributors/","rel":"distributors"},{"href":"/katello/api/distributors/","rel":"distributors"},{"href":"/katello/api/users/","rel":"users"},{"href":"/katello/api/users/","rel":"users"},{"href":"/katello/api/users/","rel":"users"},{"href":"/katello/api/sync_plans/","rel":"sync_plans"},{"href":"/katello/api/sync_plans/","rel":"sync_plans"},{"href":"/katello/api/sync_plans/","rel":"sync_plans"},{"href":"/katello/api/tasks/","rel":"tasks"},{"href":"/katello/api/packages/","rel":"packages"},{"href":"/katello/api/status/","rel":"status"},{"href":"/katello/api/guestids","rel":"guestids"},{"href":"/katello/api/content_overrides","rel":"content_overrides"},{"href":"/katello/api/available_releases","rel":"available_releases"}]


Processing by Katello::Api::Rhsm::CandlepinProxiesController#server_status as JSON
  Parameters: {"candlepin_proxy"=>{}}
Setting locale: en

==> /var/log/candlepin/candlepin.log <==
2014-08-12 15:25:57,690 [req=0e7f41bf-96d3-4047-8c5d-60529685b500, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Request: verb=GET, uri=/candlepin/status
2014-08-12 15:25:57,698 [req=0e7f41bf-96d3-4047-8c5d-60529685b500, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Response: status=200, content-type="application/json", time=8ms
2014-08-12 15:25:57,737 [req=5a96d445-3e06-4b53-b5be-3eb31e47602a, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Request: verb=GET, uri=/candlepin/status
2014-08-12 15:25:57,745 [req=5a96d445-3e06-4b53-b5be-3eb31e47602a, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Response: status=200, content-type="application/json", time=8ms
2014-08-12 15:25:57,777 [req=988796b5-a16e-47bf-b98d-61209db07ca4, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Request: verb=GET, uri=/candlepin/status
2014-08-12 15:25:57,785 [req=988796b5-a16e-47bf-b98d-61209db07ca4, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Response: status=200, content-type="application/json", time=8ms
2014-08-12 15:25:57,820 [req=6a648b81-d203-4ef8-8812-4b2db35819b5, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Request: verb=GET, uri=/candlepin/status
2014-08-12 15:25:57,828 [req=6a648b81-d203-4ef8-8812-4b2db35819b5, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Response: status=200, content-type="application/json", time=8ms
2014-08-12 15:25:57,863 [req=120813f4-f63b-49ea-ab2b-7c7b34cf16d4, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Request: verb=GET, uri=/candlepin/status
2014-08-12 15:25:57,870 [req=120813f4-f63b-49ea-ab2b-7c7b34cf16d4, org=] INFO  org.candlepin.servlet.filter.logging.LoggingFilter - Response: status=200, content-type="application/json", time=7ms

==> /var/log/foreman/production.log <==
Completed 200 OK in 218ms (Views: 0.7ms | ActiveRecord: 0.0ms)
With body: {"managerCapabilities":["cores","ram","instance_multiplier","derived_product","cert_v3","guest_limit","vcpu"],"release":"Katello","result":true,"rulesSource":"DATABASE","rulesVersion":"5.11","standalone":true,"timeUTC":"2014-08-12T19:25:57Z","version":"1.5.0-28.el6sat"}

Processing by Katello::Api::Rhsm::CandlepinProxiesController#rhsm_index as JSON
  Parameters: {"organization_id"=>"Default_Organization", "candlepin_proxy"=>{}}
Setting locale: en
  Rendered api/v1/errors/unauthorized.json.rabl (0.6ms)
Filter chain halted as :authorize rendered or redirected
Completed 401 Unauthorized in 3ms (Views: 1.7ms | ActiveRecord: 0.0ms)
With body: {"message":"Unable to authenticate user "}

Comment 1 Og Maciel 2014-08-12 19:40:12 UTC
Registering without an activationkey worked:

# subscription-manager register --org Default_Organization --username admin --password changeme --env Library
The system has been registered with ID: a6c12248-9f66-4e50-9cea-a36cdc8a7a25

Client configuration:
---------------------
* RHEL-6.6-20140812.n.0
* subscription-manager-1.12.10-1.el6.i686


Logs show:

==> /var/log/foreman/production.log <==
Processing by HostsController#externalNodes as YML
  Parameters: {"name"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com"}
  Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'restrict_registered_puppetmasters' ORDER BY name LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'require_ssl_puppetmasters' ORDER BY name LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_client_dn_env' ORDER BY name LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_client_verify_env' ORDER BY name LIMIT 1
  SmartProxy Load (0.6ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet', 'Chef Proxy') ORDER BY smart_proxies.name
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'trusted_puppetmaster_hosts' ORDER BY name LIMIT 1
Verifying request from ["cloud-qe-8.idm.lab.bos.redhat.com"] against ["cloud-qe-8.idm.lab.bos.redhat.com"]
  User Load (0.5ms)  SELECT "users".* FROM "users" WHERE "users"."login" = 'foreman_api_admin' LIMIT 1
Setting current user thread-local variable to API Admin
  Host::Managed Load (0.6ms)  SELECT "hosts".* FROM "hosts" WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."certname" = 'og-rhel-7-x64-01.idm.lab.bos.redhat.com' LIMIT 1
  SmartProxy Load (0.3ms)  SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 1 ORDER BY smart_proxies.name LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'legacy_puppet_hostname' ORDER BY name LIMIT 1
  Domain Load (0.3ms)  SELECT "domains".* FROM "domains" WHERE "domains"."id" = 1 ORDER BY domains.name LIMIT 1
  Hostgroup Load (0.5ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = 3 ORDER BY hostgroups.title LIMIT 1
  Location Load (0.5ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" = 2 ORDER BY title LIMIT 1
  Organization Load (0.5ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" = 1 ORDER BY title LIMIT 1
  CACHE (0.0ms)  SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 1 ORDER BY smart_proxies.name LIMIT 1
  Environment Load (0.4ms)  SELECT "environments".* FROM "environments" WHERE "environments"."id" = 9 ORDER BY environments.name LIMIT 1
  AuthSourceHidden Load (0.3ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."type" IN ('AuthSourceHidden')
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 3 AND (1=1) AND (users.auth_source_id <> 2) LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ignore_puppet_facts_for_provisioning' ORDER BY name LIMIT 1
  CommonParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('CommonParameter') ORDER BY parameters.name
  OrganizationParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OrganizationParameter') AND "parameters"."reference_id" = 1 ORDER BY parameters.name
  LocationParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('LocationParameter') AND "parameters"."reference_id" = 2 ORDER BY parameters.name
  DomainParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('DomainParameter') AND "parameters"."reference_id" = 1 ORDER BY parameters.name
  Operatingsystem Load (0.3ms)  SELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."id" = 3 ORDER BY operatingsystems.name LIMIT 1
  OsParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OsParameter') AND "parameters"."reference_id" = 3 ORDER BY parameters.name
  GroupParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('GroupParameter') AND "parameters"."reference_id" = 3 ORDER BY parameters.name
  HostParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('HostParameter') AND "parameters"."reference_id" = 4 ORDER BY parameters.name
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'Enable_Smart_Variables_in_ENC' ORDER BY name LIMIT 1
   (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" = 4 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
  Hostgroup Load (0.4ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
   (0.4ms)  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" = 3 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
   (0.2ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
   (0.2ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3)
   (0.2ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" = 4
   (0.5ms)  SELECT DISTINCT puppetclasses.id FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 9 AND "puppetclasses"."id" IN (1)
  LookupKey Load (0.3ms)  SELECT "lookup_keys".* FROM "lookup_keys" WHERE "lookup_keys"."puppetclass_id" IN (1) ORDER BY lookup_keys.key
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'interpolate_erb_in_parameters' ORDER BY name LIMIT 1
  Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'safemode_render' ORDER BY name LIMIT 1
  Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'Parametrized_Classes_in_ENC' ORDER BY name LIMIT 1
  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" = 4 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
  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" = 3 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" = 4
  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" = 9 AND "puppetclasses"."id" IN (1)
  SQL (0.7ms)  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"."is_param" AS t0_r10, "lookup_keys"."key_type" AS t0_r11, "lookup_keys"."override" AS t0_r12, "lookup_keys"."required" AS t0_r13, "lookup_keys"."lookup_values_count" AS t0_r14, "environment_classes"."id" AS t1_r0, "environment_classes"."puppetclass_id" AS t1_r1, "environment_classes"."environment_id" AS t1_r2, "environment_classes"."lookup_key_id" AS t1_r3 FROM "lookup_keys" INNER JOIN "environment_classes" ON "environment_classes"."lookup_key_id" = "lookup_keys"."id" WHERE "lookup_keys"."override" = 't' AND "environment_classes"."puppetclass_id" IN (1) AND "environment_classes"."environment_id" = 9 ORDER BY lookup_keys.key
  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" = 4 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
  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" = 3 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" = 4
  Puppetclass Load (0.5ms)  SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 9 AND "puppetclasses"."id" IN (1) ORDER BY puppetclasses.name
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'enc_environment' ORDER BY name LIMIT 1
  Rendered text template (0.0ms)
Completed 200 OK in 113ms (Views: 0.4ms | ActiveRecord: 14.8ms)
Processing by Api::V2::HostsController#facts as JSON
  Parameters: {"name"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com", "facts"=>"[FILTERED]", "certname"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com", "apiv"=>"v2", "base"=>{"name"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com", "certname"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com"}}
  Location Load (0.5ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" IS NULL ORDER BY title LIMIT 1
Setting current location thread-local variable to none
  Organization Load (0.4ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" IS NULL ORDER BY title LIMIT 1
Setting current organization thread-local variable to none
  SmartProxy Load (0.6ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet', 'Chef Proxy') ORDER BY smart_proxies.name
Verifying request from ["cloud-qe-8.idm.lab.bos.redhat.com"] against ["cloud-qe-8.idm.lab.bos.redhat.com"]
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."login" = 'foreman_api_admin' LIMIT 1
Setting current user thread-local variable to API Admin
  Host::Managed Load (0.5ms)  SELECT "hosts".* FROM "hosts" WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."certname" = 'og-rhel-7-x64-01.idm.lab.bos.redhat.com' LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'create_new_host_when_facts_are_uploaded' ORDER BY name LIMIT 1
  FactValue Load (1.2ms)  SELECT "fact_values".* FROM "fact_values" INNER JOIN "fact_names" ON "fact_names"."id" = "fact_values"."fact_name_id" WHERE "fact_values"."host_id" = 4 AND (fact_names.name NOT IN ('memorytotal','facterversion','processor0','productname','bios_vendor','clientcert','operatingsystemmajrelease','architecture','sshecdsakey','selinux_policyversion','uptime','filesystems','type','processorcount','physicalprocessorcount','uptime_seconds','selinux_current_mode','clientnoop','sshfp_ecdsa','uniqueid','uuid','kernelrelease','selinux_config_policy','blockdevice_vda_vendor','hardwaremodel','blockdevice_vda_size','kernelmajversion','selinux_mode','memoryfree_mb','augeasversion','kernelversion','hardwareisa','operatingsystem','blockdevices','kernel','selinux_config_mode','virtual','rubysitedir','operatingsystemrelease','memorysize','selinux_enforced','memorysize_mb','ps','domain','rubyversion','manufacturer','timezone','osfamily','memoryfree','puppetversion','sshfp_rsa','swapsize','id','fqdn','clientversion','bios_version','uptime_days','sshrsakey','hostname','bios_release_date','path','serialnumber','selinux','swapsize_mb','uptime_hours','_timestamp','swapfree_mb','is_virtual','swapfree'))
Merging facts for 'og-rhel-7-x64-01.idm.lab.bos.redhat.com': deleted 0 facts
  FactValue Load (0.8ms)  SELECT "fact_values".* FROM "fact_values" WHERE "fact_values"."host_id" = 4
  FactName Load (1.2ms)  SELECT "fact_names".* FROM "fact_names" WHERE "fact_names"."id" IN (54, 119, 52, 15, 16, 70, 21, 94, 85, 7, 111, 66, 96, 4, 69, 80, 86, 27, 87, 22, 31, 2, 9, 41, 10, 44, 71, 25, 60, 93, 5, 83, 30, 58, 59, 100, 82, 63, 104, 36, 51, 109, 97, 72, 45, 3, 28, 12, 62, 110, 105, 47, 65, 88, 118, 61, 39, 102, 26, 78, 42, 64, 107, 18, 74, 57, 32, 55, 91) ORDER BY fact_names.name
Merging facts for 'og-rhel-7-x64-01.idm.lab.bos.redhat.com': added 0 facts
Merging facts for 'og-rhel-7-x64-01.idm.lab.bos.redhat.com': updated 5 facts
   (0.1ms)  BEGIN
   (0.4ms)  UPDATE "fact_values" SET "value" = '622.56 MB', "updated_at" = '2014-08-12 19:36:11.158685' WHERE "fact_values"."id" = 259
   (9.1ms)  COMMIT
   (0.1ms)  BEGIN
   (0.3ms)  UPDATE "fact_values" SET "value" = '622.56', "updated_at" = '2014-08-12 19:36:11.170078' WHERE "fact_values"."id" = 198
   (6.4ms)  COMMIT
   (0.1ms)  BEGIN
   (0.3ms)  UPDATE "fact_values" SET "value" = 'Tue Aug 12 15:36:10 -0400 2014', "updated_at" = '2014-08-12 19:36:11.178211' WHERE "fact_values"."id" = 230
   (6.8ms)  COMMIT
   (0.1ms)  BEGIN
   (0.3ms)  UPDATE "fact_values" SET "value" = '4:30 hours', "updated_at" = '2014-08-12 19:36:11.186700' WHERE "fact_values"."id" = 250
   (6.7ms)  COMMIT
   (0.1ms)  BEGIN
   (0.3ms)  UPDATE "fact_values" SET "value" = '16210', "updated_at" = '2014-08-12 19:36:11.195015' WHERE "fact_values"."id" = 251
   (6.7ms)  COMMIT
Import facts for 'og-rhel-7-x64-01.idm.lab.bos.redhat.com' completed. Added: 0, Updated: 5, Deleted 0 facts
   (0.1ms)  BEGIN
   (0.5ms)  UPDATE "hosts" SET "last_compile" = '2014-08-12 19:36:10.000000', "updated_at" = '2014-08-12 19:36:11.204098' WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."id" = 4
   (9.4ms)  COMMIT
  Model Load (0.3ms)  SELECT "models".* FROM "models" WHERE "models"."name" = 'KVM' ORDER BY models.name LIMIT 1
  Domain Load (0.3ms)  SELECT "domains".* FROM "domains" WHERE "domains"."name" = 'idm.lab.bos.redhat.com' ORDER BY domains.name LIMIT 1
  Architecture Load (0.2ms)  SELECT "architectures".* FROM "architectures" WHERE "architectures"."name" = 'x86_64' LIMIT 1
  Operatingsystem Load (0.3ms)  SELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."name" = 'RedHat' AND "operatingsystems"."major" = '7' AND "operatingsystems"."minor" = '0' ORDER BY operatingsystems.name LIMIT 1
   (0.1ms)  BEGIN
   (0.1ms)  COMMIT
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'update_environment_from_facts' ORDER BY name LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'default_puppet_environment' ORDER BY name LIMIT 1
  Environment Load (0.3ms)  SELECT "environments".* FROM "environments" WHERE "environments"."name" = 'production' ORDER BY environments.name LIMIT 1
  Environment Load (0.3ms)  SELECT "environments".* FROM "environments" WHERE "environments"."id" = 9 ORDER BY environments.name LIMIT 1
   (0.1ms)  BEGIN
   (0.1ms)  COMMIT
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'location_fact' ORDER BY name LIMIT 1
  Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'default_location' ORDER BY name LIMIT 1
  Location Load (0.3ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."title" = '' ORDER BY title LIMIT 1
  Location Load (0.4ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" = 2 ORDER BY title LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'organization_fact' ORDER BY name LIMIT 1
  Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'default_organization' ORDER BY name LIMIT 1
  Organization Load (0.3ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."title" = '' ORDER BY title LIMIT 1
  Organization Load (0.4ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" = 1 ORDER BY title LIMIT 1
   (0.1ms)  BEGIN
   (0.1ms)  COMMIT
  Hostgroup Load (0.4ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = 3 ORDER BY hostgroups.title LIMIT 1
Body: {"architecture_id":1,"build":false,"certname":"og-rhel-7-x64-01.idm.lab.bos.redhat.com","comment":"","compute_profile_id":null,"compute_resource_id":1,"content_source_id":1,"created_at":"2014-08-12T14:53:40Z","disk":"","domain_id":1,"enabled":true,"environment_id":9,"hostgroup_id":3,"id":4,"image_file":"","image_id":null,"installed_at":"2014-08-12T15:05:15Z","ip":"192.168.100.6","last_compile":"2014-08-12T19:36:10Z","last_freshcheck":null,"last_report":"2014-08-12T19:06:08Z","location_id":2,"mac":"52:54:00:9a:58:59","managed":true,"medium_id":11,"model_id":2,"name":"og-rhel-7-x64-01.idm.lab.bos.redhat.com","operatingsystem_id":3,"organization_id":1,"otp":null,"owner_id":3,"owner_type":"User","provision_method":"build","ptable_id":7,"puppet_ca_proxy_id":1,"puppet_proxy_id":1,"puppet_status":0,"realm_id":null,"root_pass":"$1$CcWBFFnR$1iIF9Wotujrqso5lqqFDF1","serial":null,"source_file_id":null,"subnet_id":1,"updated_at":"2014-08-12T19:36:11Z","use_image":null,"uuid":"431e05e4-ad3f-1889-6c58-2c94eacdd950"}
Completed 201 Created in 136ms (Views: 4.4ms | ActiveRecord: 0.4ms)
Processing by HostsController#externalNodes as YML
  Parameters: {"name"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com"}
  SmartProxy Load (0.7ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet', 'Chef Proxy') ORDER BY smart_proxies.name
Verifying request from ["cloud-qe-8.idm.lab.bos.redhat.com"] against ["cloud-qe-8.idm.lab.bos.redhat.com"]
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."login" = 'foreman_api_admin' LIMIT 1
Setting current user thread-local variable to API Admin
  Host::Managed Load (0.6ms)  SELECT "hosts".* FROM "hosts" WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."certname" = 'og-rhel-7-x64-01.idm.lab.bos.redhat.com' LIMIT 1
  SmartProxy Load (0.3ms)  SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 1 ORDER BY smart_proxies.name LIMIT 1
  Domain Load (0.5ms)  SELECT "domains".* FROM "domains" WHERE "domains"."id" = 1 ORDER BY domains.name LIMIT 1
  Hostgroup Load (0.4ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" = 3 ORDER BY hostgroups.title LIMIT 1
  Location Load (0.3ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" = 2 ORDER BY title LIMIT 1
  Organization Load (0.3ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" = 1 ORDER BY title LIMIT 1
  CACHE (0.0ms)  SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 1 ORDER BY smart_proxies.name LIMIT 1
  Environment Load (0.3ms)  SELECT "environments".* FROM "environments" WHERE "environments"."id" = 9 ORDER BY environments.name LIMIT 1
  AuthSourceHidden Load (0.3ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."type" IN ('AuthSourceHidden')
  User Load (0.3ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 3 AND (1=1) AND (users.auth_source_id <> 2) LIMIT 1
  CommonParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('CommonParameter') ORDER BY parameters.name
  OrganizationParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OrganizationParameter') AND "parameters"."reference_id" = 1 ORDER BY parameters.name
  LocationParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('LocationParameter') AND "parameters"."reference_id" = 2 ORDER BY parameters.name
  DomainParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('DomainParameter') AND "parameters"."reference_id" = 1 ORDER BY parameters.name
  Operatingsystem Load (0.2ms)  SELECT "operatingsystems".* FROM "operatingsystems" WHERE "operatingsystems"."id" = 3 ORDER BY operatingsystems.name LIMIT 1
  OsParameter Load (0.2ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('OsParameter') AND "parameters"."reference_id" = 3 ORDER BY parameters.name
  GroupParameter Load (0.2ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('GroupParameter') AND "parameters"."reference_id" = 3 ORDER BY parameters.name
  HostParameter Load (0.2ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('HostParameter') AND "parameters"."reference_id" = 4 ORDER BY parameters.name
   (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" = 4 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
  Hostgroup Load (0.3ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
   (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" = 3 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
   (0.1ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
   (0.2ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3)
   (0.1ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" = 4
   (0.2ms)  SELECT DISTINCT puppetclasses.id FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 9 AND "puppetclasses"."id" IN (1)
  LookupKey Load (0.2ms)  SELECT "lookup_keys".* FROM "lookup_keys" WHERE "lookup_keys"."puppetclass_id" IN (1) ORDER BY lookup_keys.key
  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" = 4 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
  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" = 3 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" = 4
  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" = 9 AND "puppetclasses"."id" IN (1)
  SQL (0.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"."is_param" AS t0_r10, "lookup_keys"."key_type" AS t0_r11, "lookup_keys"."override" AS t0_r12, "lookup_keys"."required" AS t0_r13, "lookup_keys"."lookup_values_count" AS t0_r14, "environment_classes"."id" AS t1_r0, "environment_classes"."puppetclass_id" AS t1_r1, "environment_classes"."environment_id" AS t1_r2, "environment_classes"."lookup_key_id" AS t1_r3 FROM "lookup_keys" INNER JOIN "environment_classes" ON "environment_classes"."lookup_key_id" = "lookup_keys"."id" WHERE "lookup_keys"."override" = 't' AND "environment_classes"."puppetclass_id" IN (1) AND "environment_classes"."environment_id" = 9 ORDER BY lookup_keys.key
  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" = 4 AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE "hostgroups"."id" IN (3) ORDER BY (case when hostgroups.ancestry is null then 0 else 1 end), hostgroups.ancestry
  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" = 3 AND "host_config_groups"."host_type" = 'Hostgroup' ORDER BY config_groups.name
  CACHE (0.0ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IN (3)
  CACHE (0.0ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" = 4
  Puppetclass Load (0.5ms)  SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 9 AND "puppetclasses"."id" IN (1) ORDER BY puppetclasses.name
  Rendered text template (0.0ms)
Completed 200 OK in 213ms (Views: 0.6ms | ActiveRecord: 9.3ms)

==> /var/log/messages <==
Aug 12 15:36:11 cloud-qe-8 puppet-master[28057]: Compiled catalog for og-rhel-7-x64-01.idm.lab.bos.redhat.com in environment KT_Default_Organization_DEV_RHEL_7_x86_64_4 in 0.01 seconds

==> /var/log/foreman/production.log <==
Processing by Api::V2::ReportsController#create as JSON
  Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
  SmartProxy Load (0.7ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet', 'Chef Proxy') ORDER BY smart_proxies.name
Verifying request from ["cloud-qe-8.idm.lab.bos.redhat.com"] against ["cloud-qe-8.idm.lab.bos.redhat.com"]
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."login" = 'foreman_api_admin' LIMIT 1
Setting current user thread-local variable to API Admin
processing report for og-rhel-7-x64-01.idm.lab.bos.redhat.com
Report: {"metrics"=>{"events"=>{"success"=>0, "failure"=>0, "total"=>0}, "time"=>{"schedule"=>0.00046449, "filebucket"=>0.000136965, "config_retrieval"=>0.823262897, "file"=>0.001239565, "total"=>0.825103917}, "resources"=>{"skipped"=>0, "scheduled"=>0, "failed_to_restart"=>0, "failed"=>0, "changed"=>0, "out_of_sync"=>0, "total"=>8, "restarted"=>0}, "changes"=>{"total"=>0}}, "reported_at"=>"2014-08-12 19:36:08 UTC", "host"=>"og-rhel-7-x64-01.idm.lab.bos.redhat.com", "logs"=>[], "status"=>{"skipped"=>0, "failed"=>0, "applied"=>0, "failed_restarts"=>0, "pending"=>0, "restarted"=>0}}
  Host::Base Load (0.5ms)  SELECT "hosts".* FROM "hosts" WHERE "hosts"."certname" = 'og-rhel-7-x64-01.idm.lab.bos.redhat.com' LIMIT 1
   (0.1ms)  BEGIN
   (0.8ms)  UPDATE "hosts" SET "last_report" = '2014-08-12 19:36:08.000000', "updated_at" = '2014-08-12 19:36:11.904755' WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."id" = 4
   (11.9ms)  COMMIT
   (0.1ms)  BEGIN
  Report Exists (0.3ms)  SELECT 1 AS one FROM "reports" WHERE ("reports"."reported_at" = '2014-08-12 19:36:08.000000' AND "reports"."host_id" = 4) LIMIT 1
  SQL (0.7ms)  INSERT INTO "reports" ("created_at", "host_id", "metrics", "reported_at", "status", "updated_at") VALUES ($1, $2, $3, $4, $5, $6) RETURNING "id"  [["created_at", Tue, 12 Aug 2014 19:36:11 UTC +00:00], ["host_id", 4], ["metrics", "--- !ruby/hash:ActionController::Parameters\nevents: !ruby/hash:ActiveSupport::HashWithIndifferentAccess\n  success: 0\n  failure: 0\n  total: 0\ntime: !ruby/hash:ActiveSupport::HashWithIndifferentAccess\n  schedule: 0.00046449\n  filebucket: 0.000136965\n  config_retrieval: 0.823262897\n  file: 0.001239565\n  total: 0.825103917\nresources: !ruby/hash:ActiveSupport::HashWithIndifferentAccess\n  skipped: 0\n  scheduled: 0\n  failed_to_restart: 0\n  failed: 0\n  changed: 0\n  out_of_sync: 0\n  total: 8\n  restarted: 0\nchanges: !ruby/hash:ActiveSupport::HashWithIndifferentAccess\n  total: 0\n"], ["reported_at", Tue, 12 Aug 2014 19:36:08 UTC +00:00], ["status", 0], ["updated_at", Tue, 12 Aug 2014 19:36:11 UTC +00:00]]
   (8.8ms)  COMMIT
Imported report for og-rhel-7-x64-01.idm.lab.bos.redhat.com in 0.04 seconds
Body: {"created_at":"2014-08-12T19:36:11Z","host_id":4,"id":249,"metrics":{"events":{"success":0,"failure":0,"total":0},"time":{"schedule":0.00046449,"filebucket":0.000136965,"config_retrieval":0.823262897,"file":0.001239565,"total":0.825103917},"resources":{"skipped":0,"scheduled":0,"failed_to_restart":0,"failed":0,"changed":0,"out_of_sync":0,"total":8,"restarted":0},"changes":{"total":0}},"reported_at":"2014-08-12T19:36:08Z","status":{"applied":0,"restarted":0,"failed":0,"failed_restarts":0,"skipped":0,"pending":0},"updated_at":"2014-08-12T19:36:11Z"}
Completed 201 Created in 48ms (Views: 2.7ms | ActiveRecord: 0.0ms)

Comment 3 Tom McKay 2014-08-12 21:04:02 UTC
The root error seen here is in the related subscription-manager bug. Given that, there does still exist the problem that no error message is displayed to the user.

Comment 4 John Sefler 2014-08-14 18:44:02 UTC
Additional Info....
I also observed a silent failure when attempting a simple register from subscription-manager with invalid credentials (expected something like "Invalid Credentials")...

[root@jsefler-6 ~]# rpm -q subscription-manager
subscription-manager-1.12.10-1.el6.x86_64
[root@jsefler-6 ~]# subscription-manager register --username=foo --password=bar
[root@jsefler-6 ~]# echo $?
255
[root@jsefler-6 ~]#


[root@jsefler-6 ~]# tail -f /var/log/rhsm/rhsm.log
2014-08-14 14:29:30,867 [DEBUG] subscription-manager @connection.py:446 - Making request: GET /rhsm/users/foo/owners
2014-08-14 14:29:30,984 [DEBUG] subscription-manager @connection.py:469 - Response: status=401
2014-08-14 14:29:30,988 [ERROR] subscription-manager @managercli.py:1049 - 
Traceback (most recent call last):
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 1035, in _do_command
    owner_key = self._determine_owner_key(admin_cp)
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 1172, in _determine_owner_key
    owners = cp.getOwnerList(self.username)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 911, in getOwnerList
    return self.conn.request_get(method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 550, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 478, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 520, in validateResponse
    raise RestlibException(response['status'], error_msg)
RestlibException

Comment 5 Carter Kozak 2014-08-19 13:09:09 UTC
The prior part of this bug is a duplicate of bz 1129480.  The latter (no output when bad auth is given) appears to be a sam bug.

When I try to register against a candlepin server with environments with bad auth, I get:

# subman register --username=foo --password=bar
Invalid Credentials

# echo $?
255

Comment 8 Tom McKay 2014-08-19 17:44:05 UTC
Created redmine issue http://projects.theforeman.org/issues/7155 from this bug

Comment 9 Og Maciel 2014-08-27 15:01:25 UTC
fwiw I have tested registering the following OS x arch against latest build for Satellite 6: RHEL 5.7-5.10, 6.4-7.0 ppc64, s390x, x86_64 and i386.

RHEL 6.6 is the only one that shows this issue. RHEL 5.7 fails but due to a different issue (--org is not supported).

Comment 10 Og Maciel 2014-09-02 18:30:35 UTC
Moving this issue over to RHEL 6 (sub-man component) as it only seems to happen when using subscription-manager on RHEL 6.6 to subscribe to a Satellite 6 instance using an activation key.

Comment 12 John Sefler 2014-09-09 17:04:04 UTC
Decided to close this bug as a duplicate of bug 1129480
Decided to open comment 4 and comment 5 under new bug 1139811

*** This bug has been marked as a duplicate of bug 1129480 ***


Note You need to log in before you can comment on or make changes to this bug.