Page MenuHomePhabricator

Dumps pods sometimes take more than 5 minutes to start
Closed, ResolvedPublic

Description

We've observed that some dump related pods (whether they are dump, sync, monitor, ..., pods) can take a lot of time to start.

The symptom always looks like this:

cleanup-enwiki-tempfiles-m25kr0t                       0/1     ContainerCreating   0          3min42s

When inspecting the pod, we're not seeing any particular event that could explain the slowness:

Events:
  Type    Reason     Age    From               Message
  ----    ------     ----   ----               -------
  Normal  Scheduled  4m13s  default-scheduler  Successfully assigned mediawiki-dumps-legacy/cleanup-enwiki-tempfiles-m25kr0t to dse-k8s-worker1011.eqiad.wmnet

Could this be related to a slow mount, or a lock in Ceph?

Details

Related Changes in GitLab:
TitleReferenceAuthorSource BranchDest Branch
dumps/remove_old_miscellaneous_dumps: mount the dumps ceph PVC with fsgroup=33repos/data-engineering/airflow-dags!2656brouberolT437988main
dumps: ensure all pods mount the dumps ceph PVC with fsgroup=33repos/data-engineering/airflow-dags!2652brouberolT437988main
Customize query in GitLab

Event Timeline

brouberol triaged this task as High priority.

I was finally able to observe something that explains the slowness, after being plagued by it for weeks!

While ssh-ing onto the k8s worker node running the pod stuck in ContainerCreating state, I saw the following log amount the kubelet logstream:

brouberol@dse-k8s-worker1011:~$ sudo journalctl -u kubelet.service --since "10min ago" -f | grep --line-buffered ebb742f2-b166-48ba-abc9-b25c4d24026c
...
Sep 15 08:23:38 dse-k8s-worker1011 kubelet[109612]: W0915 08:23:38.519820  109612 volume_linux.go:49] Setting volume ownership for /var/lib/kubelet/pods/ebb742f2-b166-48ba-abc9-b25c4d24026c/volumes/kubernetes.io~csi/pvc-646c60c5-d272-40fc-9cb4-a0772513e1b9/mount and fsGroup set. If the volume has a lot of files then setting volume ownership could be slow, see https://github.com/kubernetes/kubernetes/issues/69699
...

That had already been solved as part of T402644, via https://gerrit.wikimedia.org/r/c/operations/deployment-charts/+/1181127, so this is clearly a regression of some kind, where the fsGroup flip-flops.

We have at least 5 types of pods mounting the dumps ceph PVC:

  • dump pods
  • monitor pods
  • dump toolbox
  • sync toolbox
  • sync pods

Looking at the toolboxes, we see:

brouberol@deploy1003:~$ k get pod -o json mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb | jq .spec.securityContext
{
  "fsGroup": 33,
  "fsGroupChangePolicy": "OnRootMismatch"
}
brouberol@deploy1003:~$ k get pod -o json mediawiki-dumps-legacy-sync-toolbox-7cdb965bcd-hrrqf | jq .spec.securityContext
{
  "fsGroup": 33,
  "fsGroupChangePolicy": "OnRootMismatch"
}

Dump and monitor pods get their spec from the mediawiki-production-dumps-job-template cronjob defined in the mediawiki-dumps-legacy namespace:

brouberol@deploy1003:~$ k get cronjob mediawiki-production-dumps-job-template -o json | jq .spec.jobTemplate.spec.template.spec.securityContext
{
  "fsGroup": 33,
  "fsGroupChangePolicy": "OnRootMismatch"
}

So far so good, everybody agrees on the fsGroup value, so that leaves us with sync pods.

brouberol@deploy1003:~$ kenv airflow-dumps
brouberol@deploy1003:~$ k exec -it airflow-scheduler-7758b49cd-l722d -- bash
runuser@airflow-scheduler-7758b49cd-l722d:/opt/airflow$ python3
Python 3.11.2 (main, Apr  8 2026, 01:58:00) [GCC 12.2.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from dumps.dags import make_sync_dumps_pod_spec
>>> sync_pod = make_sync_dumps_pod_spec('small')
>>> sync_pod.spec.security_context
{'app_armor_profile': None,
 'fs_group': 900,
 'fs_group_change_policy': 'OnRootMismatch',
 'run_as_group': None,
 'run_as_non_root': True,
 'run_as_user': None,
 'se_linux_change_policy': None,
 'se_linux_options': None,
 'seccomp_profile': {'localhost_profile': None, 'type': 'RuntimeDefault'},
 'supplemental_groups': None,
 'supplemental_groups_policy': None,
 'sysctls': None,
 'windows_options': None}

Bingo!

Another type of pod mounting the ceph dumps PVC are the pods cleaning up the temporary files from Ceph, as the last step in the DAG:

brouberol@deploy1003:~$ k get pod -o json cleanup-enwiki-tempfiles-e1kv6r6 | jq .spec.securityContext
{
  "fsGroup": 900,
  "fsGroupChangePolicy": "OnRootMismatch",
  "runAsNonRoot": true,
  "seccompProfile": {
    "type": "RuntimeDefault"
  }
}

That needs to be fixed as well.

Indeed, I'm seeing the root folderi in the volume being owned by gid 900 right now:

www-data@mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb:/$ ls -alh /mnt/dumpsdata/
total 4.0K
drwxrwsr-x  4 root      900    2 May 15  2025 .
drwxr-xr-x  1 root     root 4.0K Sep 10 18:14 ..
drwxrwsr-x 14 www-data  900   12 Jul 28  2025 otherdumps
drwxrwsr-x  5 www-data  900    3 Mar 19  2025 xmldatadumps

I'm now going to clear airflow-dumps.wikimedia.org / mediawiki_dumps_sql_xml_large_a_to_z_full / scheduled__2026-08-01T08:00:00+00:00 / enwiki.cleanup_enwiki_tempfiles, which should start a pod with fsGroup=33, which will take several minutes to start. When it is done with the chowning, the pod will finally start, and we should be done.

brouberol@deploy1003:~$ k get pod -o json cleanup-enwiki-tempfiles-t19iwct | jq .spec.securityContext
{
  "fsGroup": 33,
  "fsGroupChangePolicy": "OnRootMismatch",
  "runAsNonRoot": true,
  "seccompProfile": {
    "type": "RuntimeDefault"
  }
}
cleanup-enwiki-tempfiles-t19iwct                       0/1     ContainerCreating   0          42s

It took 2 attempts to chown -R the whole volume:

NAME                                                   READY   STATUS              RESTARTS   AGE
cleanup-enwiki-tempfiles-t19iwct                       0/1     ContainerCreating   0          37s
mediawiki-dump-commons-mediainfo-json-dump             4/4     Running             0          30h
mediawiki-dump-commons-mediainfo-rdf-dump              4/4     Running             0          38h
mediawiki-dump-wikidata-all-json-dump                  4/4     Running             0          30h
mediawiki-dump-wikidata-all-rdf-dump                   4/4     Running             0          10h
mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb   2/2     Running             0          4d15h
mediawiki-dumps-legacy-sync-toolbox-7cdb965bcd-hrrqf   2/2     Running             0          4d15h
cleanup-enwiki-tempfiles-t19iwct                       0/1     ContainerCreating   0          5m2s
cleanup-enwiki-tempfiles-t19iwct                       0/1     Terminating         0          5m2s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Pending             0          0s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Pending             0          0s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     ContainerCreating   0          0s
cleanup-enwiki-tempfiles-t19iwct                       0/1     ContainerStatusUnknown   0          7m41s
cleanup-enwiki-tempfiles-t19iwct                       0/1     ContainerStatusUnknown   0          7m41s
cleanup-enwiki-tempfiles-t19iwct                       0/1     ContainerStatusUnknown   0          7m41s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     ContainerCreating        0          2m1s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Completed                0          2m1s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Completed                0          2m2s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Completed                0          2m3s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Completed                0          2m5s
cleanup-enwiki-tempfiles-hnqhiw9                       0/1     Completed                0          2m5s

Subsequent runs were much faster!

NAME                               READY   STATUS    RESTARTS   AGE
cleanup-enwiki-tempfiles-hiftcnm   0/1     Pending   0          1s
cleanup-enwiki-tempfiles-hiftcnm   0/1     Pending   0          1s
cleanup-enwiki-tempfiles-hiftcnm   0/1     ContainerCreating   0          1s
cleanup-enwiki-tempfiles-hiftcnm   0/1     ContainerCreating   0          2s
cleanup-enwiki-tempfiles-hiftcnm   0/1     Completed           0          2s
cleanup-enwiki-tempfiles-hiftcnm   0/1     Completed           0          4s
cleanup-enwiki-tempfiles-hiftcnm   0/1     Completed           0          4s

Sync pods now also use fsGroup=33:

brouberol@deploy1003:~$ k get pod -o json enwiki-sql-xml-enwiki-sync-remaining-full-3elkc4p | jq .spec.securityContext
{
  "fsGroup": 33,
  "fsGroupChangePolicy": "OnRootMismatch",
  "runAsNonRoot": true,
  "seccompProfile": {
    "type": "RuntimeDefault"
  }
}

Same for the monitor pods

brouberol@deploy1003:~$ k get pod -o json mediawiki-sql-xml-dumps-monitor | jq .spec.securityContext
{
  "fsGroup": 33,
  "fsGroupChangePolicy": "OnRootMismatch"
}
mediawiki-sql-xml-dumps-monitor                        0/4     Pending     0          0s
mediawiki-sql-xml-dumps-monitor                        0/4     Pending     0          0s
mediawiki-sql-xml-dumps-monitor                        0/4     ContainerCreating   0          0s
mediawiki-sql-xml-dumps-monitor                        0/4     ContainerCreating   0          4s
mediawiki-sql-xml-dumps-monitor                        2/4     Running             0          11s
mediawiki-sql-xml-dumps-monitor                        3/4     Running             0          11s
mediawiki-sql-xml-dumps-monitor                        4/4     Running             0          12s
mediawiki-sql-xml-dumps-monitor                        3/4     NotReady            0          44s
mediawiki-sql-xml-dumps-monitor                        0/4     Completed           0          45s
mediawiki-sql-xml-dumps-monitor                        0/4     Completed           0          46s
mediawiki-sql-xml-dumps-monitor                        0/4     Completed           0          46s
mediawiki-sql-xml-dumps-monitor                        0/4     Completed           0          47s
mediawiki-sql-xml-dumps-monitor                        0/4     Completed           0          47s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Pending             0          0s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Pending             0          0s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     ContainerCreating   0          0s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     ContainerCreating   0          1s
mediawiki-sql-xml-dumps-monitor-sync                   1/1     Running             0          2s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Completed           0          4s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Completed           0          5s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Completed           0          6s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Completed           0          7s
mediawiki-sql-xml-dumps-monitor-sync                   0/1     Completed           0          7s
www-data@mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb:/$ ls -alh /mnt/dumpsdata/
total 4.0K
drwxrwsr-x  4 root     www-data    2 May 15  2025 .
drwxr-xr-x  1 root     root     4.0K Sep 10 18:14 ..
drwxrwsr-x 14 www-data www-data   12 Jul 28  2025 otherdumps
drwxrwsr-x  5 www-data www-data    3 Mar 19  2025 xmldatadumps
www-data@mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb:/$ getent group 33
www-data:x:33:

We're back to normal, where the root volume is owned by gid=33

I'm re-opening this as I've observed the root volume dir owned by gid 900 again:

www-data@mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb:/$ ls -alh /mnt/dumpsdata/
total 4.0K
drwxrwsr-x  4 root      900    2 May 15  2025 .
drwxr-xr-x  1 root     root 4.0K Sep 10 18:14 ..
drwxrwsr-x 14 www-data  900   12 Jul 28  2025 otherdumps
drwxrwsr-x  5 www-data  900    3 Mar 19  2025 xmldatadumps

This seems to be coming from a DAG I has forgotten about: https://gitlab.wikimedia.org/repos/data-engineering/airflow-dags/-/blob/main/dumps/dags/remove_old_miscellaneous_dumps.py?ref_type=heads#L48

brouberol merged https://gitlab.wikimedia.org/repos/data-engineering/airflow-dags/-/merge_requests/2656

dumps/remove_old_miscellaneous_dumps: mount the dumps ceph PVC with fsgroup=33

www-data@mediawiki-dumps-legacy-dump-toolbox-59cc97c9bf-9rrdb:/$ ls -alh /mnt/dumpsdata/
total 4.0K
drwxrwsr-x  4 root     www-data    2 May 15  2025 .
drwxr-xr-x  1 root     root     4.0K Sep 10 18:14 ..
drwxrwsr-x 14 www-data www-data   12 Jul 28  2025 otherdumps
drwxrwsr-x  5 www-data www-data    3 Mar 19  2025 xmldatadumps

Ok, we're back to gid 33 owning the volume. Closing.