Project

Profile

Help

Issue #2378

closed

Bad merges forward on 2.10-dev

Added by semyers over 7 years ago. Updated about 5 years ago.

Status:
CLOSED - CURRENTRELEASE
Priority:
Urgent
Assignee:
Category:
-
Sprint/Milestone:
-
Start date:
Due date:
Estimated time:
Severity:
3. High
Version:
2.10.1
Platform Release:
2.10.2
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Pulp 2
Sprint:
Quarter:

Description

A user reported https://pulp.plan.io/issues/2377 this evening, which is bad, because that migration (platform #25) was introduced in 2.11, and the user had just upgraded to 2.10.1. This is potentially a catastrophically bad thing, so I'm marking this urgent. I expect that this will result in a 2.10.2 hotfix.

mhrivnak was able to provide a workaround to the user reporting #2377, which we'll hopefully post soon.

I went through all of the issues currently MODIFIED for 2.11 and found the hashes of the related commits that erroneously appear on 2.10-dev:

9ac632e0d835eb580243c1c5cc781702a8ece117 https://pulp.plan.io/issues/2212
206cf5fd7bfd94cf994d528ac68019f143e92be8 https://pulp.plan.io/issues/1977
c4d73c7c5079d40f76812b745c55c8ea5f12f9cc https://pulp.plan.io/issues/2133
dd7c19bb12a0904ad0e5bc67e430f7c4c9d93a22 https://pulp.plan.io/issues/1069
6868481c1a0eeab06d1f18330e7fd7dc533d8007 https://pulp.plan.io/issues/1983
53e6c59c72eb2e4984d2e188e27f4ae0eebd68e9 https://pulp.plan.io/issues/752
0aa13525daad61991ac69ed780e24757eef37e40 https://pulp.plan.io/issues/2132
470ce15ddbc4fb06d36a36c8c751e605689448bb

I've created a branch that rolls back all of these commits in reverse-chronological order on the current tip of 2.10-dev (the 2.10.1 release): https://github.com/pulp/pulp/compare/2.10-dev...seandst:fix-2.10-merge-forward

The new migration causes a tricky problem, though, because it shouldn't exist in 2.10.1, and fails in 2.10.1 with an unknown (but greater than 0) probability. So, not only do we need to fix migration #25, we probably need to turn it into a no-op in 2.10, and write a new migration #26 for 2.11 that isn't broken, and is aware that some version of migration #25 may have run in the past. That's just my current and uninvestigated thinking, so I'm open to ideas.

Right now I see it as a scenario where "you can't un-ring that bell".


Related issues

Related to Pulp - Issue #2377: 0025_importer_schema_change hits issue with last_sync being NoneCLOSED - CURRENTRELEASEsemyersActions
Actions #1

Updated by mhrivnak over 7 years ago

Agreed about the bell.

Oddly enough, I think there's more to the migration resolution. We need to:

1. In 2.10.2 turn migration #25 into a no-op
2. In 2.10.2 make migration #26 to remove the new fields that migration #25 added. We have to do this because the code rollback removes them from the Importer model.
3. add migration #27 in 2.11 to add those fields back

Actions #2

Updated by mhrivnak over 7 years ago

In case it's helpful, this is the commit where 2.11 code was merged into 2.10:

https://github.com/pulp/pulp/commit/1d4088385ae973e2b14c7e591468ac9e51dbdb64

The "right" side of it, commit fc9f5f9, contains the 2.11 code.

Added by mhrivnak over 7 years ago

Revision 343961aa | View on GitHub

Converts migration 0025 to a no-op and reverts its changes.

For details, see https://pulp.plan.io/issues/2378 re #2378

Added by mhrivnak over 7 years ago

Revision 343961aa | View on GitHub

Converts migration 0025 to a no-op and reverts its changes.

For details, see https://pulp.plan.io/issues/2378 re #2378

Actions #3

Updated by mhrivnak over 7 years ago

I'm getting lots of 500s from github right now, but I did push a branch that probably addresses steps 1 and 2 above. I don't have a dev environment going at the moment, so I can't test it.

With github broken, I'm speculating that this link will eventually work: https://github.com/pulp/pulp/compare/2.10-dev...mhrivnak:2378?expand=1

Actions #4

Updated by mhrivnak over 7 years ago

This could become the new migration 0027. It fixes the original bug, adds a try...except block around parsing, and stops using code from pulp.common. It was just as easy to use the "isodate" library directly.

import datetime

import isodate

from pulp.server.db.connection import get_collection

def migrate(*args, **kwargs):
    """ 
    Add last_updated and last_override_config to the importer collection.
    """
    updated_key = 'last_updated'
    config_key = 'last_override_config'
    collection = get_collection('repo_importers')

    for importer in collection.find():
        if updated_key in importer:
            continue

        if config_key not in importer:
            importer[config_key] = {}

        try:
            importer[updated_key] = isodate.parse_datetime(importer['last_sync'])
        # The attribute doesn't exist, or parsing failed. It's safe to set a newer timestamp.
        except:
            importer[updated_key] = datetime.datetime.now(tz=isodate.UTC)

        collection.save(importer)
Actions #5

Updated by semyers over 7 years ago

mhrivnak wrote:

In case it's helpful, this is the commit where 2.11 code was merged into 2.10:

https://github.com/pulp/pulp/commit/1d4088385ae973e2b14c7e591468ac9e51dbdb64

The "right" side of it, commit fc9f5f9, contains the 2.11 code.

I'm comparing this to my reversion branch and updating accordingly.

Actions #6

Updated by amacdona@redhat.com over 7 years ago

  • Triaged changed from No to Yes
Actions #7

Updated by semyers over 7 years ago

  • Description updated (diff)

0aa13525daad61991ac69ed780e24757eef37e40 added to the list of erroneous merges forward.

Actions #8

Updated by semyers over 7 years ago

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

Things are a little spread out, but here's what I'm thinking:

  1. I've already got a branch with the reverts, so I'll start there
  2. Bring back the commit that adds migration 25
  3. Turn migration 25 into a no-op for 2.10
  4. Create migration 26 that cleans up after migration 25 for unlucky users that have already partially run the former migration 25

This should get 2.10-dev into a good state. After that:

  1. Create a migration #27 for 2.11, modified to function more like https://pulp.plan.io/issues/2377#note-4
  2. Merge the revert changes forward from 2.10-dev without actually removing the features that should be in 2.11.
Actions #9

Updated by semyers over 7 years ago

Just to clarify the work needed here.

These steps fix 2.10.1 and unblock the 2.10.2 release. They are being POSTed shortly, and this issue will be done when they are merged and released:

  1. I've already got a branch with the reverts, so I'll start there
  2. Bring back the commit that adds migration 25
  3. Turn migration 25 into a no-op for 2.10
  4. Create migration 26 that cleans up after migration 25 for unlucky users that have already partially run the former migration 25

This step will be done as part of merging this fix forward through 2.11 to master, and must be done before #2377 can be started.

  1. Merge the revert changes forward from 2.10-dev without actually removing the features that should be in 2.11.

This will resolve #2377 and unblock the next beta release of 2.11:

  1. Create a migration #27 for 2.11, modified to function more like https://pulp.plan.io/issues/2377#note-4

Added by semyers over 7 years ago

Revision c77ba648 | View on GitHub

test for migration 0026 + lint

fixes #2378 https://pulp.plan.io/issues/2378

Added by semyers over 7 years ago

Revision c77ba648 | View on GitHub

test for migration 0026 + lint

fixes #2378 https://pulp.plan.io/issues/2378

Actions #10

Updated by semyers over 7 years ago

  • Status changed from ASSIGNED to POST
  • Platform Release set to 2.10.2
Actions #11

Updated by semyers over 7 years ago

  • Description updated (diff)

470ce15ddbc4fb06d36a36c8c751e605689448bb added to changeset list

Actions #12

Updated by semyers over 7 years ago

  • Status changed from POST to MODIFIED
Actions #14

Updated by semyers over 7 years ago

2.10.2 is available for testing. Testing for this might be a little bit difficult since it's correcting a bad merge. Some thoughts about how this could be tested include:

- Upgrading to Pulp 2.10.1 would fail if an Importers had a field named "last_sync" set to a null/None value. Pulp 2.10.2 should not fail to upgrade in this case.
- Users upgrading to Pulp may have ended up with two new Importer fields named "last_updated" and "last_override_config". If these fields exist on any Importers prior to running the migrations introduced in 2.10.1, they should no longer exist after upgrading to pulp 2.10.2 and running migrations.

Since 2.10.2 is a hotfix release, this issue must be VERIFIED prior to release.

Actions #15

Updated by semyers over 7 years ago

  • Status changed from MODIFIED to 5
Actions #18

Updated by pthomas@redhat.com over 7 years ago

  • Status changed from 5 to ASSIGNED

Here is a situation I have noticed

1. Synced 3 repos in 2.10 and 2.9
2. updated the mongo repo_importers to make sure that I have last_sync set to None and null on 2 of the repos
3.Upgraded to 2.10.2 beta
4. Ran migration
5. Checked mongo
6. Ran resync
7. The first time it synced it failed
8. Ran the sync again it was successful

Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456) Malformed ISO8601 date-time string: None
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456) Traceback (most recent call last):
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 217, in run
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)     metadata_files = self.get_metadata(metadata_files)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 362, in get_metadata
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)     last_sync = dateutils.parse_iso8601_datetime(last_sync)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)   File "/usr/lib/python2.7/site-packages/pulp/common/dateutils.py", line 176, in parse_iso8601_datetime
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)     return isodate.parse_datetime(datetime_str)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)   File "/usr/lib/python2.7/site-packages/isodate/isodatetime.py", line 48, in parse_datetime
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456)     datestring, timestring = datetimestring.split('T')
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp_rpm.plugins.importers.yum.sync:ERROR: (17940-99456) ISO8601Error: Malformed ISO8601 date-time string: None
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17940]: pulp.server.async.tasks:INFO: Task failed : [490752a1-9e2e-451e-b5bc-c51ae104660a]
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456) Task pulp.server.managers.repo.sync.sync[490752a1-9e2e-451e-b5bc-c51ae104660a] raised unexpected: PulpExecutionException('Importer indicated a failed response',)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456) Traceback (most recent call last):
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)     R = retval = fun(*args, **kwargs)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 488, in __call__
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)     return super(Task, self).__call__(*args, **kwargs)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 103, in __call__
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)     return super(PulpTask, self).__call__(*args, **kwargs)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)     return self.run(*args, **kwargs)
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)   File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 810, in sync
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456)     raise pulp_exceptions.PulpExecutionException(_('Importer indicated a failed response'))
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:ERROR: (17362-99456) PulpExecutionException: Importer indicated a failed response
Nov 11 15:10:51 ibm-x3550m3-10.lab.eng.brq.redhat.com pulp[17362]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[af76af43-e54f-4b71-8068-37c10590861c] succeeded in 0.0060398889982s: None
Actions #19

Updated by semyers over 7 years ago

  • Related to Issue #2377: 0025_importer_schema_change hits issue with last_sync being None added
Actions #20

Updated by semyers over 7 years ago

wrote:

2. updated the mongo repo_importers to make sure that I have last_sync set to None and null on 2 of the repos

As I've gotten to know these issues better the last_sync = None issue should only pop up for users upgrading from Pulp 2.7, so I'll take a closer look at this to see if we already have a migration to cover this case, or if this migration needs a tweak to handle it.

Do you have any feedback on this case?

Users upgrading to Pulp may have ended up with two new Importer fields named "last_updated" and "last_override_config". If these fields exist on any Importers prior to running the migrations introduced in 2.10.1, they should no longer exist after upgrading to pulp 2.10.2 and running migrations.

Actions #21

Updated by pthomas@redhat.com over 7 years ago

Do you have any feedback on this case?

Users upgrading to Pulp may have ended up with two new Importer fields named "last_updated" and "last_override_config". If these fields exist on any Importers prior to running the migrations introduced in 2.10.1, they should no longer exist after upgrading to pulp 2.10.2 and running migrations.

I am slightly confused on this. I do not see these fields in any of the importers prior to upgrade. So I am not sure if am infact looking at the right field/collection


This is pre upgrade

db.repo_importers.find()
{ "_id" : ObjectId("5825c5440e8c23397e004fc6"), "repo_id" : "rhel7", "importer_type_id" : "yum_importer", "config" : { "feed" : "http://cdn.rcm-internal.redhat.com/content/dist/rhel/rhui/server/7/7.2/x86_64/os/", "download_policy" : "on_demand" }, "_ns" : "repo_importers", "scratchpad" : { "repomd_revision" : 1470241032, "previous_skip_list" : [ ] }, "last_sync" : "None" }
> 

Post Upgrade

 db.repo_importers.find()
{ "_id" : ObjectId("5825c5440e8c23397e004fc6"), "repo_id" : "rhel7", "importer_type_id" : "yum_importer", "config" : { "feed" : "http://cdn.rcm-internal.redhat.com/content/dist/rhel/rhui/server/7/7.2/x86_64/os/", "download_policy" : "on_demand" }, "_ns" : "repo_importers", "scratchpad" : { "repomd_revision" : 1470241032, "previous_skip_list" : [ ] }, "last_sync" : "2016-11-11T14:11:19Z" }
Actions #22

Updated by semyers over 7 years ago

Those fields would have been erroneously added to importers when they ran a migration intended for 2.11 on a pulp system running 2.10.0. I don't know of a way to programatically add those fields to a system attempting to upgrade/migrate to 2.10.2, so I think they may have to manually be added.

Actions #23

Updated by semyers over 7 years ago

Regarding the failure in https://pulp.plan.io/issues/2378#note-18, the traceback indicates that the value for last_sync was neither null nor a parseable iso8601 datestamp. Looking at the quoted sections in https://pulp.plan.io/issues/2378#note-21, I see "last_sync" : "None", which is invalid, and as far as I can tell is a situation that pulp itself will never create. Its value should be null in MongoDB, which is represented by None in python.

preethi, could you test again with last_sync set to null?

Actions #24

Updated by semyers over 7 years ago

  • Status changed from ASSIGNED to 5
Actions #25

Updated by pthomas@redhat.com over 7 years ago

Do you have any feedback on this case?

Users upgrading to Pulp may have ended up with two new Importer fields named "last_updated" and "last_override_config". If these fields exist on any Importers prior to running the migrations introduced in 2.10.1, they should no longer exist after upgrading to pulp 2.10.2 and running migrations.

Added "last_updated" and "last_override_config" to the db pre upgrade and after upgrade, running the migration unset those


>db.repo_importers.update(     { "repo_id" : "zoo" },     {       $set: { "last_updated": "None" }   } )
> 
> 
> db.repo_importers.update(     { "repo_id" : "zoo" },     {       $set: { "last_override_config": "None" }   } )
> 

db.repo_importers.find()
{ "_id" : ObjectId("58260f55e8ec9821560f4b2a"), "_ns" : "repo_importers", "config" : { "feed" : "https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm/" }, "importer_type_id" : "yum_importer", "last_override_config" : "None", "last_sync" : "2016-11-11T18:57:16Z", "last_updated" : "None", "repo_id" : "zoo", "scratchpad" : { "repomd_revision" : 1478850732, "previous_skip_list" : [ ] } }

[root@mgmt12 ~]#   sudo -u apache pulp-manage-db
Attempting to connect to localhost:27017
Attempting to connect to localhost:27017
Write concern for Mongo connection: {}
/usr/lib/python2.6/site-packages/pulp/server/db/connection.py:159: DeprecationWarning: add_son_manipulator is deprecated
  _DATABASE.add_son_manipulator(NamespaceInjector())
Loading content types.
Loading type descriptors []
Parsing type descriptors
Validating type descriptor syntactic integrity
Validating type descriptor semantic integrity
Loading unit model: docker_blob = pulp_docker.plugins.models:Blob
Loading unit model: docker_manifest = pulp_docker.plugins.models:Manifest
Loading unit model: docker_image = pulp_docker.plugins.models:Image
Loading unit model: docker_tag = pulp_docker.plugins.models:Tag
Loading unit model: python_package = pulp_python.plugins.models:Package
Loading unit model: erratum = pulp_rpm.plugins.db.models:Errata
Loading unit model: distribution = pulp_rpm.plugins.db.models:Distribution
Loading unit model: srpm = pulp_rpm.plugins.db.models:SRPM
Loading unit model: package_group = pulp_rpm.plugins.db.models:PackageGroup
Loading unit model: package_category = pulp_rpm.plugins.db.models:PackageCategory
Loading unit model: iso = pulp_rpm.plugins.db.models:ISO
Loading unit model: package_environment = pulp_rpm.plugins.db.models:PackageEnvironment
Loading unit model: drpm = pulp_rpm.plugins.db.models:DRPM
Loading unit model: package_langpacks = pulp_rpm.plugins.db.models:PackageLangpacks
Loading unit model: rpm = pulp_rpm.plugins.db.models:RPM
Loading unit model: yum_repo_metadata_file = pulp_rpm.plugins.db.models:YumMetadataFile
Loading unit model: puppet_module = pulp_puppet.plugins.db.models:Module
Updating the database with types []
/usr/lib/python2.6/site-packages/pulp/server/db/model/base.py:96: DeprecationWarning: ensure_index is deprecated. Use create_index instead.
  unique=unique, background=True)
Found the following type definitions that were not present in the update collection [puppet_module, drpm, package_langpacks, docker_manifest, docker_blob, erratum, yum_repo_metadata_file, package_group, package_category, iso, package_environment, docker_tag, python_package, srpm, rpm, distribution, docker_image]
Updating the database with types [puppet_module, drpm, package_langpacks, erratum, docker_blob, docker_manifest, yum_repo_metadata_file, package_group, package_category, iso, package_environment, docker_tag, python_package, distribution, rpm, srpm, docker_image]
/usr/lib/python2.6/site-packages/pulp/plugins/types/database.py:277: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
  content_type_collection.save(content_type)
Content types loaded.
Ensuring the admin role and user are in place.
Admin role and user are in place.
Beginning database migrations.
Applying pulp.server.db.migrations version 25
/usr/lib/python2.6/site-packages/mongoengine/document.py:367: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  upsert=upsert, **write_concern)
Migration to pulp.server.db.migrations version 25 complete.
Applying pulp.server.db.migrations version 26
/usr/lib/python2.6/site-packages/pulp/server/db/migrations/0026_revert_0025.py:13: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  collection.update({}, {'$unset': {'last_updated': 1}}, multi=True)
/usr/lib/python2.6/site-packages/pulp/server/db/migrations/0026_revert_0025.py:14: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  collection.update({}, {'$unset': {'last_override_config': 1}}, multi=True)
Migration to pulp.server.db.migrations version 26 complete.
Migration package pulp_docker.plugins.migrations is up to date at version 2
Migration package pulp_puppet.plugins.migrations is up to date at version 5
Migration package pulp_python.plugins.migrations is up to date at version 1
Applying pulp_rpm.plugins.migrations version 36
/usr/lib/python2.6/site-packages/pulp_rpm/plugins/migrations/0036_remove_srpm_drpm_checksum_type_field.py:24: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  multi=True
/usr/lib/python2.6/site-packages/pulp_rpm/plugins/migrations/0036_remove_srpm_drpm_checksum_type_field.py:29: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  multi=True
Migration to pulp_rpm.plugins.migrations version 36 complete.
Loading unit model: docker_blob = pulp_docker.plugins.models:Blob
Loading unit model: docker_manifest = pulp_docker.plugins.models:Manifest
Loading unit model: docker_image = pulp_docker.plugins.models:Image
Loading unit model: docker_tag = pulp_docker.plugins.models:Tag
Loading unit model: python_package = pulp_python.plugins.models:Package
Loading unit model: erratum = pulp_rpm.plugins.db.models:Errata
Loading unit model: distribution = pulp_rpm.plugins.db.models:Distribution
Loading unit model: srpm = pulp_rpm.plugins.db.models:SRPM
Loading unit model: package_group = pulp_rpm.plugins.db.models:PackageGroup
Loading unit model: package_category = pulp_rpm.plugins.db.models:PackageCategory
Loading unit model: iso = pulp_rpm.plugins.db.models:ISO
Loading unit model: package_environment = pulp_rpm.plugins.db.models:PackageEnvironment
Loading unit model: drpm = pulp_rpm.plugins.db.models:DRPM
Loading unit model: package_langpacks = pulp_rpm.plugins.db.models:PackageLangpacks
Loading unit model: rpm = pulp_rpm.plugins.db.models:RPM
Loading unit model: yum_repo_metadata_file = pulp_rpm.plugins.db.models:YumMetadataFile
Loading unit model: puppet_module = pulp_puppet.plugins.db.models:Module
Database migrations complete.
[root@mgmt12 ~]# service httpd start
Starting httpd: [  OK  ]
[root@mgmt12 ~]# service pulp_workers start
celery init v10.0.
Using config script: /etc/default/pulp_workers
celery multi v3.1.11 (Cipater)
> Starting nodes...
    > reserved_resource_worker-0@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-1@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-2@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-3@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-4@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-5@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-6@mgmt12.rhq.lab.eng.bos.redhat.com: OK
    > reserved_resource_worker-7@mgmt12.rhq.lab.eng.bos.redhat.com: OK

> use pulp_dataase
switched to db pulp_dataase
> db.repo_importers.find()
> 
> 
> use pulp_database
switched to db pulp_database
> db.repo_importers.find()
{ "_id" : ObjectId("58260f55e8ec9821560f4b2a"), "_ns" : "repo_importers", "config" : { "feed" : "https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm/" }, "importer_type_id" : "yum_importer", "last_sync" : "2016-11-11T18:57:16Z", "repo_id" : "zoo", "scratchpad" : { "repomd_revision" : 1478850732, "previous_skip_list" : [ ] } }
> 

</pre?
Actions #26

Updated by pthomas@redhat.com over 7 years ago

  • Status changed from 5 to ASSIGNED

I have retried this with "last_sync: null" as well and same failure occurs

> 
> db.repo_importers.update(     { "repo_id" : "zoo" },     {       $set: { "last_sync": "null" }   } )
WriteResult({ "nMatched" : 1, "nUpserted" : 0, "nModified" : 1 })
> 
> 
> db.repo_importers.find()
{ "_id" : ObjectId("58261de01661f00b3558afe7"), "repo_id" : "zoo", "importer_type_id" : "yum_importer", "config" : { "feed" : "https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm/" }, "_ns" : "repo_importers", "scratchpad" : { "repomd_revision" : 1478850732, "previous_skip_list" : [ ] }, "last_sync" : "null" }
> 

[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# sudo -u apache pulp-manage-db
Attempting to connect to localhost:27017
Attempting to connect to localhost:27017
Write concern for Mongo connection: {}
Loading content types.
Loading type descriptors []
Parsing type descriptors
Validating type descriptor syntactic integrity
Validating type descriptor semantic integrity
Loading unit model: python_package = pulp_python.plugins.models:Package
Loading unit model: erratum = pulp_rpm.plugins.db.models:Errata
Loading unit model: distribution = pulp_rpm.plugins.db.models:Distribution
Loading unit model: srpm = pulp_rpm.plugins.db.models:SRPM
Loading unit model: package_group = pulp_rpm.plugins.db.models:PackageGroup
Loading unit model: package_category = pulp_rpm.plugins.db.models:PackageCategory
Loading unit model: iso = pulp_rpm.plugins.db.models:ISO
Loading unit model: package_environment = pulp_rpm.plugins.db.models:PackageEnvironment
Loading unit model: drpm = pulp_rpm.plugins.db.models:DRPM
Loading unit model: package_langpacks = pulp_rpm.plugins.db.models:PackageLangpacks
Loading unit model: rpm = pulp_rpm.plugins.db.models:RPM
Loading unit model: yum_repo_metadata_file = pulp_rpm.plugins.db.models:YumMetadataFile
Loading unit model: docker_blob = pulp_docker.plugins.models:Blob
Loading unit model: docker_manifest = pulp_docker.plugins.models:Manifest
Loading unit model: docker_image = pulp_docker.plugins.models:Image
Loading unit model: docker_tag = pulp_docker.plugins.models:Tag
Loading unit model: ostree = pulp_ostree.plugins.db.model:Branch
Loading unit model: puppet_module = pulp_puppet.plugins.db.models:Module
Updating the database with types []
Found the following type definitions that were not present in the update collection [puppet_module, docker_tag, ostree, package_langpacks, erratum, docker_blob, docker_manifest, yum_repo_metadata_file, package_group, package_category, iso, package_environment, drpm, python_package, srpm, rpm, distribution, docker_image]
Updating the database with types [puppet_module, docker_tag, ostree, package_langpacks, erratum, python_package, docker_manifest, yum_repo_metadata_file, package_group, docker_blob, package_category, iso, package_environment, drpm, distribution, rpm, srpm, docker_image]
Content types loaded.
Ensuring the admin role and user are in place.
Admin role and user are in place.
Beginning database migrations.
Applying pulp.server.db.migrations version 25
/usr/lib/python2.7/site-packages/mongoengine/document.py:367: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  upsert=upsert, **write_concern)

Migration to pulp.server.db.migrations version 25 complete.
Applying pulp.server.db.migrations version 26
/usr/lib/python2.7/site-packages/pulp/server/db/migrations/0026_revert_0025.py:13: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  collection.update({}, {'$unset': {'last_updated': 1}}, multi=True)

/usr/lib/python2.7/site-packages/pulp/server/db/migrations/0026_revert_0025.py:14: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  collection.update({}, {'$unset': {'last_override_config': 1}}, multi=True)

Migration to pulp.server.db.migrations version 26 complete.
Migration package pulp_docker.plugins.migrations is up to date at version 2
Migration package pulp_puppet.plugins.migrations is up to date at version 5
Migration package pulp_python.plugins.migrations is up to date at version 1
Applying pulp_rpm.plugins.migrations version 36
/usr/lib/python2.7/site-packages/pulp_rpm/plugins/migrations/0036_remove_srpm_drpm_checksum_type_field.py:24: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  multi=True

/usr/lib/python2.7/site-packages/pulp_rpm/plugins/migrations/0036_remove_srpm_drpm_checksum_type_field.py:29: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
  multi=True

Migration to pulp_rpm.plugins.migrations version 36 complete.
Loading unit model: python_package = pulp_python.plugins.models:Package
Loading unit model: erratum = pulp_rpm.plugins.db.models:Errata
Loading unit model: distribution = pulp_rpm.plugins.db.models:Distribution
Loading unit model: srpm = pulp_rpm.plugins.db.models:SRPM
Loading unit model: package_group = pulp_rpm.plugins.db.models:PackageGroup
Loading unit model: package_category = pulp_rpm.plugins.db.models:PackageCategory
Loading unit model: iso = pulp_rpm.plugins.db.models:ISO
Loading unit model: package_environment = pulp_rpm.plugins.db.models:PackageEnvironment
Loading unit model: drpm = pulp_rpm.plugins.db.models:DRPM
Loading unit model: package_langpacks = pulp_rpm.plugins.db.models:PackageLangpacks
Loading unit model: rpm = pulp_rpm.plugins.db.models:RPM
Loading unit model: yum_repo_metadata_file = pulp_rpm.plugins.db.models:YumMetadataFile
Loading unit model: docker_blob = pulp_docker.plugins.models:Blob
Loading unit model: docker_manifest = pulp_docker.plugins.models:Manifest
Loading unit model: docker_image = pulp_docker.plugins.models:Image
Loading unit model: docker_tag = pulp_docker.plugins.models:Tag
Loading unit model: ostree = pulp_ostree.plugins.db.model:Branch
Loading unit model: puppet_module = pulp_puppet.plugins.db.models:Module
Database migrations complete.
[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# mongo
MongoDB shell version: 2.6.12
connecting to: test
Server has startup warnings: 
2016-11-11T14:30:02.781-0500 [initandlisten] 
2016-11-11T14:30:02.781-0500 [initandlisten] ** WARNING: Readahead for /var/lib/mongodb is set to 4096KB
2016-11-11T14:30:02.781-0500 [initandlisten] **          We suggest setting it to 256KB (512 sectors) or less
2016-11-11T14:30:02.781-0500 [initandlisten] **          http://dochub.mongodb.org/core/readahead
> use pulp_database
switched to db pulp_database
> db.repo_importers.find()
{ "_id" : ObjectId("58261de01661f00b3558afe7"), "repo_id" : "zoo", "importer_type_id" : "yum_importer", "config" : { "feed" : "https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm/" }, "_ns" : "repo_importers", "scratchpad" : { "repomd_revision" : 1478850732, "previous_skip_list" : [ ] }, "last_sync" : "null" }
> 
> 
> 
> exit

[root@qe-blade-04 ~]# sudo systemctl start httpd pulp_workers pulp_resource_manager pulp_celerybeat

[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# pulp-admin rpm repo list
+----------------------------------------------------------------------+
                            RPM Repositories
+----------------------------------------------------------------------+

Id:                  zoo
Display Name:        None
Description:         None
Content Unit Counts: 
  Erratum:           4
  Package Category:  1
  Package Group:     2
  Package Langpacks: 1
  Rpm:               32

[root@qe-blade-04 ~]# pulp-admin rpm repo sync run --repo-id zoo 
+----------------------------------------------------------------------+
                     Synchronizing Repository [zoo]
+----------------------------------------------------------------------+

This command may be exited via ctrl+c without affecting the request.

Downloading metadata...
[-]

Task Failed

Importer indicated a failed response

[root@qe-blade-04 ~]# 

Sync a 2nd time and its successful

[root@qe-blade-04 ~]# pulp-admin rpm repo sync run --repo-id zoo 
+----------------------------------------------------------------------+
                     Synchronizing Repository [zoo]
+----------------------------------------------------------------------+

This command may be exited via ctrl+c without affecting the request.

Downloading metadata...
[\]
... completed

Downloading repository content...
[-]
[==================================================] 100%
RPMs:       0/0 items
Delta RPMs: 0/0 items

... completed

Downloading distribution files...
[==================================================] 100%
Distributions: 0/0 items
... completed

Importing errata...
[-]
... completed

Importing package groups/categories...
[-]
... completed

Cleaning duplicate packages...
[-]
... completed

Task Succeeded

Task Succeeded

From  the log

Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048) Malformed ISO8601 date-time string: null
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048) Traceback (most recent call last):
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 217, in run
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)     metadata_files = self.get_metadata(metadata_files)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)   File "/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 362, in get_metadata
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)     last_sync = dateutils.parse_iso8601_datetime(last_sync)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)   File "/usr/lib/python2.7/site-packages/pulp/common/dateutils.py", line 176, in parse_iso8601_datetime
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)     return isodate.parse_datetime(datetime_str)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)   File "/usr/lib/python2.7/site-packages/isodate/isodatetime.py", line 48, in parse_datetime
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048)     datestring, timestring = datetimestring.split('T')
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp_rpm.plugins.importers.yum.sync:ERROR: (15133-82048) ISO8601Error: Malformed ISO8601 date-time string: null
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: py.warnings:WARNING: (15133-82048) /usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py:804: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: py.warnings:WARNING: (15133-82048)   sync_result_collection.save(sync_result)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: py.warnings:WARNING: (15133-82048)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: pulp.server.async.tasks:INFO: Task failed : [45d94b83-fe79-4e78-8cb6-f0b232a73292]
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: py.warnings:WARNING: (15133-82048) /usr/lib/python2.7/site-packages/mongoengine/document.py:367: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: py.warnings:WARNING: (15133-82048)   upsert=upsert, **write_concern)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[15133]: py.warnings:WARNING: (15133-82048)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048) Task pulp.server.managers.repo.sync.sync[45d94b83-fe79-4e78-8cb6-f0b232a73292] raised unexpected: PulpExecutionException('Importer indicated a failed response',)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048) Traceback (most recent call last):
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)     R = retval = fun(*args, **kwargs)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 488, in __call__
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)     return super(Task, self).__call__(*args, **kwargs)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 103, in __call__
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)     return super(PulpTask, self).__call__(*args, **kwargs)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)     return self.run(*args, **kwargs)
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)   File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 810, in sync
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048)     raise pulp_exceptions.PulpExecutionException(_('Importer indicated a failed response'))
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:ERROR: (14760-82048) PulpExecutionException: Importer indicated a failed response
Nov 11 15:27:00 qe-blade-04.idmqe.lab.eng.bos.redhat.com pulp[14760]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[8341d78a-db59-4840-9b7e-49f1125cb10b] succeeded in 0.00676513100007s: None
Actions #27

Updated by semyers over 7 years ago

That's still incorrect. The value in your output isn't null, it's "null". One is null, the other is a string.

Actions #28

Updated by pthomas@redhat.com over 7 years ago

  • Status changed from ASSIGNED to 6

Got it.
Verified


> use pulp_database
switched to db pulp_database
> 
> 
> db.repo_importers.find()
{ "_id" : ObjectId("58261de01661f00b3558afe7"), "repo_id" : "zoo", "importer_type_id" : "yum_importer", "config" : { "feed" : "https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm/" }, "_ns" : "repo_importers", "scratchpad" : { "repomd_revision" : 1478850732, "previous_skip_list" : [ ] }, "last_sync" : "2016-11-11T20:44:18Z" }
> 
> 
> db.repo_importers.update(     { "repo_id" : "zoo" },     {       $set: { "last_sync": null}   } )
WriteResult({ "nMatched" : 1, "nUpserted" : 0, "nModified" : 1 })
> 
> 
> db.repo_importers.find()
{ "_id" : ObjectId("58261de01661f00b3558afe7"), "repo_id" : "zoo", "importer_type_id" : "yum_importer", "config" : { "feed" : "https://repos.fedorapeople.org/pulp/pulp/fixtures/rpm/" }, "_ns" : "repo_importers", "scratchpad" : { "repomd_revision" : 1478850732, "previous_skip_list" : [ ] }, "last_sync" : null }
> 
> exit
bye
[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# 
[root@qe-blade-04 ~]# pulp-admin rpm repo sync run --repo-id zoo 
+----------------------------------------------------------------------+
                     Synchronizing Repository [zoo]
+----------------------------------------------------------------------+

This command may be exited via ctrl+c without affecting the request.

Downloading metadata...
[\]
... completed

Downloading repository content...
[-]
[==================================================] 100%
RPMs:       0/0 items
Delta RPMs: 0/0 items

... completed

Downloading distribution files...
[==================================================] 100%
Distributions: 0/0 items
... completed

Importing errata...
[-]
... completed

Importing package groups/categories...
[-]
... completed

Cleaning duplicate packages...
[-]
... completed

Task Succeeded

Task Succeeded

[root@qe-blade-04 ~]# 
Actions #29

Updated by semyers over 7 years ago

  • Status changed from 6 to CLOSED - CURRENTRELEASE
Actions #31

Updated by bmbouter about 5 years ago

  • Tags Pulp 2 added

Also available in: Atom PDF