Bug 887027 - Provider sync failed with: can't convert nil into String
Provider sync failed with: can't convert nil into String
Status: CLOSED WONTFIX
Product: Red Hat Satellite 6
Classification: Red Hat
Component: Hammer (Show other bugs)
6.0.1
Unspecified Unspecified
medium Severity medium (vote)
: Unspecified
: --
Assigned To: Justin Sherrill
Katello QA List
: Triaged, ZStream
Depends On:
Blocks: 896216
  Show dependency treegraph
 
Reported: 2012-12-13 16:29 EST by James Laska
Modified: 2014-09-18 11:32 EDT (History)
6 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 896216 (view as bug list)
Environment:
Last Closed: 2014-03-11 12:43:35 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)
katello-debug-20121213162417.tar.gz (4.80 MB, application/octet-stream)
2012-12-13 16:29 EST, James Laska
no flags Details

  None (edit)
Description James Laska 2012-12-13 16:29:12 EST
Created attachment 663205 [details]
katello-debug-20121213162417.tar.gz

Description of problem:

Attempting to sync a provider failed with error: can't convert nil into String

I'm not syncing any different content that is normally synced in the integration workflow.  For reference, this test was initiated by beaker job https://beaker.engineering.redhat.com/jobs/350019.

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

 * CloudForms-1.1
   * candlepin-0.7.8.1-1.el6cf.src.rpm
   * katello-1.1.12-22.el6cf.src.rpm
   * katello-candlepin-cert-key-pair-1.0-1.src.rpm
   * katello-certs-tools-1.1.8-1.el6cf.src.rpm
   * katello-cli-1.1.8-12.el6cf.src.rpm
   * katello-configure-1.1.9-12.el6cf.src.rpm
   * katello-qpid-broker-key-pair-1.0-1.src.rpm
   * katello-qpid-client-key-pair-1.0-1.src.rpm
   * katello-selinux-1.1.1-2.el6cf.src.rpm
   * pulp-1.1.14-1.el6cf.src.rpm

How reproducible:


Steps to Reproduce:
1. Import a valid Red Hat manifest from production
2. Enable RHEL and CloudForms repositories
3. Attempt to sync provider
> # katello -u admin -p admin provider synchronize --name "Red Hat"
  
Actual results:

> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%
> Progress: [##########################                        ] 53.3%can't convert nil into String
> :: [   FAIL   ] :: Running 'katello -u admin -p admin provider synchronize --name "Red Hat"' (Expected 0, got 244)

Expected results:

> No failure

Additional info:

[ /var/log/katello/client.log ]
2012-12-13 16:17:17,680 [ERROR][MainThread] error() @ base.py:222 - error: can't convert nil into String

[ /var/log/katello/production.log ]

> [ERROR: 2012-12-13 16:17:17 #23013] TypeError: can't convert nil into String
> /usr/lib/ruby/gems/1.8/gems/json-1.4.6/lib/json/common.rb:146:in `initialize'
> /usr/lib/ruby/gems/1.8/gems/json-1.4.6/lib/json/common.rb:146:in `new'
> /usr/lib/ruby/gems/1.8/gems/json-1.4.6/lib/json/common.rb:146:in `parse'
> /usr/lib/ruby/gems/1.8/gems/multi_json-1.0.3/lib/multi_json/engines/json_gem.rb:13:in `decode'
> /usr/lib/ruby/gems/1.8/gems/multi_json-1.0.3/lib/multi_json.rb:65:in `decode'
> /usr/lib/ruby/gems/1.8/gems/tire-0.3.12/lib/tire/index.rb:60:in `store'
> /usr/lib/ruby/gems/1.8/gems/tire-0.3.12/lib/tire/model/search.rb:134:in `update_index'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:414:in `_run_update_elasticsearch_index_callbacks'
> /usr/lib/ruby/gems/1.8/gems/tire-0.3.12/lib/tire/model/search.rb:130:in `send'
> /usr/lib/ruby/gems/1.8/gems/tire-0.3.12/lib/tire/model/search.rb:130:in `update_index'
> /usr/lib/ruby/gems/1.8/gems/tire-0.3.12/lib/tire/model/callbacks.rb:21:in `_callback_after_1692'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:456:in `_run_save_callbacks'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/callbacks.rb:273:in `create_or_update'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/persistence.rb:60:in `save!'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/validations.rb:49:in `save!'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/attribute_methods/dirty.rb:30:in `save!'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/transactions.rb:245:in `save!'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/transactions.rb:292:in `with_transaction_returning_status'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/connection_adapters/abstract/database_statements.rb:139:in `transaction'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/transactions.rb:207:in `transaction'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/transactions.rb:290:in `with_transaction_returning_status'
> /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.10/lib/active_record/transactions.rb:245:in `save!'
> /usr/share/katello/app/models/pulp_task_status.rb:82:in `refresh'
> /usr/share/katello/app/models/pulp_task_status.rb:19:in `refresh'
> /usr/share/katello/app/controllers/api/tasks_controller.rb:48:in `show'
> /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__1007790535__process_action__1355923442__callbacks'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:221:in `_conditional_callback_around_3387'
> /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_3387'
> /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.10/lib/active_support/callbacks.rb:451:in `_run__1007790535__process_action__1355923442__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:82: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/apipie-rails-0.0.11/lib/apipie/static_dispatcher.rb:57: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:24:in `load'
> /usr/share/katello/script/thin:24
Comment 1 James Laska 2012-12-13 16:30:03 EST
After encountering the error, I attempted to re-initiate the sync, but it appears the previous sync is still active.  Perhaps a case where the CLI returned, but pulp/grinder is still busy?

> # katello -u admin -p admin provider synchronize --name "Red Hat"
> Sync already in process for repo [redhat-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_i386_5_7]
Comment 3 Justin Sherrill 2013-01-22 16:30:00 EST
I've tried to reproduce this several times but am unable to.  I've tried in master as well as against a CFSE 1.1.1 box.  Is this reproducible always?
Comment 4 James Laska 2013-02-12 13:46:27 EST
Looks like aweiteka is ran into this issue last week.

Test output available - http://lab-02.rhts.eng.bos.redhat.com/beaker/logs/tasks/10536127/TESTOUT.log
Tarball containing katello logs available - http://lab-02.rhts.eng.bos.redhat.com/beaker/logs/tasks/10536127/tmp-katello-logs.374783_787794_10536127.tar.gz
Comment 7 Justin Sherrill 2013-02-19 09:36:51 EST
I'm thinking this might be a race condition, as multiple repos are syncing at the same time.  Relevant tracebacks:



Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/tasking/task.py", line 418, in run
    result = self.callable(*self.args, **self.kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line 283, in _sync
    progress_callback, synchronizer, max_speed, threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line 379, in fetch_content
    synchronizer.add_distribution_from_dir(repo_dir, repo_id, skip_dict)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/synchronizers.py", line 347, in add_distribution_from_dir
    self._process_repo_images(dir, repo)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/synchronizers.py", line 484, in _process_repo_images
    os.mkdir(distro_path)
OSError: [Errno 17] File exists: '/var/lib/pulp/published/ks'


upon trying to re-sync:



Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/tasking/task.py", line 418, in run
    result = self.callable(*self.args, **self.kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line 283, in _sync
    progress_callback, synchronizer, max_speed, threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line 372, in fetch_content
    progress_callback, max_speed, threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/synchronizers.py", line 164, in sync
    max_speed=max_speed, threads=threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/synchronizers.py", line 811, in remote
    verify_options=verify_options)
  File "/usr/lib/python2.6/site-packages/grinder/RepoFetch.py", line 204, in fetchYumRepo
    self.setupDistroInfo()
  File "/usr/lib/python2.6/site-packages/grinder/RepoFetch.py", line 154, in setupDistroInfo
    distro_items = info.prepareTrees(self.repoFetch)
  File "/usr/lib/python2.6/site-packages/grinder/DistroInfo.py", line 42, in prepareTrees
    return self.__prepareTrees(tree_manifest)
  File "/usr/lib/python2.6/site-packages/grinder/DistroInfo.py", line 126, in __prepareTrees
    os.makedirs(info['pkgpath'])
  File "/usr/lib64/python2.6/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/var/lib/pulp/distributions/ks-Red Hat Enterprise Linux-Server-6.4-x86_64'
Comment 8 Mike McCune 2013-08-16 14:10:57 EDT
getting rid of 6.0.0 version since that doesn't exist
Comment 11 Bryan Kearney 2014-03-11 12:43:35 EDT
Closing old bugs which are not relevant based on new UI and CLI

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