Bug 1372850

Summary: Redeploy leads to "Product ID \"69\" has already been registered with this activation key"
Product: Red Hat Quickstart Cloud Installer Reporter: Thom Carlin <tcarlin>
Component: Installation - SatelliteAssignee: Derek Whatley <dwhatley>
Status: CLOSED ERRATA QA Contact: Antonin Pagac <apagac>
Severity: medium Docs Contact: Julie <juwu>
Priority: unspecified    
Version: 1.0CC: apagac, bthurber, dwhatley, jmatthew, joden, juwu, qci-bugzillas
Target Milestone: ---Keywords: Reopened, Triaged
Target Release: 1.1   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-02-28 01:39:12 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Thom Carlin 2016-09-02 22:13:51 UTC
Description of problem:

Redeploy after content sync led to "Product ID \"69\" has already been registered with this activation key"

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

QCI-1.0-RHEL-7-20160901.5

How reproducible:

Uncertain, believe 100% for this *very* specific set of circumstances

Steps to Reproduce:
1. After steps in https://bugzilla.redhat.com/show_bug.cgi?id=1372847 are followed, watch Installation Progress

Actual results:

Failed to Configure host groups: Katello::Resources::Candlepin::ActivationKey: 400 Bad Request {"displayMessage":"Product ID \"69\" has already been registered with this activation key","requestUuid":"a8b9684b-db4e-45e8-9016-9838c5ea0ba7"} (POST /candlepin/activation_keys/40287c8156ebbbda0156ece857c90110/product/69)

Expected results:

Successful configuration, sync, and deployment

Additional info:

Backtrace:
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/abstract_response.rb:48:in `return!'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:230:in `process_result'
/opt/theforeman/tfm/root/usr/share/gems/gems/rbovirt-0.0.37.4/lib/restclient_ext/request.rb:50:in `block in transmit'
/opt/rh/rh-ruby22/root/usr/share/ruby/net/http.rb:853:in `start'
/opt/theforeman/tfm/root/usr/share/gems/gems/rbovirt-0.0.37.4/lib/restclient_ext/request.rb:44:in `transmit'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:67:in `post'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.73/app/lib/katello/http_resource.rb:98:in `post'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.73/app/lib/katello/resources/candlepin.rb:765:in `add_product'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.73/app/models/katello/glue/candlepin/activation_key.rb:77:in `add_custom_product'
/opt/theforeman/tfm/root/usr/share/gems/gems/fusor_server-1.0.12/app/lib/actions/fusor/activation_key/add_subscriptions.rb:53:in `block in associate_subscriptions'
/opt/theforeman/tfm/root/usr/share/gems/gems/fusor_server-1.0.12/app/lib/actions/fusor/activation_key/add_subscriptions.rb:51:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/fusor_server-1.0.12/app/lib/actions/fusor/activation_key/add_subscriptions.rb:51:in `associate_subscriptions'
/opt/theforeman/tfm/root/usr/share/gems/gems/fusor_server-1.0.12/app/lib/actions/fusor/activation_key/add_subscriptions.rb:40:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:506:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.73/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.73/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.73/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:30:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:505:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:504:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:504:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:419:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:419:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:419:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:419:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:499:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/action.rb:260:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/execution_plan/steps/abstract.rb:155:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/executors/parallel/worker.rb:15:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/executors/parallel/worker.rb:12:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.11/lib/dynflow/actor.rb:26:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:161:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.0/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:333:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:333:in `run_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:322:in `block (3 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:305:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:305:in `block (2 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:304:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.0/lib/concurrent/executor/ruby_thread_pool_executor.rb:304:in `block in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'

Comment 4 Thom Carlin 2016-09-05 18:09:34 UTC
No reproducer yet in production so closing for now.  Please reopen if this reoccurs.

Comment 5 James Olin Oden 2016-11-07 21:41:09 UTC
I've recreated this.   Basically, I brought my interface down while it was on the satellite progress bar on the installation progress screen.   When that eventually this showed up above the satellite progress bar in red text:

   Error View Content Sync Status Failed to configure host groups: Katello::Resources::Candlepin::ActivationKey: 400 Bad Request {"displayMessage":"Product ID \"69\" has already been registered with this activation key","requestUuid":"eba4c2a4-208a-40dc-a941-dcc890fad8b4"} (POST /candlepin/activation_keys/40282f8a582bea1101582fd173b401dc/product/69) 

I went to details and it actually showed that all the sync tasks were done, however the deploy task was stopped.   I tried to resume the deploy but it kept stopping again (even though I had brought the interface back up).

The thing I was trying to test was resuming a sync that had stopped, but since all the locals were up to date, I missed that and hit this.

Comment 7 Julie 2016-11-21 04:34:26 UTC
Also ran into the issue Thom described. Is there any workaround for this?

Comment 8 Derek Whatley 2016-11-22 21:07:09 UTC
Reproduced in QCI 1.1 dev env on 11/22 by bringing down network interfaces for a few minutes during content sync. 

Deployment eventually failed during RHV deploy step due to missing dependencies from content sync step. Had to click "re-deploy" to get error message to show up.

---
ACTIONS
---
Failed action:     "Actions::Fusor::ConfigureHostGroupsForProducts"
Failed sub-action: "Actions::Fusor::ActivationKey::AddSubscriptions"

---
INPUT
--- 

activation_key_id: 1
hostgroup:
  name: RHV-Engine
  os: RedHat
  major: '7'
  minor: '3'
  parent: root_deployment
  puppet_classes: 
  activation_key:
    name: RHV-Engine
    content: rhevm
    subscription_descriptions:
    - Red Hat Cloud Infrastructure
subscription_descriptions:
- Red Hat Cloud Infrastructure
user_id: 3
repository_cp_labels:
- rhel-7-server-rpms
- rhel-7-server-kickstart
- rhel-7-server-satellite-tools-6.2-rpms
- rhel-7-server-supplementary-rpms
- rhel-7-server-rhv-4.0-rpms
- jb-eap-7-for-rhel-7-server-rpms
- rhel-7-server-optional-rpms
locale: en



---
OUTPUT (ERROR)
---

RestClient::BadRequest

Katello::Resources::Candlepin::ActivationKey: 400 Bad Request {"displayMessage":"Product ID \"69\" has already been registered with this activation key","requestUuid":"10956652-fefa-4aae-adab-1275dfff0434"} (POST /candlepin/activation_keys/ff808081588797a6015888c4fc0d016f/product/69)


---
STACK TRACE
---

- "/home/dwhatley/dev/QCI/katello/app/lib/katello/resources/candlepin.rb:765:in `add_product'"
- "/home/dwhatley/dev/QCI/katello/app/models/katello/glue/candlepin/activation_key.rb:77:in
  `add_custom_product'"
- "/home/dwhatley/dev/QCI/fusor/server/app/lib/actions/fusor/activation_key/add_subscriptions.rb:53:in
  `block in associate_subscriptions'"
- "/home/dwhatley/dev/QCI/fusor/server/app/lib/actions/fusor/activation_key/add_subscriptions.rb:51:in
  `each'"
- "/home/dwhatley/dev/QCI/fusor/server/app/lib/actions/fusor/activation_key/add_subscriptions.rb:51:in
  `associate_subscriptions'"
- "/home/dwhatley/dev/QCI/fusor/server/

Comment 9 Derek Whatley 2016-12-06 18:08:02 UTC
Added error handling for case where Activation key already has Product ID added.

PR created at: https://github.com/fusor/fusor/pull/1295

Comment 10 John Matthews 2016-12-09 13:13:56 UTC
Built in fusor-server 1.1.16-1

Comment 11 Antonin Pagac 2017-01-05 15:51:12 UTC
Unable to reproduce using QCI-1.1-RHEL-7-20170104.t.0, marking as verified.

Comment 14 errata-xmlrpc 2017-02-28 01:39:12 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2017:0335