development.log

2016-01-05 10:07:50 [I] Connecting to database specified by database.yml
2016-01-05 10:08:01 [D]   Setting::General Load (1.5ms)  SELECT "settings".* FROM "settings" WHERE "settings"."category" IN ('Setting::General') AND "settings"."name" = 'fix_db_cache' ORDER BY name LIMIT 1
2016-01-05 10:08:01 [D]   Setting Load (0.6ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:01 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:01 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'discovery_fact' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.7ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'discovery_fact' AND "settings"."id" != 2) LIMIT 1
2016-01-05 10:08:02 [D] removing discovery_fact from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'discovery_auto' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'discovery_auto' AND "settings"."id" != 3) LIMIT 1
2016-01-05 10:08:02 [D] removing discovery_auto from cache
2016-01-05 10:08:02 [D]    (0.2ms)  COMMIT
2016-01-05 10:08:02 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'discovery_prefix' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'discovery_prefix' AND "settings"."id" != 4) LIMIT 1
2016-01-05 10:08:02 [D] removing discovery_prefix from cache
2016-01-05 10:08:02 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:02 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'discovery_fact_column' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'discovery_fact_column' AND "settings"."id" != 5) LIMIT 1
2016-01-05 10:08:02 [D] removing discovery_fact_column from cache
2016-01-05 10:08:02 [D]    (0.2ms)  COMMIT
2016-01-05 10:08:02 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'discovery_location' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'discovery_location' AND "settings"."id" != 6) LIMIT 1
2016-01-05 10:08:02 [D] removing discovery_location from cache
2016-01-05 10:08:02 [D]    (0.2ms)  COMMIT
2016-01-05 10:08:02 [D]    (0.2ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'discovery_organization' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'discovery_organization' AND "settings"."id" != 7) LIMIT 1
2016-01-05 10:08:02 [D] removing discovery_organization from cache
2016-01-05 10:08:02 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'dynflow_allow_dangerous_actions' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.5ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'dynflow_allow_dangerous_actions' AND "settings"."id" != 8) LIMIT 1
2016-01-05 10:08:02 [D] removing dynflow_allow_dangerous_actions from cache
2016-01-05 10:08:02 [D]   Setting Load (0.5ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'dynflow_enable_console' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'dynflow_enable_console' AND "settings"."id" != 9) LIMIT 1
2016-01-05 10:08:02 [D] removing dynflow_enable_console from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'dynflow_console_require_auth' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'dynflow_console_require_auth' AND "settings"."id" != 10) LIMIT 1
2016-01-05 10:08:02 [D] removing dynflow_console_require_auth from cache
2016-01-05 10:08:02 [D]    (0.2ms)  COMMIT
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'satellite_default_provision' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'satellite_default_provision' AND "settings"."id" != 11) LIMIT 1
2016-01-05 10:08:02 [D] removing satellite_default_provision from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'satellite_default_finish' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'satellite_default_finish' AND "settings"."id" != 12) LIMIT 1
2016-01-05 10:08:02 [D] removing satellite_default_finish from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'satellite_default_user_data' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'satellite_default_user_data' AND "settings"."id" != 13) LIMIT 1
2016-01-05 10:08:02 [D] removing satellite_default_user_data from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'satellite_default_PXELinux' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'satellite_default_PXELinux' AND "settings"."id" != 14) LIMIT 1
2016-01-05 10:08:02 [D] removing satellite_default_PXELinux from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'satellite_default_iPXE' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'satellite_default_iPXE' AND "settings"."id" != 15) LIMIT 1
2016-01-05 10:08:02 [D] removing satellite_default_iPXE from cache
2016-01-05 10:08:02 [D]   Setting Load (0.5ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'satellite_default_ptable' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'satellite_default_ptable' AND "settings"."id" != 16) LIMIT 1
2016-01-05 10:08:02 [D] removing satellite_default_ptable from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'content_action_accept_timeout' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'content_action_accept_timeout' AND "settings"."id" != 17) LIMIT 1
2016-01-05 10:08:02 [D] removing content_action_accept_timeout from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'content_action_finish_timeout' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'content_action_finish_timeout' AND "settings"."id" != 18) LIMIT 1
2016-01-05 10:08:02 [D] removing content_action_finish_timeout from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'pulp_sync_node_action_accept_timeout' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'pulp_sync_node_action_accept_timeout' AND "settings"."id" != 19) LIMIT 1
2016-01-05 10:08:02 [D] removing pulp_sync_node_action_accept_timeout from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'pulp_sync_node_action_finish_timeout' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'pulp_sync_node_action_finish_timeout' AND "settings"."id" != 20) LIMIT 1
2016-01-05 10:08:02 [D] removing pulp_sync_node_action_finish_timeout from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'check_services_before_actions' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'check_services_before_actions' AND "settings"."id" != 21) LIMIT 1
2016-01-05 10:08:02 [D] removing check_services_before_actions from cache
2016-01-05 10:08:02 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]    (0.2ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'administrator' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'administrator' AND "settings"."id" != 22) LIMIT 1
2016-01-05 10:08:02 [D] removing administrator from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'foreman_url' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'foreman_url' AND "settings"."id" != 23) LIMIT 1
2016-01-05 10:08:02 [D] removing foreman_url from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'email_reply_address' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'email_reply_address' AND "settings"."id" != 24) LIMIT 1
2016-01-05 10:08:02 [D] removing email_reply_address from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'email_subject_prefix' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'email_subject_prefix' AND "settings"."id" != 25) LIMIT 1
2016-01-05 10:08:02 [D] removing email_subject_prefix from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'send_welcome_email' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'send_welcome_email' AND "settings"."id" != 26) LIMIT 1
2016-01-05 10:08:02 [D] removing send_welcome_email from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'entries_per_page' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'entries_per_page' AND "settings"."id" != 27) LIMIT 1
2016-01-05 10:08:02 [D] removing entries_per_page from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'fix_db_cache' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'fix_db_cache' AND "settings"."id" != 1) LIMIT 1
2016-01-05 10:08:02 [D] removing fix_db_cache from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'authorize_login_delegation' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (1.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'authorize_login_delegation' AND "settings"."id" != 28) LIMIT 1
2016-01-05 10:08:02 [D] removing authorize_login_delegation from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'authorize_login_delegation_api' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (5.8ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'authorize_login_delegation_api' AND "settings"."id" != 29) LIMIT 1
2016-01-05 10:08:02 [D] removing authorize_login_delegation_api from cache
2016-01-05 10:08:02 [D]   Setting Load (5.9ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'idle_timeout' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'idle_timeout' AND "settings"."id" != 30) LIMIT 1
2016-01-05 10:08:02 [D] removing idle_timeout from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'max_trend' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'max_trend' AND "settings"."id" != 31) LIMIT 1
2016-01-05 10:08:02 [D] removing max_trend from cache
2016-01-05 10:08:02 [D]   Setting Load (0.5ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'use_gravatar' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.5ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'use_gravatar' AND "settings"."id" != 32) LIMIT 1
2016-01-05 10:08:02 [D] removing use_gravatar from cache
2016-01-05 10:08:02 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'db_pending_migration' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'db_pending_migration' AND "settings"."id" != 33) LIMIT 1
2016-01-05 10:08:02 [D] removing db_pending_migration from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'db_pending_seed' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'db_pending_seed' AND "settings"."id" != 34) LIMIT 1
2016-01-05 10:08:02 [D] removing db_pending_seed from cache
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'proxy_request_timeout' ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'proxy_request_timeout' AND "settings"."id" != 35) LIMIT 1
2016-01-05 10:08:02 [D] removing proxy_request_timeout from cache
2016-01-05 10:08:02 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:02 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:02 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'oauth_active' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.5ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'oauth_active' AND "settings"."id" != 36) LIMIT 1
2016-01-05 10:08:03 [D] removing oauth_active from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'oauth_consumer_key' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'oauth_consumer_key' AND "settings"."id" != 37) LIMIT 1
2016-01-05 10:08:03 [D] removing oauth_consumer_key from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'oauth_consumer_secret' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'oauth_consumer_secret' AND "settings"."id" != 38) LIMIT 1
2016-01-05 10:08:03 [D] removing oauth_consumer_secret from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'oauth_map_users' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'oauth_map_users' AND "settings"."id" != 39) LIMIT 1
2016-01-05 10:08:03 [D] removing oauth_map_users from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'restrict_registered_puppetmasters' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'restrict_registered_puppetmasters' AND "settings"."id" != 40) LIMIT 1
2016-01-05 10:08:03 [D] removing restrict_registered_puppetmasters from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'require_ssl_puppetmasters' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'require_ssl_puppetmasters' AND "settings"."id" != 41) LIMIT 1
2016-01-05 10:08:03 [D] removing require_ssl_puppetmasters from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'trusted_puppetmaster_hosts' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'trusted_puppetmaster_hosts' AND "settings"."id" != 42) LIMIT 1
2016-01-05 10:08:03 [D] removing trusted_puppetmaster_hosts from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_client_dn_env' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'ssl_client_dn_env' AND "settings"."id" != 43) LIMIT 1
2016-01-05 10:08:03 [D] removing ssl_client_dn_env from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_client_verify_env' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'ssl_client_verify_env' AND "settings"."id" != 44) LIMIT 1
2016-01-05 10:08:03 [D] removing ssl_client_verify_env from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'login_delegation_logout_url' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'login_delegation_logout_url' AND "settings"."id" != 45) LIMIT 1
2016-01-05 10:08:03 [D] removing login_delegation_logout_url from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'authorize_login_delegation_auth_source_user_autocreate' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'authorize_login_delegation_auth_source_user_autocreate' AND "settings"."id" != 46) LIMIT 1
2016-01-05 10:08:03 [D] removing authorize_login_delegation_auth_source_user_autocreate from cache
2016-01-05 10:08:03 [D]    (0.2ms)  COMMIT
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'puppet_interval' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'puppet_interval' AND "settings"."id" != 47) LIMIT 1
2016-01-05 10:08:03 [D] removing puppet_interval from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'default_puppet_environment' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'default_puppet_environment' AND "settings"."id" != 48) LIMIT 1
2016-01-05 10:08:03 [D] removing default_puppet_environment from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'modulepath' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'modulepath' AND "settings"."id" != 49) LIMIT 1
2016-01-05 10:08:03 [D] removing modulepath from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'document_root' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'document_root' AND "settings"."id" != 50) LIMIT 1
2016-01-05 10:08:03 [D] removing document_root from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'puppetrun' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'puppetrun' AND "settings"."id" != 51) LIMIT 1
2016-01-05 10:08:03 [D] removing puppetrun from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'puppet_server' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'puppet_server' AND "settings"."id" != 52) LIMIT 1
2016-01-05 10:08:03 [D] removing puppet_server from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'Default_variables_Lookup_Path' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'Default_variables_Lookup_Path' AND "settings"."id" != 53) LIMIT 1
2016-01-05 10:08:03 [D] removing Default_variables_Lookup_Path from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'Enable_Smart_Variables_in_ENC' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'Enable_Smart_Variables_in_ENC' AND "settings"."id" != 54) LIMIT 1
2016-01-05 10:08:03 [D] removing Enable_Smart_Variables_in_ENC from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'Parametrized_Classes_in_ENC' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'Parametrized_Classes_in_ENC' AND "settings"."id" != 55) LIMIT 1
2016-01-05 10:08:03 [D] removing Parametrized_Classes_in_ENC from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'interpolate_erb_in_parameters' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'interpolate_erb_in_parameters' AND "settings"."id" != 56) LIMIT 1
2016-01-05 10:08:03 [D] removing interpolate_erb_in_parameters from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'enc_environment' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'enc_environment' AND "settings"."id" != 57) LIMIT 1
2016-01-05 10:08:03 [D] removing enc_environment from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'use_uuid_for_certificates' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'use_uuid_for_certificates' AND "settings"."id" != 58) LIMIT 1
2016-01-05 10:08:03 [D] removing use_uuid_for_certificates from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'update_environment_from_facts' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'update_environment_from_facts' AND "settings"."id" != 59) LIMIT 1
2016-01-05 10:08:03 [D] removing update_environment_from_facts from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'host_group_matchers_inheritance' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'host_group_matchers_inheritance' AND "settings"."id" != 60) LIMIT 1
2016-01-05 10:08:03 [D] removing host_group_matchers_inheritance from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'create_new_host_when_facts_are_uploaded' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'create_new_host_when_facts_are_uploaded' AND "settings"."id" != 61) LIMIT 1
2016-01-05 10:08:03 [D] removing create_new_host_when_facts_are_uploaded from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'create_new_host_when_report_is_uploaded' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'create_new_host_when_report_is_uploaded' AND "settings"."id" != 62) LIMIT 1
2016-01-05 10:08:03 [D] removing create_new_host_when_report_is_uploaded from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'legacy_puppet_hostname' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'legacy_puppet_hostname' AND "settings"."id" != 63) LIMIT 1
2016-01-05 10:08:03 [D] removing legacy_puppet_hostname from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'location_fact' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'location_fact' AND "settings"."id" != 64) LIMIT 1
2016-01-05 10:08:03 [D] removing location_fact from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'organization_fact' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'organization_fact' AND "settings"."id" != 65) LIMIT 1
2016-01-05 10:08:03 [D] removing organization_fact from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'default_location' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'default_location' AND "settings"."id" != 66) LIMIT 1
2016-01-05 10:08:03 [D] removing default_location from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'default_organization' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'default_organization' AND "settings"."id" != 67) LIMIT 1
2016-01-05 10:08:03 [D] removing default_organization from cache
2016-01-05 10:08:03 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'root_pass' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.4ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'root_pass' AND "settings"."id" != 68) LIMIT 1
2016-01-05 10:08:03 [D] removing root_pass from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'unattended_url' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'unattended_url' AND "settings"."id" != 69) LIMIT 1
2016-01-05 10:08:03 [D] removing unattended_url from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'safemode_render' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'safemode_render' AND "settings"."id" != 70) LIMIT 1
2016-01-05 10:08:03 [D] removing safemode_render from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_certificate' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'ssl_certificate' AND "settings"."id" != 71) LIMIT 1
2016-01-05 10:08:03 [D] removing ssl_certificate from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_ca_file' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'ssl_ca_file' AND "settings"."id" != 72) LIMIT 1
2016-01-05 10:08:03 [D] removing ssl_ca_file from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ssl_priv_key' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'ssl_priv_key' AND "settings"."id" != 73) LIMIT 1
2016-01-05 10:08:03 [D] removing ssl_priv_key from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'manage_puppetca' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'manage_puppetca' AND "settings"."id" != 74) LIMIT 1
2016-01-05 10:08:03 [D] removing manage_puppetca from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'ignore_puppet_facts_for_provisioning' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'ignore_puppet_facts_for_provisioning' AND "settings"."id" != 75) LIMIT 1
2016-01-05 10:08:03 [D] removing ignore_puppet_facts_for_provisioning from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'query_local_nameservers' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'query_local_nameservers' AND "settings"."id" != 76) LIMIT 1
2016-01-05 10:08:03 [D] removing query_local_nameservers from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'remote_addr' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'remote_addr' AND "settings"."id" != 77) LIMIT 1
2016-01-05 10:08:03 [D] removing remote_addr from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'token_duration' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'token_duration' AND "settings"."id" != 78) LIMIT 1
2016-01-05 10:08:03 [D] removing token_duration from cache
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'libvirt_default_console_address' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'libvirt_default_console_address' AND "settings"."id" != 79) LIMIT 1
2016-01-05 10:08:03 [D] removing libvirt_default_console_address from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'update_ip_from_built_request' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'update_ip_from_built_request' AND "settings"."id" != 80) LIMIT 1
2016-01-05 10:08:03 [D] removing update_ip_from_built_request from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'use_shortname_for_vms' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'use_shortname_for_vms' AND "settings"."id" != 81) LIMIT 1
2016-01-05 10:08:03 [D] removing use_shortname_for_vms from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'websockets_encrypt' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'websockets_encrypt' AND "settings"."id" != 82) LIMIT 1
2016-01-05 10:08:03 [D] removing websockets_encrypt from cache
2016-01-05 10:08:03 [D]   Setting Load (0.3ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'websockets_ssl_key' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'websockets_ssl_key' AND "settings"."id" != 83) LIMIT 1
2016-01-05 10:08:03 [D] removing websockets_ssl_key from cache
2016-01-05 10:08:03 [D]    (0.7ms)  UPDATE "settings" SET "description" = 'Private key that Foreman will use to encrypt websockets', "updated_at" = '2016-01-05 15:08:03.341973' WHERE "settings"."category" IN ('Setting::Provisioning') AND "settings"."id" = 83
2016-01-05 10:08:03 [D]   Setting Load (0.4ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'websockets_ssl_cert' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   Setting Exists (0.3ms)  SELECT 1 AS one FROM "settings" WHERE ("settings"."name" = 'websockets_ssl_cert' AND "settings"."id" != 84) LIMIT 1
2016-01-05 10:08:03 [D] removing websockets_ssl_cert from cache
2016-01-05 10:08:03 [D]    (0.3ms)  UPDATE "settings" SET "description" = 'Certificate that Foreman will use to encrypt websockets', "updated_at" = '2016-01-05 15:08:03.356101' WHERE "settings"."category" IN ('Setting::Provisioning') AND "settings"."id" = 84
2016-01-05 10:08:03 [D]    (13.7ms)  COMMIT
2016-01-05 10:08:03 [D]   Setting Load (0.5ms)  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'entries_per_page' ORDER BY name LIMIT 1
2016-01-05 10:08:03 [D]   SQL (0.9ms)  SELECT "users"."id" FROM "users" 
2016-01-05 10:08:06 [W] Creating scope :no_location. Overwriting existing method Host::Managed.no_location.
2016-01-05 10:08:06 [W] Creating scope :no_organization. Overwriting existing method Host::Managed.no_organization.
2016-01-05 10:08:10 [W] Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
2016-01-05 10:08:10 [W] Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
2016-01-05 10:08:12 [D]   Feature Load (0.4ms)  SELECT "features".* FROM "features" 
2016-01-05 10:08:13 [D]    (0.7ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.7ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_discovered_hosts' AND "permissions"."resource_type" = 'Host' LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'provision_discovered_hosts' AND "permissions"."resource_type" = 'Host' LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_discovered_hosts' AND "permissions"."resource_type" = 'Host' LIMIT 1
2016-01-05 10:08:13 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_discovered_hosts' AND "permissions"."resource_type" = 'Host' LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_discovery_rules' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.6ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'new_discovery_rules' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.5ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_discovery_rules' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'execute_discovery_rules' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:13 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'delete_discovery_rules' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:13 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:13 [D]    (0.2ms)  BEGIN
2016-01-05 10:08:13 [D]   Role Load (0.5ms)  SELECT "roles".* FROM "roles" WHERE "roles"."name" = 'Discovery Manager' LIMIT 1
2016-01-05 10:08:14 [D]    (1.4ms)  SELECT COUNT(*) FROM "permissions" INNER JOIN "filterings" ON "permissions"."id" = "filterings"."permission_id" INNER JOIN "filters" ON "filterings"."filter_id" = "filters"."id" WHERE "filters"."role_id" = 1
2016-01-05 10:08:14 [D]    (0.2ms)  COMMIT
2016-01-05 10:08:14 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:14 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:14 [D]   Role Load (0.3ms)  SELECT "roles".* FROM "roles" WHERE "roles"."name" = 'Discovery Reader' LIMIT 1
2016-01-05 10:08:14 [D]    (0.9ms)  SELECT COUNT(*) FROM "permissions" INNER JOIN "filterings" ON "permissions"."id" = "filterings"."permission_id" INNER JOIN "filters" ON "filterings"."filter_id" = "filters"."id" WHERE "filters"."role_id" = 2
2016-01-05 10:08:14 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:14 [W] fusor_server has added '["api/v21/foreman_tasks"]' to 'Katello.config.logging.ignored_paths': ["/notices/get_new", "/assets/", "/api/tasks/bulk_search", "api/v21/foreman_tasks"]
2016-01-05 10:08:14 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:14 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_fusor_deployments' AND "permissions"."resource_type" = 'Fusor::Deployment' LIMIT 1
2016-01-05 10:08:14 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:14 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_fusor_deployments' AND "permissions"."resource_type" = 'Fusor::Deployment' LIMIT 1
2016-01-05 10:08:14 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:14 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_fusor_deployments' AND "permissions"."resource_type" = 'Fusor::Deployment' LIMIT 1
2016-01-05 10:08:14 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:14 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_fusor_deployments' AND "permissions"."resource_type" = 'Fusor::Deployment' LIMIT 1
2016-01-05 10:08:14 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:14 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_fusor_deployments' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:14 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:14 [D]   Permission Exists (0.3ms)  SELECT 1 AS one FROM "permissions" WHERE "permissions"."name" = 'view_fusor_deployments' LIMIT 1
2016-01-05 10:08:16 [D]    (0.3ms)  ROLLBACK
2016-01-05 10:08:16 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:16 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'rename_discovered_hosts' AND "permissions"."resource_type" = '::Host::Discovered' LIMIT 1
2016-01-05 10:08:16 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:16 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_foreman_tasks' AND "permissions"."resource_type" = 'ForemanTasks::Task' LIMIT 1
2016-01-05 10:08:16 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:16 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_foreman_tasks' AND "permissions"."resource_type" = 'ForemanTasks::Task' LIMIT 1
2016-01-05 10:08:16 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:16 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:16 [D]   Role Load (0.3ms)  SELECT "roles".* FROM "roles" WHERE "roles"."name" = 'Tasks Manager' LIMIT 1
2016-01-05 10:08:16 [D]    (0.8ms)  SELECT COUNT(*) FROM "permissions" INNER JOIN "filterings" ON "permissions"."id" = "filterings"."permission_id" INNER JOIN "filters" ON "filterings"."filter_id" = "filters"."id" WHERE "filters"."role_id" = 3
2016-01-05 10:08:16 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:16 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:16 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:16 [D]   Role Load (0.3ms)  SELECT "roles".* FROM "roles" WHERE "roles"."name" = 'Tasks Reader' LIMIT 1
2016-01-05 10:08:16 [D]    (0.9ms)  SELECT COUNT(*) FROM "permissions" INNER JOIN "filterings" ON "permissions"."id" = "filterings"."permission_id" INNER JOIN "filters" ON "filterings"."filter_id" = "filters"."id" WHERE "filters"."role_id" = 4
2016-01-05 10:08:16 [D]    (0.1ms)  COMMIT
2016-01-05 10:08:16 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:16 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_content_reports' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:21 [D]    (0.6ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.9ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_containers' AND "permissions"."resource_type" = 'Container' LIMIT 1
2016-01-05 10:08:21 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'commit_containers' AND "permissions"."resource_type" = 'Container' LIMIT 1
2016-01-05 10:08:21 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_containers' AND "permissions"."resource_type" = 'Container' LIMIT 1
2016-01-05 10:08:21 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_containers' AND "permissions"."resource_type" = 'Container' LIMIT 1
2016-01-05 10:08:21 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'power_compute_resources_vms' AND "permissions"."resource_type" = 'ComputeResource' LIMIT 1
2016-01-05 10:08:21 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_registries' AND "permissions"."resource_type" = 'DockerRegistry' LIMIT 1
2016-01-05 10:08:21 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_registries' AND "permissions"."resource_type" = 'DockerRegistry' LIMIT 1
2016-01-05 10:08:21 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_registries' AND "permissions"."resource_type" = 'DockerRegistry' LIMIT 1
2016-01-05 10:08:21 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:21 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'search_repository_image_search' AND "permissions"."resource_type" = 'Docker/ImageSearch' LIMIT 1
2016-01-05 10:08:21 [E] Abnormal execution plans, process was probably killed.
Following ExecutionPlans will be set to paused, 
it should be fixed manually by administrator.
                       ExecutionPlan      state     result
128bbb13-46a9-4e4e-a26a-ab0569582e63    running    pending
2016-01-05 10:08:21 [D] ExecutionPlan 128bbb13-46a9-4e4e-a26a-ab0569582e63      running >>    paused
2016-01-05 10:08:21 [D]   ForemanTasks::Task::DynflowTask Load (0.5ms)  SELECT "foreman_tasks_tasks".* FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."external_id" = '128bbb13-46a9-4e4e-a26a-ab0569582e63' LIMIT 1
2016-01-05 10:08:21 [D]    (0.3ms)  BEGIN
2016-01-05 10:08:21 [D]    (0.5ms)  UPDATE "foreman_tasks_tasks" SET "state" = 'paused' WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."id" = '77d43ec1-217a-4ed8-94d0-ae0718ff5b5e'
2016-01-05 10:08:21 [D]    (10.6ms)  COMMIT
2016-01-05 10:08:21 [D]   ForemanTasks::Task::DynflowTask Load (0.8ms)  SELECT "foreman_tasks_tasks".* FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND (state NOT IN ('stopped', 'paused'))
2016-01-05 10:08:21 [D] ExecutionPlan 22f73e6e-0282-4d43-8506-50c7b55fb3af      pending >>  planning
2016-01-05 10:08:21 [D]    (0.3ms)  BEGIN
2016-01-05 10:08:21 [D]   SQL (1.1ms)  INSERT INTO "foreman_tasks_tasks" ("ended_at", "external_id", "id", "label", "parent_task_id", "result", "started_at", "state", "type") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9) RETURNING "id"  [["ended_at", nil], ["external_id", "22f73e6e-0282-4d43-8506-50c7b55fb3af"], ["id", "6f5980ac-1443-436e-bae3-1f981cc4a27a"], ["label", "Actions::Candlepin::ListenOnCandlepinEvents"], ["parent_task_id", nil], ["result", "pending"], ["started_at", Tue, 05 Jan 2016 15:08:21 UTC +00:00], ["state", "planning"], ["type", "ForemanTasks::Task::DynflowTask"]]
2016-01-05 10:08:21 [D]    (6.5ms)  COMMIT
2016-01-05 10:08:21 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:21 [D]          Step 22f73e6e-0282-4d43-8506-50c7b55fb3af: 1   pending >>   running in phase     Plan Actions::Candlepin::ListenOnCandlepinEvents
2016-01-05 10:08:21 [D]    (0.6ms)  SELECT COUNT(*) FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."label" = 'Actions::Candlepin::ListenOnCandlepinEvents' AND (state NOT IN ('stopped', 'paused')) AND (external_id != '22f73e6e-0282-4d43-8506-50c7b55fb3af')
2016-01-05 10:08:21 [D]          Step 22f73e6e-0282-4d43-8506-50c7b55fb3af: 1   running >>   success in phase     Plan Actions::Candlepin::ListenOnCandlepinEvents
2016-01-05 10:08:21 [D]    (0.3ms)  COMMIT
2016-01-05 10:08:21 [D] ExecutionPlan 22f73e6e-0282-4d43-8506-50c7b55fb3af     planning >>   planned
2016-01-05 10:08:21 [D]   ForemanTasks::Task::DynflowTask Load (0.5ms)  SELECT "foreman_tasks_tasks".* FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."external_id" = '22f73e6e-0282-4d43-8506-50c7b55fb3af' LIMIT 1
2016-01-05 10:08:21 [D]    (0.3ms)  BEGIN
2016-01-05 10:08:21 [D]    (0.3ms)  UPDATE "foreman_tasks_tasks" SET "state" = 'planned' WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."id" = '6f5980ac-1443-436e-bae3-1f981cc4a27a'
2016-01-05 10:08:21 [D]    (6.1ms)  COMMIT
2016-01-05 10:08:21 [D] ExecutionPlan 22f73e6e-0282-4d43-8506-50c7b55fb3af      planned >>   running
2016-01-05 10:08:21 [D]   ForemanTasks::Task::DynflowTask Load (0.8ms)  SELECT "foreman_tasks_tasks".* FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."external_id" = '22f73e6e-0282-4d43-8506-50c7b55fb3af' LIMIT 1
2016-01-05 10:08:21 [D]    (0.1ms)  BEGIN
2016-01-05 10:08:21 [D]    (0.4ms)  UPDATE "foreman_tasks_tasks" SET "state" = 'running' WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."id" = '6f5980ac-1443-436e-bae3-1f981cc4a27a'
2016-01-05 10:08:21 [D]    (5.4ms)  COMMIT
2016-01-05 10:08:21 [D]   ForemanTasks::Task::DynflowTask Load (0.4ms)  SELECT "foreman_tasks_tasks".* FROM "foreman_tasks_tasks" WHERE "foreman_tasks_tasks"."type" IN ('ForemanTasks::Task::DynflowTask') AND "foreman_tasks_tasks"."external_id" = '22f73e6e-0282-4d43-8506-50c7b55fb3af' LIMIT 1
2016-01-05 10:08:22 [D]          Step 22f73e6e-0282-4d43-8506-50c7b55fb3af: 2   pending >>   running in phase      Run Actions::Candlepin::ListenOnCandlepinEvents
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.8ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_sync_plans' AND "permissions"."resource_type" = 'Katello::SyncPlan' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_sync_plans' AND "permissions"."resource_type" = 'Katello::SyncPlan' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_sync_plans' AND "permissions"."resource_type" = 'Katello::SyncPlan' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (2.5ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_sync_plans' AND "permissions"."resource_type" = 'Katello::SyncPlan' LIMIT 1
2016-01-05 10:08:22 [D]          Step 22f73e6e-0282-4d43-8506-50c7b55fb3af: 2   running >> suspended in phase      Run Actions::Candlepin::ListenOnCandlepinEvents
2016-01-05 10:08:22 [D]    (1.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_content_views' AND "permissions"."resource_type" = 'Katello::ContentView' LIMIT 1
2016-01-05 10:08:22 [D]    (0.5ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_content_views' AND "permissions"."resource_type" = 'Katello::ContentView' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.7ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_content_views' AND "permissions"."resource_type" = 'Katello::ContentView' LIMIT 1
2016-01-05 10:08:22 [D]    (0.9ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_content_views' AND "permissions"."resource_type" = 'Katello::ContentView' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (1.0ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'publish_content_views' AND "permissions"."resource_type" = 'Katello::ContentView' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'promote_or_remove_content_views' AND "permissions"."resource_type" = 'Katello::ContentView' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.5ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'my_organizations' AND "permissions"."resource_type" IS NULL LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_content_hosts' AND "permissions"."resource_type" = 'Katello::System' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_content_hosts' AND "permissions"."resource_type" = 'Katello::System' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_content_hosts' AND "permissions"."resource_type" = 'Katello::System' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_content_hosts' AND "permissions"."resource_type" = 'Katello::System' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'manage_capsule_content' AND "permissions"."resource_type" = 'SmartProxy' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_lifecycle_environments' AND "permissions"."resource_type" = 'Katello::KTEnvironment' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_lifecycle_environments' AND "permissions"."resource_type" = 'Katello::KTEnvironment' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_lifecycle_environments' AND "permissions"."resource_type" = 'Katello::KTEnvironment' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_lifecycle_environments' AND "permissions"."resource_type" = 'Katello::KTEnvironment' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'promote_or_remove_content_views_to_environments' AND "permissions"."resource_type" = 'Katello::KTEnvironment' LIMIT 1
2016-01-05 10:08:22 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_subscriptions' AND "permissions"."resource_type" = 'Organization' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'attach_subscriptions' AND "permissions"."resource_type" = 'Organization' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'unattach_subscriptions' AND "permissions"."resource_type" = 'Organization' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'import_manifest' AND "permissions"."resource_type" = 'Organization' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'delete_manifest' AND "permissions"."resource_type" = 'Organization' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_products' AND "permissions"."resource_type" = 'Katello::Product' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_products' AND "permissions"."resource_type" = 'Katello::Product' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_products' AND "permissions"."resource_type" = 'Katello::Product' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_products' AND "permissions"."resource_type" = 'Katello::Product' LIMIT 1
2016-01-05 10:08:22 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:22 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'sync_products' AND "permissions"."resource_type" = 'Katello::Product' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_activation_keys' AND "permissions"."resource_type" = 'Katello::ActivationKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_activation_keys' AND "permissions"."resource_type" = 'Katello::ActivationKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_activation_keys' AND "permissions"."resource_type" = 'Katello::ActivationKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_activation_keys' AND "permissions"."resource_type" = 'Katello::ActivationKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_host_collections' AND "permissions"."resource_type" = 'Katello::HostCollection' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_host_collections' AND "permissions"."resource_type" = 'Katello::HostCollection' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.3ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_host_collections' AND "permissions"."resource_type" = 'Katello::HostCollection' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_host_collections' AND "permissions"."resource_type" = 'Katello::HostCollection' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'view_gpg_keys' AND "permissions"."resource_type" = 'Katello::GpgKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'create_gpg_keys' AND "permissions"."resource_type" = 'Katello::GpgKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.4ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'edit_gpg_keys' AND "permissions"."resource_type" = 'Katello::GpgKey' LIMIT 1
2016-01-05 10:08:23 [D]    (0.3ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" 
2016-01-05 10:08:23 [D]   Permission Load (0.4ms)  SELECT "permissions".* FROM "permissions" WHERE "permissions"."name" = 'destroy_gpg_keys' AND "permissions"."resource_type" = 'Katello::GpgKey' LIMIT 1
2016-01-05 10:08:28 [D]          Step 22f73e6e-0282-4d43-8506-50c7b55fb3af: 2 got event Actions::Candlepin::ListenOnCandlepinEvents::Reconnect[message: initialized...have not connected yet]
2016-01-05 10:08:28 [D]          Step 22f73e6e-0282-4d43-8506-50c7b55fb3af: 2 suspended >>   running in phase      Run Actions::Candlepin::ListenOnCandlepinEvents