Bug 1197710

Summary: Actions::Candlepin::Environment::SetContent called multiple times when publishing CV after repo remove
Product: Red Hat Satellite Reporter: Peter Vreman <peter.vreman>
Component: Content ViewsAssignee: Justin Sherrill <jsherril>
Status: CLOSED ERRATA QA Contact: Jameer Pathan <jpathan>
Severity: low Docs Contact:
Priority: unspecified    
Version: 6.0.8CC: bbuckingham, cwelton, ehelms, oprazak, pmoravec
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
URL: http://projects.theforeman.org/issues/15183
Whiteboard:
Fixed In Version: rubygem-katello-3.0.0.38-1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-27 11:17:39 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:
Embargoed:
Bug Depends On:    
Bug Blocks: 1122832    
Attachments:
Description Flags
Candlepin::Environment::SetContent called only once - 92 none

Description Peter Vreman 2015-03-02 13:07:24 UTC
Description of problem:
Publishing a Content View after Removing a repository (or component in a Composite View) calls Actions::Candlepin::Environment::SetContent multiple times. One for each Delete repository and then a final call at the end.

See steps 76. and 81. in the dynflow output below:

 70: Actions::Pulp::Repository::Destroy (success) [ 12.22s / 2.64s ]
Started at: 2015-03-02 12:43:18 UTC
Ended at: 2015-03-02 12:43:30 UTC
Real time: 12.22s
Execution time (excluding suspended state): 2.64s
Input:
---
pulp_id: Hilti-Library-Test-HOICI-HOICI-1_0_0-sp17
remote_user: hoici-b11965af
locale: en
Output:
---
pulp_tasks:
- exception: 
  task_type: pulp.server.tasks.repository.delete
  _href: /pulp/api/v2/tasks/cdf5d4bd-9061-4417-be44-4a90899e3816/
  task_id: cdf5d4bd-9061-4417-be44-4a90899e3816
  tags:
  - pulp:repository:Hilti-Library-Test-HOICI-HOICI-1_0_0-sp17
  - pulp:action:delete
  finish_time: '2015-03-02T12:43:29Z'
  _ns: task_status
  start_time: '2015-03-02T12:43:19Z'
  traceback: 
  spawned_tasks: []
  progress_report: {}
  queue: reserved_resource_worker-1.hilti.com.dq
  state: finished
  result: 
  error: 
  _id:
    $oid: 54f45ae7b354357289fc53c0
  id: 54f45ae7f540aa14f5134372
poll_attempts:
  total: 11
  failed: 0
73: Actions::ElasticSearch::Repository::Destroy (success) [ 1.32s / 1.32s ]
Started at: 2015-03-02 12:43:18 UTC
Ended at: 2015-03-02 12:43:19 UTC
Real time: 1.32s
Execution time (excluding suspended state): 1.32s
Input:
---
pulp_id: Hilti-Library-Test-HOICI-HOICI-1_0_0-sp17
remote_user: hoici-b11965af
locale: en
Output:
--- {}
76: Actions::Candlepin::Environment::SetContent (success) [ 0.67s / 0.67s ]
Started at: 2015-03-02 12:43:18 UTC
Ended at: 2015-03-02 12:43:19 UTC
Real time: 0.67s
Execution time (excluding suspended state): 0.67s
Input:
---
cp_environment_id: 2-41
content_ids:
- '1421224072547'
remote_user: hoici-b11965af
locale: en
Output:
---
add_ids: []
delete_ids:
- '1424770949654'
delete_response: 202
81: Actions::Candlepin::Environment::SetContent (success) [ 0.15s / 0.15s ]
Started at: 2015-03-02 12:44:18 UTC
Ended at: 2015-03-02 12:44:18 UTC
Real time: 0.15s
Execution time (excluding suspended state): 0.15s
Input:
---
cp_environment_id: 2-41
content_ids:
- '1421224072547'
remote_user: hoici-b11965af
locale: en
Output:
---
add_ids: []
delete_ids: []
85: Actions::Katello::ContentView::Publish (success) [ 0.60s / 0.60s ]


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


How reproducible:


Steps to Reproduce:
1. Create Content View
2. Add Repository
3. Publish Content View
4. Remove Repository
5. Publish Content View

Alternative is the 22 step process from BZ1196156

Actual results:
Duplicate call to SetContent

Expected results:
Single call to SetContent

Additional info:

Comment 1 RHEL Program Management 2015-03-02 14:24:35 UTC
Since this issue was entered in Red Hat Bugzilla, the release flag has been
set to ? to ensure that it is properly evaluated for this release.

Comment 3 Peter Vreman 2015-03-13 12:24:29 UTC
The multiple calls to SetContent are giving for me an error in Candlepin:

 452: Actions::Candlepin::Environment::SetContent (success) [ 0.61s / 0.61s ]

Started at: 2015-03-13 11:22:57 UTC

Ended at: 2015-03-13 11:22:58 UTC

Real time: 0.61s

Execution time (excluding suspended state): 0.61s

Input:

---
cp_environment_id: 2-11
content_ids:
- '1426234009103'
- '1425912741564'
- '1426233888739'
- '1283'
- '2740'
- '1285'
- '1952'
- '2396'
- '2003'
remote_user: hoici-e5c83d29
locale: en

Output:

---
add_ids:
- '1426234009103'
- '1426233888739'
add_response:
  id: regen_entitlement_cert_of_envfb5af083-aa8b-4430-9ff6-58c8ea6a449d
  state: CREATED
  startTime: 
  finishTime: 
  result: 
  principalName: hoici-e5c83d29
  targetType: 
  targetId: 
  group: async group
  done: false
  statusPath: /jobs/regen_entitlement_cert_of_envfb5af083-aa8b-4430-9ff6-58c8ea6a449d
  created: '2015-03-13T11:22:58.481+0000'
  updated: '2015-03-13T11:22:58.481+0000'
delete_ids:
- '1425913171202'
delete_response: 202

457: Actions::Pulp::Repository::Destroy (success) [ 3.49s / 0.91s ]
460: Actions::ElasticSearch::Repository::Destroy (success) [ 0.35s / 0.35s ]
463: Actions::Candlepin::Environment::SetContent (error) [ 0.32s / 0.32s ] Skip

Started at: 2015-03-13 11:22:58 UTC

Ended at: 2015-03-13 11:22:58 UTC

Real time: 0.32s

Execution time (excluding suspended state): 0.32s

Input:

---
cp_environment_id: 2-11
content_ids:
- '1426234009103'
- '1426233888739'
- '1283'
- '2740'
- '1285'
- '1952'
- '2396'
- '2003'
remote_user: hoici-e5c83d29
locale: en

Output:

---
add_ids: []
delete_ids:
- '1425913171202'
- '1425912741564'

Error:

Katello::Errors::CandlepinError

Runtime Error null at org.candlepin.model.AbstractHibernateCurator.delete:325

---
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/propagate_candlepin_errors.rb:35:in
  `rescue in propagate_candlepin_errors'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/propagate_candlepin_errors.rb:33:in
  `propagate_candlepin_errors'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/propagate_candlepin_errors.rb:23:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:22:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:26:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware.rb:16:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:25:in
  `block in run'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:51:in
  `block (2 levels) in as_remote_user'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/katello/util/thread_session.rb:85:in
  `set_pulp_config'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:41:in
  `as_pulp_user'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:50:in
  `block in as_remote_user'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/katello/util/thread_session.rb:92:in
  `set_cp_config'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:36:in
  `as_cp_user'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:49:in
  `as_remote_user'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/remote_action.rb:25:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:22:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:26:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware.rb:16:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action/progress.rb:30:in
  `with_progress_calculation'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action/progress.rb:16:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:22:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:26:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware.rb:16:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/keep_locale.rb:24:in
  `block in run'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/keep_locale.rb:35:in
  `with_locale'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/keep_locale.rb:24:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:22:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/world.rb:30:in
  `execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:442:in
  `block (2 levels) in execute_run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:441:in
  `catch'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:441:in
  `block in execute_run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:365:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:365:in
  `block in with_error_handling'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:365:in
  `catch'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:365:in
  `with_error_handling'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:436:in
  `execute_run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:230:in
  `execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in
  `block (2 levels) in execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/execution_plan/steps/abstract.rb:152:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/execution_plan/steps/abstract.rb:152:in
  `with_meta_calculation'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in
  `block in execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in
  `open_action'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in
  `execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/executors/parallel/worker.rb:20:in
  `block in on_message'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:859:in
  `block in assigns'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:858:in
  `tap'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:858:in
  `assigns'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:138:in
  `match_value'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:116:in
  `block in match'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:115:in
  `each'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:115:in
  `match'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/executors/parallel/worker.rb:17:in
  `on_message'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:82:in
  `on_envelope'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:72:in
  `receive'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:99:in
  `block (2 levels) in run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:99:in
  `loop'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:99:in
  `block in run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:99:in
  `catch'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:99:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/micro_actor.rb:13:in
  `block in initialize'
- /opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in
  `block in create_with_logging_context'
- ! 'caused by: (RestClient::InternalServerError) Katello::Resources::Candlepin::Environment:
  500 Internal Server Error {"displayMessage":"Runtime Error null at org.candlepin.model.AbstractHibernateCurator.delete:325","requestUuid":"634d1df6-5d10-4af2-8fb7-cc2db44d780c"}
  (DELETE /candlepin/environments/2-11/content?content=1425913171202&content=1425912741564)'
- /opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/abstract_response.rb:48:in
  `return!'
- /opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:230:in
  `process_result'
- /opt/rh/ruby193/root/usr/share/gems/gems/rbovirt-0.0.29/lib/restclient_ext/request.rb:50:in
  `block in transmit'
- /opt/rh/ruby193/root/usr/share/ruby/net/http.rb:746:in `start'
- /opt/rh/ruby193/root/usr/share/gems/gems/rbovirt-0.0.29/lib/restclient_ext/request.rb:44:in
  `transmit'
- /opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in
  `execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in
  `execute'
- /opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:94:in
  `delete'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/katello/http_resource.rb:139:in
  `delete'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/katello/resources/candlepin.rb:522:in
  `delete_content'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/candlepin/environment/set_content.rb:38:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/action.rb:443:in
  `block (3 levels) in execute_run'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:26:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware/stack.rb:26:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.3/lib/dynflow/middleware.rb:16:in
  `pass'
- /opt/rh/ruby193/root/usr/share/gems/gems/katello-1.5.0/app/lib/actions/middleware/propagate_candlepin_errors.rb:23:in
  `block in run'
- ! '    ... skipped 61 lines'

468: Actions::Candlepin::Environment::SetContent (pending)
472: Actions::Katello::ContentView::Publish (pending)

Comment 4 Peter Vreman 2015-03-13 13:45:18 UTC
From candlepin log:

2015-03-13 11:22:58,762 [req=634d1df6-5d10-4af2-8fb7-cc2db44d780c, org=Hilti] ERROR org.candlepin.exceptions.mappers.CandlepinExceptionMapper - Runtime Error null at org.candlepin.model.AbstractHibernateCurator.delete:325
java.lang.NullPointerException: null
        at org.candlepin.model.AbstractHibernateCurator.delete(AbstractHibernateCurator.java:325) ~[AbstractHibernateCurator.class:na]
        at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:66) ~[guice-persist-3.0-redhat-1.jar:3.0-redhat-1]
        at org.candlepin.resource.EnvironmentResource.demoteContent(EnvironmentResource.java:228) ~[EnvironmentResource.class:na]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_75]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_75]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_75]
        at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75]
        at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167) ~[resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.core.ResourceMethod.invokeOnTarget(ResourceMethod.java:269) ~[resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:227) ~[resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:216) ~[resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.core.SynchronousDispatcher.getResponse(SynchronousDispatcher.java:542) [resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:524) [resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:126) [resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:208) [resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:55) [resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:50) [resteasy-jaxrs-2.3.7.2.Final-redhat-1.jar:2.3.7.2.Final-redhat-1]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [tomcat6-servlet-2.5-api-6.0.24.jar:na]
        at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at org.candlepin.servlet.filter.ContentTypeHackFilter.doFilter(ContentTypeHackFilter.java:58) [ContentTypeHackFilter.class:na]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at org.candlepin.common.filter.LoggingFilter.doFilter(LoggingFilter.java:88) [candlepin-common-1.0.1.jar:]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at org.candlepin.servlet.filter.CandlepinPersistFilter.doFilter(CandlepinPersistFilter.java:48) [CandlepinPersistFilter.class:na]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at org.candlepin.servlet.filter.CandlepinScopeFilter.doFilter(CandlepinScopeFilter.java:67) [CandlepinScopeFilter.class:na]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) [guice-servlet-3.0-redhat-1.jar:3.0-redhat-1]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina-6.0.24.jar:na]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.24.jar:na]
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina-6.0.24.jar:na]
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.24.jar:na]
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.24.jar:na]
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina-6.0.24.jar:na]
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.24.jar:na]
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina-6.0.24.jar:na]
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:857) [tomcat-coyote-6.0.24.jar:na]
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588) [tomcat-coyote-6.0.24.jar:na]
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote-6.0.24.jar:na]
        at java.lang.Thread.run(Thread.java:745) [na:1.7.0_75]

Comment 5 Peter Vreman 2015-11-24 08:44:50 UTC
With Sat6.1.3 the runtime error in candlepin is not happening. But the call to Candlepin::Environment::SetContent is still done twice with exactly the same input from the ContentView Publish Action, this is not optimal:



 722: Actions::Candlepin::Environment::SetContent (success) [ 0.31s / 0.31s ]

Started at: 2015-11-23 14:03:50 UTC

Ended at: 2015-11-23 14:03:50 UTC

Real time: 0.31s

Execution time (excluding suspended state): 0.31s

Input:

---
cp_environment_id: 2-26
content_ids:
- '1447116546749'
- '1447495666342'
- '1447122547859'
- '1447495903905'
- '1952'
- '166'
- '2699'
- '168'
- '367'
- '4064'
- '4185'
- '1997'
remote_user: hoici-4dbfe556
remote_cp_user: hoici
locale: en

Output:

---
add_ids: []
delete_ids:
- '1447345770670'
delete_response: 202

726: Actions::Candlepin::Environment::SetContent (success) [ 0.17s / 0.17s ]

Started at: 2015-11-23 17:46:19 UTC

Ended at: 2015-11-23 17:46:19 UTC

Real time: 0.17s

Execution time (excluding suspended state): 0.17s

Input:

---
cp_environment_id: 2-26
content_ids:
- '1447116546749'
- '1447495666342'
- '1447122547859'
- '1447495903905'
- '1952'
- '166'
- '2699'
- '168'
- '367'
- '4064'
- '4185'
- '1997'
remote_user: hoici-4dbfe556
remote_cp_user: hoici
locale: en

Output:

---
add_ids: []
delete_ids: []

Comment 6 Pavel Moravec 2016-03-17 09:52:30 UTC
Hi Peter,
see attached

https://access.redhat.com/solutions/2202641

how to remedy / workaround the situation.

Comment 7 Justin Sherrill 2016-05-10 17:53:49 UTC
This was likely fixed by https://bugzilla.redhat.com/show_bug.cgi?id=1276479

which is in the beta.  Moving to on_qa

Comment 8 Justin Sherrill 2016-05-25 14:27:33 UTC
Moving back to assigned as this was seen on the beta.

Comment 9 Justin Sherrill 2016-05-25 16:01:26 UTC
Created redmine issue http://projects.theforeman.org/issues/15183 from this bug

Comment 10 Ondřej Pražák 2016-06-30 13:01:35 UTC
Created attachment 1174576 [details]
Candlepin::Environment::SetContent called only once - 92

Comment 11 Ondřej Pražák 2016-06-30 13:02:27 UTC
Verified on RHEL7, snap 18.1

Comment 12 Bryan Kearney 2016-07-27 11:17:39 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/RHBA-2016:1501