Project

Profile

Help

Issue #3845

Pulp discards error message on ISO sync validation failure

Added by rmcgover over 3 years ago. Updated over 2 years ago.

Status:
CLOSED - CURRENTRELEASE
Priority:
Normal
Assignee:
Sprint/Milestone:
-
Start date:
Due date:
Estimated time:
Severity:
1. Low
Version:
2.14.0
Platform Release:
2.17.0
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Pulp 2
Sprint:
Sprint 40
Quarter:

Description

A user reported an error during ISO sync where Pulp's given error messages were blank.

https://www.redhat.com/archives/pulp-list/2018-July/msg00001.html

The sync errors look like this:

Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936) Task pulp.server.managers.repo.sync.sync[41520be8-0395-4753-ac6a-ca
ff60bcfcb3] raised unexpected: Exception([{'name': u'rhel-server-6.10-x86_64-boot.iso', 'error': {}}, {'name': u'rhel-server-6.10-x86_64-dvd.iso', 'error': {}
}],)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936) Traceback (most recent call last):
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line
 367, in trace_task
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     R = retval = fun(*args, **kwargs)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py
", line 529, in __call__
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     return super(Task, self).__call__(*args, **kwargs)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py
", line 107, in __call__
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     return super(PulpTask, self).__call__(*args, **kwargs)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line
 622, in __protected_call__
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     return self.run(*args, **kwargs)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp/server/controllers/re
pository.py", line 769, in sync
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     sync_report = sync_repo(transfer_repo, conduit, call_config)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py
", line 737, in wrap_f
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     return f(*args, **kwargs)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers
/iso/importer.py", line 103, in sync_repo
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     report = self.iso_sync.perform_sync()
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers
/iso/sync.py", line 263, in perform_sync
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     self.progress_report.state = self.progress_report.STATE_COMPLET
E
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)   File "/usr/lib/python2.7/site-packages/pulp_rpm/common/progress.p
y", line 307, in _set_state
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936)     raise Exception(self.iso_error_messages)
Jul  5 06:15:02 pulp.college.edu pulp: celery.app.trace:ERROR: [41520be8] (98361-63936) Exception: [{'name': u'rhel-server-6.10-x86_64-boot.iso', 'error':
{}}, {'name': u'rhel-server-6.10-x86_64-dvd.iso', 'error': {}}]

Since the message contains an empty 'error', one can only review the Pulp code and make estimates at the cause of the error.

The reason for the empty error seems to be because Pulp catches the relevant exception and silently discards it.

See pulp_rpm/plugins/pulp_rpm/plugins/importers/iso/sync.py :

    def download_succeeded(self, report):
        """
        This is the callback that we will get from the downloader library when it succeeds in
        downloading a file. This method will check to see if we are in the ISO downloading stage,
        and if we are, it will add the new ISO to the database.

        :param report: The report of the file we downloaded
        :type  report: nectar.report.DownloadReport
        """
        # If we are in the isos stage, then this must be one of our ISOs.
        if self.progress_report.state == self.progress_report.STATE_ISOS_IN_PROGRESS:
            # This will update our bytes downloaded
            self.download_progress(report)
            iso = report.data
            iso.set_storage_path(os.path.basename(report.destination))
            try:
                if self._validate_downloads:
                    iso.validate_iso(report.destination)
                try:
                    iso.save()
                except NotUniqueError:
                    iso = iso.__class__.objects.filter(**iso.unit_key).first()
                self._associate_unit(self.sync_conduit.repo, iso)
                iso.safe_import_content(report.destination)

                # We can drop this ISO from the url --> ISO map
                self.progress_report.num_isos_finished += 1
                self.progress_report.update_progress()
            except ValueError:
                self.download_failed(report)

And pulp_rpm/plugins/pulp_rpm/plugins/db/models.py :

    def validate_iso(self, storage_path, full_validation=True):
        """
        Validate that the name of the ISO is not the same as the manifest's name. Also, if
        full_validation is True, validate that the file found at self.storage_path matches the size
        and checksum of self. A ValueError will be raised if the validation fails.

        :param storage_path   : The path to the file to perform validation on
        :type  storage_path   : basestring

        :param full_validation: Whether or not to perform validation on the size and checksum of the
                                ISO. Name validation is always performed.
        :type  full_validation: bool
        """
        # Don't allow PULP_MANIFEST to be the name
        if self.name == ISOManifest.FILENAME:
            msg = _('An ISO may not be named %(name)s, as it conflicts with the name of the '
                    'manifest during publishing.')
            msg = msg % {'name': ISOManifest.FILENAME}
            raise ValueError(msg)

        if full_validation:
            with open(storage_path) as destination_file:
                # Validate the size
                actual_size = self.calculate_size(destination_file)
                if actual_size != self.size:
                    raise ValueError(_('Downloading <%(name)s> failed validation. '
                                       'The manifest specified that the file should be %('
                                       'expected)s bytes, but '
                                       'the downloaded file is %(found)s bytes.') % {
                                     'name': self.name,
                                     'expected': self.size,
                                     'found': actual_size})

                # Validate the checksum
                actual_checksum = self.calculate_checksum(destination_file)
                if actual_checksum != self.checksum:
                    raise ValueError(
                        _('Downloading <%(name)s> failed checksum validation. The manifest '
                          'specified the checksum to be %(c)s, but it was %(f)s.') % {
                            'name': self.name, 'c': self.checksum,
                            'f': actual_checksum})

Consider what happens if an ISO doesn't match PULP_MANIFEST:

- validate_iso raises a ValueError with a detailed error message
- download_succeeded catches the ValueError with the message, discards it (without even logging), and calls download_failed with the download report, which will not contain any error message (since the download succeeded)

This doesn't seem to make sense - all the error details are prepared, but then discarded, which only makes it more difficult to support Pulp users.

Steps to reproduce

- Manually set up a corrupted ISO repo (e.g. take a valid repo and then alter the size of a file in PULP_MANIFEST)
- Attempt to sync from the corrupted repo

Actual behavior

Pulp sync task fails, but logs produce no error details.

Expected behavior

Pulp sync task fails, and logs contain an error message explaining that a file failed validation against the manifest.


Related issues

Related to RPM Support - Issue #3899: Failed PULP_MANIFEST downloads aren't reported to the userCLOSED - CURRENTRELEASE<a title="Actions" class="icon-only icon-actions js-contextmenu" href="#">Actions</a>

Associated revisions

Revision 05d03329 View on GitHub
Added by werwty over 3 years ago

Display validation sync error failure message for ISO

When synced ISO fails validation, error message is not on the nectar report. Rather than trying to put this on the nector report pass the exception to the progress report and display it there.

closes #3845 https://pulp.plan.io/issues/3845

History

#1 Updated by CodeHeeler over 3 years ago

  • Triaged changed from No to Yes
  • Sprint set to Sprint 39

#2 Updated by dkliban@redhat.com over 3 years ago

  • Sprint changed from Sprint 39 to Sprint 40

#3 Updated by bizhang over 3 years ago

  • Status changed from NEW to ASSIGNED
  • Assignee set to bizhang

#4 Updated by bizhang over 3 years ago

  • Status changed from ASSIGNED to POST

#5 Updated by werwty over 3 years ago

  • Status changed from POST to MODIFIED

#6 Updated by daviddavis over 3 years ago

  • Related to Issue #3899: Failed PULP_MANIFEST downloads aren't reported to the user added

#8 Updated by dkliban@redhat.com about 3 years ago

  • Status changed from MODIFIED to CLOSED - CURRENTRELEASE
  • Platform Release set to 2.17.0

#9 Updated by bmbouter over 2 years ago

  • Tags Pulp 2 added

Please register to edit this issue

Also available in: Atom PDF