Bug 882428

Summary:	Creating a scheduled sync with a feed URL that is shared with another repo that is currently syncing causes an unserializable JSON TypeError
Product:	[Retired] Pulp	Reporter:	Randy Barlow <rbarlow>
Component:	async/tasks	Assignee:	Jason Connor <jconnor>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Preethi Thomas <pthomas>
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	2.0.6	CC:	jason.dobies, mmccune, skarmark
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2013-01-07 14:09:36 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:

Description Randy Barlow 2012-11-30 22:37:21 UTC

I created two different repos with the same feed URL. Then I started a sync on one, and on the other I created a schedule to sync. Once the schedule started the other sync, pulp-admin tasks list started causing this traceback in the /var/log/pulp/pulp.log:

2012-11-30 17:08:34,064 pulp.server.dispatch.task:INFO: SUCCESS: Task 23a90c6d-1d69-4e3b-8bcd-a36050ab869c: CallRequest: AggregateScheduleManager.create_sync_schedule(u'rhel6-server-i386', u'yum_importer', {'override_config': {}}, {'schedule': '2012-11-30T22:10:00Z/P1M', 'enabled': True, 'failure_threshold': None})
2012-11-30 17:10:28,816 pulp.server.dispatch.task:INFO: SUCCESS: Task 6061264d-4b48-46b4-8973-37c8e8e7e6b9: CallRequest: sync_with_auto_publish_itinerary(u'rhel6-server-i386', overrides={})
2012-11-30 17:10:29,028 pulp.server.dispatch.scheduler:INFO: Scheduled CallRequest: RepoSyncManager.sync(u'rhel6-server-i386', sync_config_override={}, importer_config={}, importer_instance=<yum_importer.importer.YumImporter object at 0x9ffd202c>): accepted [reasons: []]
2012-11-30 17:10:29,029 pulp.server.dispatch.scheduler:INFO: Scheduled CallRequest: RepoPublishManager.publish(u'rhel6-server-i386', u'yum_distributor', distributor_instance=<yum_distributor.distributor.YumDistributor object at 0xa17c41ac>, distributor_config={}): postponed [reasons: [{'operation': u'update',
  u'resource_id': u'rhel6-server-i386',
  u'resource_type': u'repository'}]]
2012-11-30 17:10:29,228 pulp.plugins.yum_importer.importer_rpm:INFO: Begin sync of repo <rhel6-server-i386> from feed_url <https://cdn.redhat.com/content/dist/rhel/server/6/6Server/i386/os>
2012-11-30 17:10:29,647 pulp.server.webservices.middleware.exception:ERROR: <pulp.server.dispatch.call.CallRequest object at 0x9a596a2c> is not JSON serializable
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/middleware/exception.py", line 44, in __call__
    return self.app(environ, start_response)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/middleware/postponed.py", line 39, in __call__
    return self.app(environ, start_response)
  File "/usr/lib/python2.6/site-packages/web/application.py", line 279, in wsgi
    result = self.handle_with_processors()
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 26, in _handle_with_processors
    return process(self.processors)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in process
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/web/application.py", line 566, in processor
    return handler()
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in <lambda>
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in process
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/web/application.py", line 581, in processor
    result = handler()
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in <lambda>
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 25, in process
    return self.handle()
  File "/usr/lib/python2.6/site-packages/web/application.py", line 230, in handle
    return self._delegate(fn, self.fvars, args)
  File "/usr/lib/python2.6/site-packages/web/application.py", line 422, in _delegate
    return f()
  File "/usr/lib/python2.6/site-packages/web/application.py", line 430, in <lambda>
    f = lambda: self._delegate_sub_application(pat, what)
  File "/usr/lib/python2.6/site-packages/web/application.py", line 455, in _delegate_sub_application
    return app.handle_with_processors()
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 26, in _handle_with_processors
    return process(self.processors)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in process
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/web/application.py", line 566, in processor
    return handler()
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in <lambda>
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in process
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/web/application.py", line 581, in processor
    result = handler()
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 23, in <lambda>
    return p(lambda : process(processors))
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 25, in process
    return self.handle()
  File "/usr/lib/python2.6/site-packages/web/application.py", line 230, in handle
    return self._delegate(fn, self.fvars, args)
  File "/usr/lib/python2.6/site-packages/web/application.py", line 405, in _delegate
    return handle_class(f)
  File "/usr/lib/python2.6/site-packages/web/application.py", line 396, in handle_class
    return tocall(*args)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/decorators.py", line 231, in _auth_decorator
    value = method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/dispatch.py", line 85, in GET
    return self.ok(serialized_call_reports)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 155, in ok
    return self._output(data)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 131, in _output
    body = json.dumps(data, default=json_util.default)
  File "/usr/lib/python2.6/json/__init__.py", line 237, in dumps
    **kw).encode(obj)
  File "/usr/lib/python2.6/json/encoder.py", line 367, in encode
    chunks = list(self.iterencode(o))
  File "/usr/lib/python2.6/json/encoder.py", line 306, in _iterencode
    for chunk in self._iterencode_list(o, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 204, in _iterencode_list
    for chunk in self._iterencode(value, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 309, in _iterencode
    for chunk in self._iterencode_dict(o, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 275, in _iterencode_dict
    for chunk in self._iterencode(value, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 306, in _iterencode
    for chunk in self._iterencode_list(o, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 204, in _iterencode_list
    for chunk in self._iterencode(value, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 317, in _iterencode
    for chunk in self._iterencode_default(o, markers):
  File "/usr/lib/python2.6/json/encoder.py", line 323, in _iterencode_default
    newobj = self.default(o)
  File "/usr/lib/python2.6/site-packages/bson/json_util.py", line 133, in default
    raise TypeError("%r is not JSON serializable" % obj)
TypeError: <pulp.server.dispatch.call.CallRequest object at 0x9a596a2c> is not JSON serializable

Comment 1 Jay Dobies 2012-12-03 16:13:31 UTC

I don't even know where to start on this one. Can you reliably reproduce it?

Comment 2 Randy Barlow 2012-12-03 16:30:17 UTC

I went in to look at it today, and I found something kind of interesting:

$ pulp-admin rpm repo list
+----------------------------------------------------------------------+
                            RPM Repositories
+----------------------------------------------------------------------+

Id:                 pulp-rhel6-i386
Display Name:       pulp-rhel6-i386
Description:        None
Content Unit Count: 36

Id:                 rhel6-i386
Display Name:       rhel6-i386
Description:        None
Content Unit Count: 0

Id:                 rhel6-server-i386
Display Name:       rhel6-server-i386
Description:        None
Content Unit Count: 8284

The bottom two repos there are the two that were causing this issue. The strange thing is that the one that was syncing first is the one that now reports having 0 units, and the second one was the one that caused the issue when I added the sync schedule.

$ pulp-admin rpm repo sync schedules list --repo-id=rhel6-server-i386
+----------------------------------------------------------------------+
                               Schedules
+----------------------------------------------------------------------+

Schedule: 2012-11-30T22:10:00Z/P1M
Id:       50b92e61e5147d0bbc0028a2
Enabled:  True
Last Run: 2012-12-30T22:10:00Z
Next Run: 2012-12-30T22:10:00Z

I haven't tried to reproduce it today, but I will put that on my todo list.

Comment 3 Jason Connor 2012-12-04 17:47:08 UTC

I know what's going here. The result from a meta usage of the coordinator in the scheduler is generating the scheduled call requests. These call requests are being reported as the result of the meta call request and are not serializable.

Randy's observation in comment 2, however, isn't relavent.

Comment 4 Randy Barlow 2012-12-04 18:25:11 UTC

(In reply to comment #3)
> Randy's observation in comment 2, however, isn't relavent.

Should we report that as a separate bug then?

Comment 5 Jason Connor 2012-12-04 21:06:09 UTC

*** Bug 880094 has been marked as a duplicate of this bug. ***

Comment 6 Jason Connor 2012-12-04 21:08:44 UTC

Added a flag to call report to toggle the obfuscation of call's result.

Fix in branch: jconnor-result-reporting-bugs

Comment 7 Jason Connor 2012-12-07 16:30:40 UTC

Merged into pulp-2.0 in revision:
a210efcff37315a8b04876c12ea179aba958900e

Comment 8 Jeff Ortel 2012-12-07 20:03:39 UTC

build: 2.0.6-0.12.beta

Comment 9 Preethi Thomas 2012-12-10 14:03:34 UTC

verified
1. Created 2 repos same feed url
2. Sync one
3. Create a sync schedule on other
4. Run tasks list

[root@preethi ~]# pulp-admin tasks list
+----------------------------------------------------------------------+
                                 Tasks
+----------------------------------------------------------------------+

Operations:  create_sync_schedule
Resources:   fedora17-1 (repository), yum_importer (repository_importer)
State:       Successful
Start Time:  Unstarted
Finish Time: 2012-12-10T13:55:26Z
Result:      50c5e9cd758cc94b56000132
Task Id:     89ce6115-384b-42ce-92ac-15c4e0d313a0

Operations:  sync
Resources:   fedora17 (repository)
State:       Running
Start Time:  2012-12-10T13:52:48Z
Finish Time: Incomplete
Result:      Incomplete
Task Id:     e582b358-7770-4474-bd44-0787e2b7245a

Operations:  auto_publish, publish
Resources:   fedora17 (repository)
State:       Waiting
Start Time:  Unstarted
Finish Time: Incomplete
Result:      Incomplete
Task Id:     e510e5ca-31e0-4cb8-8225-5cc6fded4433

Comment 10 Preethi Thomas 2013-01-07 14:09:36 UTC

Pulp 2.0 released.