Page MenuHomeSoftware Heritage

swh-lister: Unstuck debian build failures
Closed, ResolvedPublic

Description

Build fails on tests [1]

What's been fixed already:

  • missing MANIFEST.in instruction to package the cgit tests data (7377439)
  • missing build dependency on python3-pytest-postgresql (8367f38)

Still failing [2], claiming that the swh.lister.*.tasks are not registered.
And indeed, within the chroot, tampering with code to actually print other information [3], we can see that the swh.lister.*.tasks are not included in the swh_app's context.

Which as far as i could tell from the code and the documentation [4], should.

So, so far, my analysis is that within the chroot context, the fixture decorators are not working as expected.
Because the code within those decorators work as expected [4]

[1] https://jenkins.softwareheritage.org/view/Debian%20packages/job/debian/job/packages/job/DLS/job/gbp-buildpackage/31/consoleFull

[2] https://jenkins.softwareheritage.org/view/Debian%20packages/job/debian/job/packages/job/DLS/job/gbp-buildpackage/32/consoleFull

[3] Tampering with chroot's inner python code

$ export TERM=xterm
$ apt-get install nano
$ cd swh-lister-0.0.35
$ nano swh/lister/bitbucket/tests/test_task.py # <- edit to add the print statements
$ dpkg-buildpackage -A 

And then, output excerpt of the error:

swh_app = <Celery celery.tests at 0x7fe3f06dfd10>, celery_session_worker = <Worker: gen12716@yavin4 (running)>

    def test_ping(swh_app, celery_session_worker):
        print(swh_app)
        print(swh_app.conf)
        print(swh_app.tasks)
        res = swh_app.send_task(
            'swh.lister.bitbucket.tasks.ping')
        assert res
>       res.wait()

swh/lister/bitbucket/tests/test_tasks.py:14:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
/usr/lib/python3/dist-packages/celery/result.py:224: in get
    on_message=on_message,
/usr/lib/python3/dist-packages/celery/backends/base.py:480: in wait_for_pending
    return result.maybe_throw(propagate=propagate, callback=callback)
/usr/lib/python3/dist-packages/celery/result.py:329: in maybe_throw
    self.throw(value, self._to_remote_traceback(tb))
/usr/lib/python3/dist-packages/celery/result.py:322: in throw
    self.on_ready.throw(*args, **kwargs)
/usr/lib/python3/dist-packages/vine/promises.py:217: in throw
    reraise(type(exc), exc, tb)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

tp = <class 'celery.exceptions.NotRegistered'>, value = Task of kind 'swh.lister.bitbucket.tasks.ping' never registered, please make sure it's imported., tb = None

    def reraise(tp, value, tb=None):
        """Reraise exception."""
        if value.__traceback__ is not tb:
            raise value.with_traceback(tb)
>       raise value
E       celery.exceptions.NotRegistered: 'swh.lister.bitbucket.tasks.ping'

/usr/lib/python3/dist-packages/vine/five.py:179: NotRegistered
------------------------------------------------------------------------------------------------------------ Captured stderr setup ------------------------------------------------------------------------------------------------------------
[2019-09-10 10:22:51,171: INFO/MainProcess] Connected to memory://localhost//
[2019-09-10 10:22:52,180: INFO/MainProcess] Received task: celery.ping[a15d9252-1042-4ffc-a471-d88cef8d4078]
[2019-09-10 10:22:52,185: INFO/MainProcess] Task celery.ping[a15d9252-1042-4ffc-a471-d88cef8d4078] succeeded in 0.0027758179930970073s: 'pong'
------------------------------------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------------------------------------
INFO     celery.worker.consumer.connection:connection.py:24 Connected to memory://localhost//
INFO     celery.worker.strategy:strategy.py:156 Received task: celery.ping[a15d9252-1042-4ffc-a471-d88cef8d4078]
INFO     celery.app.trace:trace.py:124 Task celery.ping[a15d9252-1042-4ffc-a471-d88cef8d4078] succeeded in 0.0027758179930970073s: 'pong'
------------------------------------------------------------------------------------------------------------ Captured stdout call -------------------------------------------------------------------------------------------------------------
<Celery celery.tests at 0x7fe3f06dfd10>
Settings({'include': ('celery.app.builtins', 'celery.contrib.testing.tasks', 'swh.scheduler.tests.tasks')}, {'worker_hijack_root_logger': False, 'worker_log_color': False, 'accept_content': ['application/x-msgpack', 'application/json'], 'enable_utc': True, 'timezone': 'UTC', 'broker_url': 'memory://', 'result_backend': 'cache+memory://', 'broker_heartbeat': 0, 'task_serializer': 'msgpack', 'result_serializer': 'json'}, {}, {'accept_content': ['json'], 'enable_utc': True, 'imports': (), 'include': (), 'timezone': None, 'beat_max_loop_interval': 0, 'beat_schedule': {}, 'beat_scheduler': 'celery.beat:PersistentScheduler', 'beat_schedule_filename': 'celerybeat-schedule', 'beat_sync_every': 0, 'broker_url': None, 'broker_read_url': None, 'broker_write_url': None, 'broker_transport': None, 'broker_transport_options': {}, 'broker_connection_timeout': 4, 'broker_connection_retry': True, 'broker_connection_max_retries': 100, 'broker_failover_strategy': None, 'broker_heartbeat': 120, 'broker_heartbeat_checkrate': 3.0, 'broker_login_method': None, 'broker_pool_limit': 10, 'broker_use_ssl': False, 'broker_host': None, 'broker_port': None, 'broker_user': None, 'broker_password': None, 'broker_vhost': None, 'cache_backend': None, 'cache_backend_options': {}, 'cassandra_entry_ttl': None, 'cassandra_keyspace': None, 'cassandra_port': None, 'cassandra_read_consistency': None, 'cassandra_servers': None, 'cassandra_table': None, 'cassandra_write_consistency': None, 'cassandra_auth_provider': None, 'cassandra_auth_kwargs': None, 'cassandra_options': {}, 'control_queue_ttl': 300.0, 'control_queue_expires': 10.0, 'couchbase_backend_settings': None, 'mongodb_backend_settings': None, 'event_queue_expires': 60.0, 'event_queue_ttl': 5.0, 'event_queue_prefix': 'celeryev', 'event_serializer': 'json', 'redis_backend_use_ssl': None, 'redis_db': None, 'redis_host': None, 'redis_max_connections': None, 'redis_password': None, 'redis_port': None, 'redis_socket_timeout': 120.0, 'redis_socket_connect_timeout': None, 'result_backend': None, 'result_cache_max': -1, 'result_compression': None, 'result_exchange': 'celeryresults', 'result_exchange_type': 'direct', 'result_expires': datetime.timedelta(days=1), 'result_persistent': None, 'result_serializer': 'json', 'result_backend_transport_options': {}, 'elasticsearch_retry_on_timeout': None, 'elasticsearch_max_retries': None, 'elasticsearch_timeout': None, 'riak_backend_settings': None, 'security_certificate': None, 'security_cert_store': None, 'security_key': None, 'database_url': None, 'database_engine_options': None, 'database_short_lived_sessions': False, 'database_table_names': None, 'task_acks_late': False, 'task_always_eager': False, 'task_annotations': None, 'task_compression': None, 'task_create_missing_queues': True, 'task_default_delivery_mode': 2, 'task_default_queue': 'celery', 'task_default_exchange': None, 'task_default_exchange_type': 'direct', 'task_default_routing_key': None, 'task_default_rate_limit': None, 'task_eager_propagates': False, 'task_ignore_result': False, 'task_protocol': 2, 'task_publish_retry': True, 'task_publish_retry_policy': {'max_retries': 3, 'interval_start': 0, 'interval_max': 1, 'interval_step': 0.2}, 'task_queues': None, 'task_queue_ha_policy': None, 'task_queue_max_priority': None, 'task_reject_on_worker_lost': None, 'task_remote_tracebacks': False, 'task_routes': None, 'task_send_sent_event': False, 'task_serializer': 'json', 'task_soft_time_limit': None, 'task_time_limit': None, 'task_store_errors_even_if_ignored': False, 'task_track_started': False, 'worker_agent': None, 'worker_autoscaler': 'celery.worker.autoscale:Autoscaler', 'worker_concurrency': 0, 'worker_consumer': 'celery.worker.consumer:Consumer', 'worker_direct': False, 'worker_disable_rate_limits': False, 'worker_enable_remote_control': True, 'worker_hijack_root_logger': True, 'worker_log_color': None, 'worker_log_format': '[%(asctime)s: %(levelname)s/%(processName)s] %(message)s', 'worker_lost_wait': 10.0, 'worker_max_memory_per_child': None, 'worker_max_tasks_per_child': None, 'worker_pool': 'prefork', 'worker_pool_putlocks': True, 'worker_pool_restarts': False, 'worker_prefetch_multiplier': 4, 'worker_redirect_stdouts': True, 'worker_redirect_stdouts_level': 'WARNING', 'worker_send_task_events': False, 'worker_state_db': None, 'worker_task_log_format': '[%(agbp buildpackage --git-builder=sbuild --nolog --batch --no-run-lintian --arch-all --source --force-orig-source --uploader="Software Heritage autobuilder (on jenkins-debian1) <jenkins@jenkins-debian1.internal.softwareheritage.org>" --build-dep-resolver=aptitude --extra-repository="deb [trusted=yes] https://debian.softwareheritage.org/ stretch-swh main" --extra-repository="deb http://deb.debian.org/debian/ stretch-backports main" --git-ignore-newgbp buildpackage --git-builder=sbuild --nolog --batch --no-run-lintian --arch-all --source --force-orig-source --uploader="Software Heritage autobuilder (on jenkins-debian1) <jenkins@jenkins-debian1.internal.softwareheritage.org>" --build-dep-resolver=aptitude --extra-repository="deb [trusted=yes] https://debian.softwareheritage.org/ stretch-swh main" --extra-repository="deb http://deb.debian.org/debian/ stretch-backports main" --git-ignore-newgbp buildpackage --git-builder=sbuild --nolog --batch --no-run-lintian --arch-all --source --force-orig-source --uploader="Software Heritage autobuilder (on jenkins-debian1) <jenkins@jenkins-debian1.internal.softwareheritage.org>" --build-dep-resolver=aptitude --extra-repository="deb [trusted=yes] https://debian.softwareheritage.org/ stretch-swh main" --extra-repository="deb http://deb.debian.org/debian/ stretch-backports main" --git-ignore-newsctime)s: %(levelname)s/%(processName)s] %(task_name)s[%(task_id)s]: %(message)s', 'worker_timer': None, 'worker_timer_precision': 1.0})
{'celery.accumulate': <@task: celery.accumulate of celery.tests at 0x7fe3f06dfd10>, 'swh.scheduler.tests.tasks.add': <@task: swh.scheduler.tests.tasks.add of celery.tests at 0x7fe3f06dfd10>, 'celery.chord': <@task: celery.chord of celery.tests at 0x7fe3f06dfd10>, 'celery.chunks': <@task: celery.chunks of celery.tests at 0x7fe3f06dfd10>, 'celery.ping': <@task: celery.ping of celery.tests at 0x7fe3f06dfd10>, 'celery.backend_cleanup': <@task: celery.backend_cleanup of celery.tests at 0x7fe3f06dfd10>, 'celery.chord_unlock': <@task: celery.chord_unlock of celery.tests at 0x7fe3f06dfd10>, 'swh.scheduler.tests.tasks.ping': <@task: swh.scheduler.tests.tasks.ping of celery.tests at 0x7fe3f06dfd10>, 'celery.group': <@task: celery.group of celery.tests at 0x7fe3f06dfd10>, 'swh.scheduler.tests.tasks.error': <@task: swh.scheduler.tests.tasks.error of celery.tests at 0x7fe3f06dfd10>, 'celery.map': <@task: celery.map of celery.tests at 0x7fe3f06dfd10>, 'celery.chain': <@task: celery.chain of celery.tests at 0x7fe3f06dfd10>, 'celery.starmap': <@task: celery.starmap of celery.tests at 0x7fe3f06dfd10>, 'swh.scheduler.tests.tasks.multiping': <@task: swh.scheduler.tests.tasks.multiping of celery.tests at 0x7fe3f06dfd10>}>
...

No swh.lister.tasks.* modules.

[4] https://docs.celeryproject.org/en/latest/userguide/testing.html#py-test

[5] To be in that chroot context, use the following command:

$ cd swh-environment/swh-lister
$ git pull
$ git checkout debian/unstable-swh && git reset --hard origin/debian/unstable-swh
$ gbp buildpackage --git-builder=sbuild --nolog --batch --no-run-lintian --arch-all --source --force-orig-source --uploader="Software Heritage autobuilder (on jenkins-debian1) <jenkins@jenkins-debian1.internal.softwareheritage.org>" --build-dep-resolver=aptitude --extra-repository="deb [trusted=yes] https://debian.softwareheritage.org/ stretch-swh main" --extra-repository="deb http://deb.debian.org/debian/ stretch-backports main"  --build-failed-commands %SBUILD_SHELL --git-ignore-new
# ^ that's the command used by the ci plus some tweaks to be left on the chroot on failures

Python3 toplevel from within the chroot context

(sid-amd64-sbuild)root@yavin4:/build/swh-lister-1sw01E/swh-lister-0.0.35# python3
Python 3.7.4+ (default, Sep  4 2019, 08:03:05)
[GCC 9.2.1 20190827] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import pkg_resources
>>> task_modules = []
>>> for entrypoint in pkg_resources.iter_entry_points('swh.workers'):
...     task_modules.extend(entrypoint.load()().get('task_modules', []))
...
>>> task_modules
['swh.lister.bitbucket.tasks', 'swh.lister.cgit.tasks', 'swh.lister.cran.tasks', 'swh.lister.debian.tasks', 'swh.lister.github.tasks', 'swh.lister.gitlab.tasks', 'swh.lister.gnu.tasks',  'swh.lister.npm.tasks', 'swh.lister.packagist.tasks', 'swh.lister.phabricator.tasks', 'swh.lister.pypi.tasks']

Revisions and Commits

Event Timeline

ardumont changed the task status from Open to Work in Progress.Sep 10 2019, 1:33 PM
ardumont triaged this task as High priority.
ardumont created this task.
ardumont updated the task description. (Show Details)Sep 10 2019, 1:37 PM
ardumont updated the task description. (Show Details)Sep 10 2019, 1:44 PM

Also, as to why it worked before, because within the scheduler, the lister tasks were declared from the swh-scheduler:/.../50-swh-data.sql.

ardumont renamed this task from swh-lister: Unstuck debian build failure to swh-lister: Unstuck debian build failures.Sep 10 2019, 1:59 PM
ardumont added a project: Lister.
ardumont added a comment.EditedSep 10 2019, 2:21 PM

Editing our swh.scheduler.tests.conftest's @celery_includes definition fixture (to print the task_modules computed).
We can further see that the task modules computation is off:

From within the chroot:

(sid-amd64-sbuild)root@yavin4:/build/swh-lister-8IlOTN/swh-lister-0.0.35# $ apt install nano
(sid-amd64-sbuild)root@yavin4:/build/swh-lister-8IlOTN/swh-lister-0.0.35# nano /usr/lib/python3/dist-packages/swh/scheduler/tests/conftest.py
(sid-amd64-sbuild)root@yavin4:/build/swh-lister-8IlOTN/swh-lister-0.0.35# dpkg-buildpackage -A
...
------------------------------------------------------------------------------------------------------------ Captured stdout setup ------------------------------------------------------------------------------------------------------------
############## task_modules ['swh.scheduler.tests.tasks']

^ where i'd expect to see the lister's modules as in something like:

['swh.lister.bitbucket.tasks', 'swh.lister.cgit.tasks', 'swh.lister.cran.tasks', 'swh.lister.debian.tasks', 'swh.lister.github.tasks', 'swh.lister.gitlab.tasks', 'swh.lister.gnu.tasks',  'swh.lister.npm.tasks', 'swh.lister.packagist.tasks', 'swh.lister.phabricator.tasks', 'swh.lister.pypi.tasks']
olasd added a subscriber: olasd.Sep 10 2019, 2:54 PM

By default, pybuild doesn't copy the egg-info files (which contains the entry points) before running tests. This means the entrypoints aren't available.

The egg-info needs to be copied explicitly, e.g. by using the debian/pybuild.testfiles file.

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=900526 for reference.

olasd added a comment.Sep 10 2019, 3:11 PM

With the proper version constraint (dh-python (>= 3)) the package build went through for all three suites (unstable, stretch, buster).

Another fix to actually reference the python3-swh.storage.schemata runtime dependency.
Without this, a fresh lister install makes the service fail to start as well.