Issue #1932: More gracefully handle KeyError when an rpm has no data in filelists.xml nor in other.xml - RPM Support - Pulp

Actions

Send by e-mail Copy link

Issue #1932

closed

More gracefully handle KeyError when an rpm has no data in filelists.xml nor in other.xml

Added by dgao@redhat.com over 8 years ago. Updated over 5 years ago.

Status:

CLOSED - DUPLICATE

Priority:

Normal

Assignee:

Sprint/Milestone:

Start date:

Due date:

Estimated time:

Severity:

1. Low

Version:

2.8.3

Platform Release:

OS:

RHEL 7

Triaged:

Yes

Groomed:

Sprint Candidate:

Tags:

Pulp 2

Sprint:

Quarter:

Description

Encountered this error while trying to sync repo with feed-url of: https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/rhev-mgmt-agent/3/os/

May 19 10:30:02 localhost pulp: pulp_rpm.plugins.importers.yum.sync:INFO: Determining which units need to be downloaded.
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512) '\xff\xff\xff\xff\xd8\xec2\x05'
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512) Traceback (most recent call last):
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 220, in run
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)     self.update_content(metadata_files, url)
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 451, in update_content
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)     self.download_rpms(metadata_files, rpms_to_download, url)
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 643, in download_rpms
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)     self.add_rpm_unit(metadata_files, unit)
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 595, in add_rpm_unit
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)     metadata_files.add_repodata(unit)
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/repomd/metadata.py", line 338, in add_repodata
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512)     raw_xml = db_file[db_key]
May 19 10:30:08 localhost pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (3528-08512) KeyError: '\xff\xff\xff\xff\xd8\xec2\x05'
May 19 10:30:08 localhost pulp: pulp.server.event.http:INFO: (3528-08512) {"call_report": {"exception": null, "task_type": "pulp.server.managers.repo.sync.sync", "_href": "/pulp/api/v2/tasks/52a86064-e9a9-4401-84bc-2a7ed4dee24b/", "task_id": "52a86064-e9a9-4401-84bc-2a7ed4dee24b", "tags": ["pulp:repository:Default_Organization-Red_Hat_Enterprise_Virtualization-Red_Hat_Enterprise_Virtualization_Management_Agents_for_RHEL_7_RPMs_x86_64_7Server", "pulp:action:sync"], "finish_time": null, "_ns": "task_status", "start_time": "2016-05-19T14:29:50Z", "traceback": null, "spawned_tasks": [], "progress_report": {"yum_importer": {"content": {"size_total": 5641369641, "items_left": 14, "items_total": 525, "state": "FAILED", "size_left": 8844392, "details": {"rpm_total": 525, "rpm_done": 511, "drpm_total": 0, "drpm_done": 0}, "error": "'\\xff\\xff\\xff\\xff\\xd8\\xec2\\x05'", "error_details": []}, "comps": {"state": "NOT_STARTED"}, "purge_duplicates": {"state": "NOT_STARTED"}, "distribution": {"items_total": 0, "state": "NOT_STARTED", "error_details": [], "items_left": 0}, "errata": {"state": "NOT_STARTED"}, "metadata": {"state": "FINISHED"}}}, "state": "running", "worker_name": "reserved_resource_worker-1@qci.example.com", "result": null, "error": null, "_id": {"$oid": "573dcdce3acc973a58ccf90e"}, "id": "573dcdce3acc973a58ccf90e"}, "event_type": "repo.sync.finish", "payload": {"importer_id": "yum_importer", "exception": null, "repo_id": "Default_Organization-Red_Hat_Enterprise_Virtualization-Red_Hat_Enterprise_Virtualization_Management_Agents_for_RHEL_7_RPMs_x86_64_7Server", "traceback": null, "started": "2016-05-19T14:29:50Z", "_ns": "repo_sync_results", "completed": "2016-05-19T14:30:08Z", "importer_type_id": "yum_importer", "error_message": null, "summary": {"content": {"state": "FAILED"}, "comps": {"state": "NOT_STARTED"}, "purge_duplicates": {"state": "NOT_STARTED"}, "distribution": {"state": "NOT_STARTED"}, "errata": {"state": "NOT_STARTED"}, "metadata": {"state": "FINISHED"}}, "added_count": 511, "result": "failed", "updated_count": 0,
May 19 10:30:08 localhost pulp: pulp.server.event.http:INFO: (3528-08512) "details": {"content": {"size_total": 5641369641, "items_left": 14, "items_total": 525, "state": "FAILED", "size_left": 8844392, "details": {"rpm_total": 525, "rpm_done": 511, "drpm_total": 0, "drpm_done": 0}, "error": "'\\xff\\xff\\xff\\xff\\xd8\\xec2\\x05'", "error_details": []}, "comps": {"state": "NOT_STARTED"}, "purge_duplicates": {"state": "NOT_STARTED"}, "distribution": {"items_total": 0, "state": "NOT_STARTED", "error_details": [], "items_left": 0}, "errata": {"state": "NOT_STARTED"}, "metadata": {"state": "FINISHED"}}, "id": "573dcdf016b1580dc8987e1f", "removed_count": 0}}
May 19 10:30:08 localhost pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): qci.example.com
May 19 10:30:08 localhost pulp: pulp.server.async.tasks:INFO: Task failed : [52a86064-e9a9-4401-84bc-2a7ed4dee24b]
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512) Task pulp.server.managers.repo.sync.sync[52a86064-e9a9-4401-84bc-2a7ed4dee24b] raised unexpected: PulpExecutionException('Importer indicated a failed response',)
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512) Traceback (most recent call last):
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)     R = retval = fun(*args, **kwargs)
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 473, in __call__
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)     return super(Task, self).__call__(*args, **kwargs)
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 103, in __call__
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)     return super(PulpTask, self).__call__(*args, **kwargs)
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)     return self.run(*args, **kwargs)
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)   File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 810, in sync
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512)     raise pulp_exceptions.PulpExecutionException(_('Importer indicated a failed response'))
May 19 10:30:08 localhost pulp: celery.worker.job:ERROR: (3153-08512) PulpExecutionException: Importer indicated a failed response
May 19 10:30:08 localhost pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[b437ad56-93e5-48f8-bf68-a6347b39b715] succeeded in 0.0128640589974s: None

[root@ip-10-0-0-30 rpm]# rpm -qa | grep "pulp"
python-pulp-common-2.8.3-1.el7.noarch
pulp-docker-plugins-2.0.1-1.el7.noarch
python-isodate-0.5.0-4.pulp.el7.noarch
python-kombu-3.0.33-5.pulp.el7.noarch
python-pulp-client-lib-2.8.3-1.el7.noarch
python-pulp-bindings-2.8.3-1.el7.noarch
pulp-admin-client-2.8.3-1.el7.noarch
python-pulp-docker-common-2.0.1-1.el7.noarch
pulp-selinux-2.8.3-1.el7.noarch
pulp-server-2.8.3-1.el7.noarch
pulp-puppet-plugins-2.8.3-1.el7.noarch
python-pulp-repoauth-2.8.3-1.el7.noarch
python-pulp-rpm-common-2.8.3-1.el7.noarch
python-pulp-oid_validation-2.8.3-1.el7.noarch
pulp-rpm-admin-extensions-2.8.3-1.el7.noarch
python-pulp-puppet-common-2.8.3-1.el7.noarch
pulp-rpm-plugins-2.8.3-1.el7.noarch

Files

fail-to-sync-sat61-rhel6.txt (10.7 KB) fail-to-sync-sat61-rhel6.txt

Log output from another user who hit the same problem

mhrivnak, 05/23/2016 05:50 PM

Related issues

Actions

Copy link

Updated by ttereshc over 8 years ago

Project changed from Pulp to RPM Support

This error occurs when there is no data for some rpms from the repo in the filelists.xml or in the other.xml files.
For example, the repo mentioned in this issue has no data for libcacard-rhev-2.3.0-31.el7_2.12.x86_64.rpm neither in filelists.xml nor in other.xml

Actions

Copy link

Updated by mhrivnak over 8 years ago

File fail-to-sync-sat61-rhel6.txt fail-to-sync-sat61-rhel6.txt added

Actions

Copy link

Updated by semyers over 8 years ago

This came up in triage today. My understanding of this issue is that we don't yet know if this is a CDN issue and pulp should handle the error more gracefully, or if the CDN data was valid and this is a pulp issue. If possible, please add information to this issue so we can triage it next week.

Actions

Copy link

Updated by dkliban@redhat.com over 8 years ago

Severity changed from 3. High to 1. Low
Triaged changed from No to Yes

Actions

Copy link

Updated by ttereshc over 8 years ago

I was about to submit an issue with RCM to fix repositories on CDN, but now everything is working and I am unable to find a broken repository. All the repos which were broken before are good now. So I guess this CDN problem was fixed.

We still need to handle such error more gracefully.

Actions

Copy link

Updated by dgregor@redhat.com over 8 years ago

Does someone have a reproducer? I'm not quite clear on the situation that triggers this.

Actions

Copy link

Updated by bmbouter over 8 years ago

Subject changed from KeyError: '\xff\xff\xff\xff\xd8\xec2\x05' to More gracefully handle KeyError when an rpm has no data in filelists.xml nor in other.xml

Actions

Copy link

#11

Updated by mhrivnak over 8 years ago

An interesting behavioral difference is seen between on_demand vs. immediate sync. When the problem is encountered:

on_demand: the task fails right away and shows an ugly error message.

immediate: the task continues and gets its status marked as SUCCESS. (This is a long-standing sync behavior, that if a couple out of 15k downloads fail, that's not unusual and shouldn't cause the task to be marked as failed. That's up for debate, but not here and now.) The problem is that the task status shows no helpful information except that some of the RPMs were not fetched. Here is an example:

$ pulp-admin tasks details --task-id=fb1a8d9f-322d-435e-a7ee-27aed12ad373
+----------------------------------------------------------------------+
                              Task Details
+----------------------------------------------------------------------+

Operations:       sync
Resources:        os3 (repository)
State:            Successful
Start Time:       2016-06-20T16:36:04Z
Finish Time:      2016-06-20T16:38:24Z
Result:           
  Added Count:      489
  Completed:        2016-06-20T16:38:24Z
  Details:          
    Comps:            
      State: FINISHED
    Content:          
      Details:       
        Drpm Done:  0
        Drpm Total: 0
        Rpm Done:   477
        Rpm Total:  496
      Error Details: 
      Items Left:    19
      Items Total:   496
      Size Left:     90663740
      Size Total:    456536072
      State:         FINISHED
    Distribution:     
      Error Details: 
      Items Left:    0
      Items Total:   0
      State:         FINISHED
    Errata:           
      State: FINISHED
    Metadata:         
      State: FINISHED
    Purge Duplicates: 
      State: FINISHED
  Error Message:    None
  Exception:        None
  Id:               57681c00e7798973d9b949b0
  Importer Id:      yum_importer
  Importer Type Id: yum_importer
  Removed Count:    0
  Repo Id:          os3
  Result:           success
  Started:          2016-06-20T16:36:04Z
  Summary:          
    Comps:            
      State: FINISHED
    Content:          
      State: FINISHED
    Distribution:     
      State: FINISHED
    Errata:           
      State: FINISHED
    Metadata:         
      State: FINISHED
    Purge Duplicates: 
      State: FINISHED
  Traceback:        None
  Updated Count:    0
Task Id:          fb1a8d9f-322d-435e-a7ee-27aed12ad373
Progress Report:  
  Yum Importer: 
    Comps:            
      State: FINISHED
    Content:          
      Details:       
        Drpm Done:  0
        Drpm Total: 0
        Rpm Done:   477
        Rpm Total:  496
      Error Details: 
      Items Left:    19
      Items Total:   496
      Size Left:     90663740
      Size Total:    456536072
      State:         FINISHED
    Distribution:     
      Error Details: 
      Items Left:    0
      Items Total:   0
      State:         FINISHED
    Errata:           
      State: FINISHED
    Metadata:         
      State: FINISHED
    Purge Duplicates: 
      State: FINISHED

Based on pulp-admin output, and perhaps (I'm speculating based on the BZ) katello output, the user has no idea anything went wrong. Even a savvy user who noticed the task status won't have any idea what went wrong unless they look in the log, which is filled with ugly tracebacks.

Actions

Copy link

#12