Bug 783465

Summary: Clicking on failed promotion results in: <NoMethodError: undefined method `[]' for nil:NilClass>
Product: Red Hat Satellite Reporter: James Laska <jlaska>
Component: WebUIAssignee: Partha Aji <paji>
Status: CLOSED CURRENTRELEASE QA Contact: Katello QA List <katello-qa-list>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.0.0CC: cwelton, hbrock, jturner, mmccune, paji
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-08-22 18:21:37 UTC Type: ---
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: 747354    
Attachments:
Description Flags
katello-debug-20120120043657.tar.gz
none
Screenshot of failure none

Description James Laska 2012-01-20 14:41:56 UTC
Created attachment 556518 [details]
katello-debug-20120120043657.tar.gz

Description of problem:

I have a promotion that seems to have failed.  I'll likely track the failure in a different bug.  However, when I click on the 

Version-Release number of selected component (if applicable):
* candlepin-0.5.10-1.el6.src.rpm
* katello-0.1.180-2.el6.src.rpm
* katello-certs-tools-1.0.1-2.el6.src.rpm
* katello-cli-0.1.34-2.el6.src.rpm
* katello-configure-0.1.52-2.el6.src.rpm
* katello-httpd-ssl-key-pair-1.0-1.src.rpm
* katello-qpid-broker-key-pair-1.0-1.src.rpm
* katello-trusted-ssl-cert-1.0-1.src.rpm
* pulp-0.0.256-1.el6.src.rpm

How reproducible:
 * Everytime I click on my failed promotion, I see this error

Steps to Reproduce:
1. Install RHEL-6.2, register to RHN and update
2. Install katello
3. Run katello-configure
4. Import a Red Hat manifest, and add custom Provider repositories
5. Add a new environment (Stage), sync and promote repositories to Stage
6. Create 2 system templates with different package sets
7. Add another repository to an existing custom provider
8. Attempt to promote templates and new repository
9. After promotion fails, click on the "Promotion failed <name>" link under "Content Management" -> "Promotions" -> "Stage Changesets"
  
Actual results:

(See attachment for complete katello-debug dump)

> Started GET "/katello//changesets/3/object/?_=1327068795754" for 10.11.231.160 at Fri Jan 20 04:10:46 -0500 2012
>   Processing by ChangesetsController#object as 
>   Parameters: {"id"=>"3", "_"=>"1327068795754"}
> undefined method `[]' for nil:NilClass
> undefined method `[]' for nil:NilClass
> #<NoMethodError: undefined method `[]' for nil:NilClass>
> /usr/share/katello/app/controllers/changesets_controller.rb:308:in `simplify_changeset'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/associations/association_collection.rb:431:in `method_missing'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/associations/association_proxy.rb:220:in `method_missing'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/associations/association_proxy.rb:220:in `each'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/associations/association_proxy.rb:220:in `send'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/associations/association_proxy.rb:220:in `method_missing'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/associations/association_collection.rb:431:in `method_missing'
> /usr/share/katello/app/controllers/changesets_controller.rb:304:in `simplify_changeset'
> /usr/share/katello/app/controllers/changesets_controller.rb:303:in `each'
> /usr/share/katello/app/controllers/changesets_controller.rb:303:in `simplify_changeset'
> /usr/share/katello/app/controllers/changesets_controller.rb:98:in `object'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/abstract_controller/base.rb:150:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/rendering.rb:11:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/abstract_controller/callbacks.rb:18:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:467:in `_run__2091943037__process_action__340365298__callbacks'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:221:in `_conditional_callback_around_2615'
> /usr/share/katello/lib/util/threadsession.rb:79:in `thread_locals'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:220:in `_conditional_callback_around_2615'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:451:in `_run__2091943037__process_action__340365298__callbacks'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:410:in `send'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:410:in `_run_process_action_callbacks'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:94:in `send'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:94:in `run_callbacks'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/abstract_controller/callbacks.rb:17:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/rescue.rb:17:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/notifications.rb:52:in `instrument'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/notifications.rb:52:in `instrument'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/abstract_controller/base.rb:119:in `process'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/abstract_controller/rendering.rb:41:in `process'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal.rb:138:in `dispatch'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_controller/metal.rb:178:in `action'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/routing/route_set.rb:62:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/routing/route_set.rb:62:in `dispatch'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/routing/route_set.rb:27:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-mount-0.7.1/lib/rack/mount/route_set.rb:150:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-mount-0.7.1/lib/rack/mount/code_generation.rb:93:in `recognize'
> /usr/lib/ruby/gems/1.8/gems/rack-mount-0.7.1/lib/rack/mount/code_generation.rb:68:in `optimized_each'
> /usr/lib/ruby/gems/1.8/gems/rack-mount-0.7.1/lib/rack/mount/code_generation.rb:92:in `recognize'
> /usr/lib/ruby/gems/1.8/gems/rack-mount-0.7.1/lib/rack/mount/route_set.rb:141:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/routing/route_set.rb:493:in `call'
> /usr/lib/ruby/gems/1.8/gems/warden-1.0.5/lib/warden/manager.rb:35:in `call'
> /usr/lib/ruby/gems/1.8/gems/warden-1.0.5/lib/warden/manager.rb:34:in `catch'
> /usr/lib/ruby/gems/1.8/gems/warden-1.0.5/lib/warden/manager.rb:34:in `call'
> /usr/lib/ruby/gems/1.8/gems/sass-3.1.4/lib/sass/../sass/plugin/rack.rb:54:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/head.rb:14:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/methodoverride.rb:24:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/flash.rb:182:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/session/abstract_store.rb:149:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/cookies.rb:302:in `call'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/query_cache.rb:32:in `call'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/connection_adapters/abstract/query_cache.rb:28:in `cache'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/query_cache.rb:12:in `cache'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/query_cache.rb:31:in `call'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/connection_adapters/abstract/connection_pool.rb:354:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/callbacks.rb:46:in `call'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:416:in `_run_call_callbacks'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/callbacks.rb:44:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/sendfile.rb:102:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/remote_ip.rb:48:in `call'
> /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.10/lib/action_dispatch/middleware/show_exceptions.rb:47:in `call'
> /usr/lib/ruby/gems/1.8/gems/railties-3.0.10/lib/rails/rack/logger.rb:13:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/runtime.rb:17:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/lock.rb:34:in `call'
> /usr/lib/ruby/gems/1.8/gems/railties-3.0.10/lib/rails/application.rb:168:in `call'
> /usr/lib/ruby/gems/1.8/gems/railties-3.0.10/lib/rails/application.rb:77:in `send'
> /usr/lib/ruby/gems/1.8/gems/railties-3.0.10/lib/rails/application.rb:77:in `method_missing'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/urlmap.rb:52:in `call'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/urlmap.rb:46:in `each'
> /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/urlmap.rb:46:in `call'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:84:in `pre_process'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `catch'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `pre_process'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:57:in `process'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:42:in `receive_data'
> /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine'
> /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/backends/base.rb:61:in `start'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/server.rb:159:in `start'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/controllers/controller.rb:86:in `start'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `send'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `run_command'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:151:in `run!'
> /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/bin/thin:6
> /usr/share/katello/script/thin:59:in `load'
> /usr/share/katello/script/thin:59
> Rendering 500:undefined method `[]' for nil:NilClass
> Rendered common/_config.html.haml (0.7ms)
> Rendered layouts/_ajax_notices.haml (4.1ms)
> Rendered layouts/_notification.haml (0.4ms)
> Rendered common/_common_i18n.html.haml (0.5ms)
> Rendered layouts/_org.haml (1.2ms)
> Rendered layouts/_header.haml (7.7ms)
> Rendered layouts/_footer.haml (1.1ms)
> Rendered common/500.html.haml within layouts/katello (632.4ms)
> Completed 500 Internal Server Error in 1022ms (Views: 603.7ms | ActiveRecord: 65.0ms)

Expected results:

No error when clicking on the failed promotion link

Additional info:

 * See

Comment 1 Jason E. Rist 2012-01-20 20:34:09 UTC
From pulp log.
2012-01-20 04:07:21,698 1861:139916172285696: pulp.server.api.synchronizers:INFO: synchronizers:1201 Copying repodata from /var/lib/pulp//repos/ACME_Corporation/Locker/custom/CloudEngine/ce-rhel-6-candidate/repodata to /var/lib/pulp//repos/ACME_Corporation/Stage/custom/CloudEngine/ce-rhel-6-candidate/repodata
2012-01-20 04:07:28,562 1861:139916172285696: pulp.server.api.synchronizers:INFO: synchronizers:785 Running createrepo, this may take a few minutes to complete.
2012-01-20 04:07:28,562 1861:139916172285696: pulp.server.util:INFO: util:487 metadata found; taking backup.
2012-01-20 04:07:28,571 1861:139916172285696: pulp.server.util:INFO: util:454 Checking what metadata types are available: ['filelists', 'primary', 'primary_db', 'other_db', 'other', 'filelists_db']
2012-01-20 04:07:28,572 1861:139916172285696: pulp.server.util:INFO: util:470 started repo metadata update: ['createrepo', '--database', '--checksum', 'sha256', '--update', '/var/lib/pulp//repos/ACME_Corporation/Stage/custom/CloudEngine/ce-rhel-6-candidate']
2012-01-20 04:07:52,511 1861:139916172285696: pulp.server.util:INFO: util:520 createrepo on /var/lib/pulp//repos/ACME_Corporation/Stage/custom/CloudEngine/ce-rhel-6-candidate finished
2012-01-20 04:07:52,514 1861:139916172285696: pulp.server.api.synchronizers:INFO: synchronizers:789 Createrepo finished in 23.9514591694 seconds
2012-01-20 04:07:52,518 1861:139916172285696: pulp.server.api.synchronizers:INFO: synchronizers:397 No image files to import to repo..
2012-01-20 04:07:52,524 1861:139916172285696: pulp.server.api.synchronizers:INFO: synchronizers:377 No metadata for 'File Sync' present; no files to import to repo..
2012-01-20 04:07:52,532 1861:139916172285696: pulp.server.api.synchronizers:INFO: synchronizers:369 Skipping errata imports from sync process
2012-01-20 04:07:52,536 1861:139916172285696: pulp.server.api.repo_sync:INFO: repo_sync:275 Sync returned 351 packages, 0 errata in 46.7493960857 seconds
2012-01-20 04:07:52,539 1861:139916172285696: pulp.server.api.repo_sync:INFO: repo_sync:286 0 old packages to process, 0 new packages to process
2012-01-20 04:07:52,548 1861:139916172285696: pulp.server.api.repo_sync:INFO: repo_sync:301 Examining 0 errata from repo ACME_Corporation-Stage-CloudEngine-ce-rhel-6-candidate
2012-01-20 04:07:52,550 1861:139916172285696: pulp.server.api.repo_sync:INFO: repo_sync:305 Removing 0 old errata from repo ACME_Corporation-Stage-CloudEngine-ce-rhel-6-candidate
2012-01-20 04:07:52,562 1861:139916172285696: pulp.server.api.repo_sync:INFO: repo_sync:314 Adding 0 new errata to repo ACME_Corporation-Stage-CloudEngine-ce-rhel-6-candidate
2012-01-20 04:07:52,571 1861:139916172285696: pulp.server.tasking.task:INFO: task:440 Task succeeded: Task 1fc005ae-4346-11e1-857f-0015172f2f5c: _sync(ACME_Corporation-Stage-CloudEngine-ce-rhel-6-candidate, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f40e004ac10>, skip={}, max_speed=None, threads=4, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f40e004a710>>)
2012-01-20 04:08:00,235 1861:139916560279296: pulp.server.api.repo:INFO: repo:909 Finished created pkg_object in 0.0208868980408 seconds
2012-01-20 04:08:00,235 1861:139916560279296: pulp.server.api.repo:INFO: repo:962 Finished check of NEVRA/filename in argument data by 0.0212709903717 seconds
2012-01-20 04:08:00,253 1861:139916560279296: pulp.server.api.repo:WARNING: repo:980 Package with same NVREA [(u'rhev-agent-gdm-plugin-rhevcred', u'0', u'2.3.16', u'3.el6', u'x86_64')] already exists in repo [ACME_Corporation-Stage-CloudEngine-ce-rhel-6-puddle]
2012-01-20 04:08:00,285 1861:139916560279296: pulp.server.webservices.controllers.decorators:ERROR: decorators:52 Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/decorators.py", line 48, in report_error
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/decorators.py", line 127, in _auth_decorator
    value = method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/repositories.py", line 1706, in POST
    return action(id)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/repositories.py", line 1110, in add_package
    errors, filtered_count = api.add_package(id, data['packageid'])
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo.py", line 981, in add_package
    errors.append(form_error_tup(pkg, error_message))
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo.py", line 888, in form_error_tup
    return (pkg["id"], pkg_tup, pkg["filename"], pkg["checksum"]["sha256"], error_message)
KeyError: 'sha256'

Comment 2 James Laska 2012-01-20 20:39:53 UTC
Created attachment 556597 [details]
Screenshot of failure

I was asked to track the pulp failure in bug#783499.

== Description of problem ==

I have a promotion that seems to have failed.  I'll likely track the failure in
a different bug.  However, when I click on the failed promotion row in the list of "Stage Changesets" ... I am presented with an onscreen error "undefined method `[]' for nil:NilClass"

Comment 3 Partha Aji 2012-01-24 23:54:13 UTC
James would you be able to also attach the delayed_jobs log in /var/log/katello directory ??

Comment 4 James Laska 2012-01-25 13:17:49 UTC
(In reply to comment #3)
> James would you be able to also attach the delayed_jobs log in /var/log/katello
> directory ??

Hi Partha, I'm sorry ... I've long since reinstalled this system.  But good news, /var/log/katello/delayed_job.log appears to be included in the katello_debug file I attached (see attachment#556518 [details]).

Comment 5 Jeff Weiss 2012-02-06 15:05:49 UTC
This doesn't seem to fit the definition of urgent severity to me.  It doesn't break a lot of functionality, is there data corruption?  Seems like a workaround exists (do another changeset).

Comment 6 Mike McCune 2012-03-07 23:43:26 UTC
mass move ON_QA after brewing

Comment 7 Corey Welton 2012-03-20 13:05:02 UTC
Been having a hard time actually getting a promotion to fail now :). Used to be able to shut down the delayed_job to trigger a failed promotion, but that doesn't seem to occur anymore. Will try other things  (shutdown pulp, etc.) to try and emulate/trigger a failed promotion.

Comment 8 Corey Welton 2012-03-22 01:17:51 UTC
Finally managed a forced fail by stopping pulp-server service (and most of the system along with it) while a promotion was en route.  Upon bringing these services back up and reloading the page, a failed promotion resulted.

QA Verified - clicking the resulting failed promotion no longer triggers the undefined error -- rather, user can click through and view the attempted promotion's details.