Deploy latest swh.loader.core and swh.lister

loader:

• loader.core doc improvment on the package loader tutorial
• fixes for the loader debian
• fix for the package loader in general (nixguix currently impacted)

lister:

• new maven lister
• drop unnecessary parameter in the debian lister (this actually implies data migration in the current listed origins in the scheduler)

Plan:

• tag
• unstuck builds if any (there is, the lister failed already [1])

staging (and production):

• migrate scheduling db data (drop the date field in the extra_loader_arguments for deb listed_origins) [4]
• deploy lister
• restart lister service
• deploy loader core
• restart package loader services
• wait for scheduling of tasks to happen (it does not)
• unstuck task type mess (load-deb-package instead of load-deb which prevents load debian task scheduling from happening) [5]
• we good? yes, see #3765 (closed)

Checks:

• ensure deb loading origins are actually scheduled now [2]

• ensure the nixguix loader actually finish loading now [3]. It does [6)

• [1] https://jenkins.softwareheritage.org/job/debian/job/packages/job/DLS/job/gbp-buildpackage/161/console

• [2] Related to #2400 (closed)

• [3] Related to T3763

• [4] migrated/migration$1222

• [5] Install latest version of the loader.core package in the scheduler node and trigger the task type registering

swhscheduler@scheduler0.staging $ swh scheduler --config-file /etc/softwareheritage/scheduler/backend.yml task-type register

• [6] migrated/migration$1224

---

Migrated from T3765 (view on Phabricator)

marked this issue as related to #2400 (closed)

added Core Loader Lister System administration priority:Normal labels

changed the description

mentioned in commit swh/devel/swh-lister@6a8f5d42

mentioned in commit swh/devel/swh-lister@a991f872

marked the checklist item unstuck builds if any (there is, the lister failed already [1]) as completed

changed the description

marked the checklist item migrate scheduling db data (drop the date field in the extra_loader_arguments for deb listed_origins) [4] as completed

marked the checklist item deploy lister as completed

marked the checklist item restart lister service as completed

marked the checklist item deploy loader core as completed

marked the checklist item restart package loader services as completed

changed the description

What a mess! The existing data both in staging and production are not in the expected shape for the loader. Hence the issue of failing the load [1]

I'm working on cleaning up that mess and trigger things correctly for the existing debian origins we got.

After cleaning up the listed origins for visit_type 'deb' (table 'listed_origins') and cleaning up the state of the right lister (table 'listers', name 'debian', instance_name 'Debian'). The listing is fine [2].

And the loading finally starts to give positive results. [3]

• [1] https://sentry.softwareheritage.org/share/issue/9c5645bafe154c4ba328dee3f834aeb8/

• [2]

Dec 03 14:46:37 worker0 python3[3948658]: [2021-12-03 14:46:37,158: INFO/MainProcess] Received task: swh.lister.debian.tasks.DebianListerTask[1bbfd171-b0b3-45a9-adbe-6c30a75cbeec]                                                            Dec 03 14:48:45 worker0 python3[3948668]: [2021-12-03 14:48:45,219: INFO/ForkPoolWorker-4] Task swh.lister.debian.tasks.DebianListerTask[1bbfd171-b0b3-45a9-adbe-6c30a75cbeec] succeeded in 128.05661826208234s: {'pages': 9, 'origins': 35035}

• [3]

Dec 03 14:53:54 worker0 python3[3945922]: [2021-12-03 14:53:54,078: INFO/MainProcess] Received task: swh.loader.package.debian.tasks.LoadDebian[3da60a01-e9ad-4fc0-8114-9b3a6424b39d]
Dec 03 14:54:13 worker0 python3[3949860]: [2021-12-03 14:54:13,223: INFO/ForkPoolWorker-119] Task swh.loader.package.debian.tasks.LoadDebian[17f1f904-b6e2-4b3a-ab1a-7d8dd4aece93] succeeded in 19.120316199958324s: {'status': 'eventful', 'snapshot_id': '6c1b021d4ff5479db8e91150ffce71bd885100b9'}
Dec 03 14:54:13 worker0 python3[3945922]: [2021-12-03 14:54:13,231: INFO/MainProcess] Received task: swh.loader.package.debian.tasks.LoadDebian[e1e0cb99-ae43-4917-a852-145b16f1f502]
Dec 03 14:56:10 worker0 python3[3949860]: [2021-12-03 14:56:10,316: INFO/ForkPoolWorker-119] Task swh.loader.package.debian.tasks.LoadDebian[3da60a01-e9ad-4fc0-8114-9b3a6424b39d] succeeded in 117.08710754103959s: {'status': 'eventful', 'snapshot_id': 'e1d115c47b565f4dcdffdb1c68753da3ea18716d'}
Dec 03 14:56:13 worker0 python3[3945922]: [2021-12-03 14:56:13,291: INFO/MainProcess] Received task: swh.loader.package.debian.tasks.LoadDebian[b56a6348-807b-4ca8-9b67-1c14a9adb79c]
Dec 03 14:56:34 worker0 python3[3951980]: [2021-12-03 14:56:34,081: INFO/ForkPoolWorker-120] Task swh.loader.package.debian.tasks.LoadDebian[e1e0cb99-ae43-4917-a852-145b16f1f502] succeeded in 20.769159140065312s: {'status': 'eventful', 'snapshot_id': '218f1bfff64da567f233c684d8a82caf7f8b0ed5'}
Dec 03 14:56:34 worker0 python3[3945922]: [2021-12-03 14:56:34,086: INFO/MainProcess] Received task: swh.loader.package.debian.tasks.LoadDebian[d0cc84fc-9fa4-4ef1-896d-d3cc79e3e4b1]
Dec 03 14:56:53 worker0 python3[3951980]: [2021-12-03 14:56:53,862: INFO/ForkPoolWorker-120] Task swh.loader.package.debian.tasks.LoadDebian[b56a6348-807b-4ca8-9b67-1c14a9adb79c] succeeded in 19.775573259219527s: {'status': 'eventful', 'snapshot_id': 'd854c59528da5d9cfc3c9ef4741ae7a0afbb247b'}
Dec 03 14:56:53 worker0 python3[3945922]: [2021-12-03 14:56:53,866: INFO/MainProcess] Received task: swh.loader.package.debian.tasks.LoadDebian[190d5290-33d8-4a11-a8cf-06f53988c0b1]

added state:wip label

After some fighting to untangle the mess we had in the scheduling dbs:

• wrong task type used
• wrong data format in old entries

And some more work from @anlambert to actually have the last_update filled in [3] by the lister (so the scheduler can do its work alone...)

I've finally managed to have deb origins scheduled in production the now "standard" way (service swh-scheduler-schedule-recurrent).

And workers are happily ingesting those!

• [1]

Dec 03 16:03:19 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:Skewed fetch for visit type deb with policy already_visited_order_by_lag: fetched 0.7530120481927711, requested 0.5
Dec 03 16:03:19 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:Skewed fetch for visit type deb with policy never_visited_oldest_update_first: fetched 0.2469879518072289, requested 0.5
Dec 03 16:03:23 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:deb: 6640 visits scheduled in queue swh.loader.package.debian.tasks.LoadDebian
Dec 03 16:03:29 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:Skewed fetch for visit type deb with policy already_visited_order_by_lag: fetched 1.0, requested 0.5
Dec 03 16:03:29 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:Skewed fetch for visit type deb with policy never_visited_oldest_update_first: fetched 0.0, requested 0.5
Dec 03 16:03:32 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:deb: 5000 visits scheduled in queue swh.loader.package.debian.tasks.LoadDebian
Dec 03 16:03:38 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:Skewed fetch for visit type deb with policy already_visited_order_by_lag: fetched 1.0, requested 0.5
Dec 03 16:03:38 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:Skewed fetch for visit type deb with policy never_visited_oldest_update_first: fetched 0.0, requested 0.5
Dec 03 16:03:39 saatchi swh[3728333]: INFO:swh.scheduler.celery_backend.recurrent_visits:deb: 813 visits scheduled in queue swh.loader.package.debian.tasks.LoadDebian

• [2]

---------------
worker02
---------------
Dec 03 16:07:35 worker02 python3[2459047]: [2021-12-03 16:07:35,261: INFO/ForkPoolWorker-9] Task swh.loader.package.debian.tasks.LoadDebian[8aef6cee-d951-4426-8bed-47a876c1ecea] succeeded in 2.106049958616495s: {'status': 'uneventful', 'sn
apshot_id': '392a6d9a8b819afc25e75cadd476dd3c0cf5b129'}
Dec 03 16:07:43 worker02 python3[2459047]: [2021-12-03 16:07:43,270: INFO/ForkPoolWorker-9] Task swh.loader.package.debian.tasks.LoadDebian[13a7c133-d7b8-4b70-806e-ced08f173503] succeeded in 8.006375344470143s: {'status': 'eventful', 'snap
shot_id': '01fdfd620291fd98b8215174f41575a1a7f0b0de'}
Dec 03 16:08:16 worker02 python3[2459047]: [2021-12-03 16:08:16,225: INFO/ForkPoolWorker-9] Task swh.loader.package.debian.tasks.LoadDebian[3cc4bb47-1ffc-4b2f-854f-30e96c2909f2] succeeded in 32.952051220461726s: {'status': 'eventful', 'sna
pshot_id': '800615d433a0a4ffe61882555e9e77c3586f25a3'}
Dec 03 16:08:19 worker02 python3[2459047]: [2021-12-03 16:08:19,668: INFO/ForkPoolWorker-9] Task swh.loader.package.debian.tasks.LoadDebian[d59eb79a-7ae3-4417-bb02-e763fe2f0e06] succeeded in 3.439918976277113s: {'status': 'eventful', 'snap
shot_id': '03c5b36062d7fe68079e2fcabbd00e17c8a33a1f'}
Dec 03 16:08:26 worker02 python3[2459047]: [2021-12-03 16:08:26,197: INFO/ForkPoolWorker-9] Task swh.loader.package.debian.tasks.LoadDebian[d2a86a4e-300c-40fa-9cbd-cc549ce4bdbe] succeeded in 6.524066129699349s: {'status': 'eventful', 'snap
shot_id': '199baff05a2a86b2d37abff3e10cbf2435a3b69f'}
---------------
worker03
---------------
Dec 03 16:09:00 worker03 python3[329252]: [2021-12-03 16:09:00,399: INFO/ForkPoolWorker-12] Task swh.loader.package.debian.tasks.LoadDebian[9f353afb-b9f3-4ec2-9ee0-921f8a17d9b9] succeeded in 0.8490705993026495s: {'status': 'uneventful', 's
napshot_id': '460ca204c0d9c9df728c863b499d8b4ce8aaf59a'}
Dec 03 16:09:03 worker03 python3[329252]: [2021-12-03 16:09:03,447: INFO/ForkPoolWorker-12] Task swh.loader.package.debian.tasks.LoadDebian[e756bc48-e374-43e6-933a-a2b6fded8bbb] succeeded in 3.0455843079835176s: {'status': 'eventful', 'sna
pshot_id': '3e2a60fc77fe897997d971c6fc8a7592e6bf1604'}
Dec 03 16:09:04 worker03 python3[329252]: [2021-12-03 16:09:04,975: INFO/ForkPoolWorker-12] Task swh.loader.package.debian.tasks.LoadDebian[d5e12c7f-584c-48b1-8cf6-d94d50b91521] succeeded in 1.5250638499855995s: {'status': 'eventful', 'sna
pshot_id': 'c00632a2e8dddc4a2c66bd34427ba4f5ce1a31b1'}
Dec 03 16:09:07 worker03 python3[329252]: [2021-12-03 16:09:07,541: INFO/ForkPoolWorker-12] Task swh.loader.package.debian.tasks.LoadDebian[fd0dce12-9ab4-4521-af27-f9cdfe9d92e0] succeeded in 2.5631604827940464s: {'status': 'eventful', 'sna
pshot_id': '6a1cf3f176cce5de62fddab36eb03a6fcf7a2d21'}
Dec 03 16:09:18 worker03 python3[329335]: [2021-12-03 16:09:18,104: INFO/ForkPoolWorker-13] Task swh.loader.package.debian.tasks.LoadDebian[0fd23095-55fe-4096-afd2-b701ca81e4b7] succeeded in 6.773381747305393s: {'status': 'eventful', 'snap
shot_id': 'bd392d06433a205e4ad4ef5e20f628eb89dbdbce'}

• [3]

17:10:57 softwareheritage-scheduler@belvedere:5432=> select count(*) from listed_origins where visit_type='deb' and last_update is not null;
+-------+
| count |
+-------+
| 37604 |
+-------+
(1 row)

Time: 1112.519 ms (00:01.113)

marked the checklist item ensure deb loading origins are actually scheduled now [2] as completed

marked the checklist item ensure the nixguix loader actually finish loading now [3] as completed

marked the checklist item ensure the nixguix loader actually finish loading now [3] as incomplete

removed state:wip label

closed

changed the description

mentioned in issue #2400 (closed)