RPM Support

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.