Too many scheduler processes

[Avphy]

In our Airflow 2.8.1. setup, randomly scheduler starts forking new scheduler processes which just stick around and cause a huge memory spike. This result in pipeline execution failure down the line.

Steps to reproduce:

• Create a Pipeline with 4-5 level of nested pipelines (Nesting implies dag contains task to trigger another dag execution, and using sensor poll for it's completion)
• Leaf level DAG contains 35 Tasks which execute for 5 mins
• That sums up to a total of ~700-800 task executing in Airflow
• Schedule pipeline execution for every 15 mins in an hour, i.e. cron (*/15 * * * *)
• After running this setup for a day, suddenly scheduler starts forking new processes (example given below) and never release them

    885  0.0  0.2 1954080 147848 ?      Sl   May07   0:58  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
   28029 13.9  1.3 3368452 858160 ?      Sl   May09 321:46  |       \_ airflow scheduler -- DagFileProcessorManager
    1635  0.8  2.0 3751132 1237864 ?     Sl   May09   7:45  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1637  0.8  2.0 3751136 1245312 ?     Sl   May09   7:40  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1639  0.7  2.0 3751132 1238744 ?     Sl   May09   7:13  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1641  0.7  2.0 3751132 1238744 ?     Sl   May09   7:08  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1645  0.7  2.0 3751132 1238744 ?     Sl   May09   7:17  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1648  0.7  2.0 3751132 1246156 ?     Sl   May09   7:20  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1650  0.7  2.0 3751132 1238744 ?     Sl   May09   7:18  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1652  0.7  2.0 3751132 1246160 ?     Sl   May09   7:11  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1654  0.7  2.0 3751132 1246156 ?     Sl   May09   7:11  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1655  0.7  2.0 3751132 1246156 ?     Sl   May09   7:12  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1657  0.8  2.0 3751132 1246156 ?     Sl   May09   7:22  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1659  0.7  2.0 3751132 1246156 ?     Sl   May09   7:11  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
    1661  0.7  2.0 3751132 1246156 ?     Sl   May09   7:21  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler    
    1664  0.7  2.0 3751132 1246160 ?     Sl   May09   7:22  |       \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler

Airflow.cfg changes which triggers this behaviour:

parallelism = 32
max_active_tasks_per_dag = 32
max_tis_per_query = 128
worker_concurrency = 500
Worker_autoscale = 500,32

Airflow Setup:

3 Nodes - webserver (2 CPU, 32 GB memory)
3 Nodes - scheduler (4 CPU, 128 GB memory)
3 Nodes - Celery (8CPU, 128 GB memory)
3 Nodes - Redis (8 CPU, 64 GB memory)
3 Nodes HA setup - MySQL

[potiuk]

can you run pyspy on some of the forked processes and let us know what you find ?

[Avphy]

py-spy doesn't recognise scheduler process as a valid

root      1879  0.0  0.0 103020  4608 ?        Ss   Jun20   0:00 /sbin/dhclient -q -lf /var/lib/dhclient/dhclient-54a7f4b1-f227-46eb-b956-776353ae17b7-ens3.lease -pf /var/run/dhclient-ens3.pid -H hostname ens3
root      6307  0.0  0.0 114292  2320 pts/0    S+   09:33   0:00                          \_ grep --color=auto scheduler
user   13879 15.6  0.6 3053844 901124 ?      Rl   Jul09 238:13      |   |   |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   30961 15.8  0.6 3054100 875352 ?      S    00:48  83:26      |   |   |       \_ airflow scheduler -- DagFileProcessorManager
user    6301 90.5  0.6 3054100 872268 ?      R    09:33   0:00      |   |   |           \_ airflow scheduler - DagFileProcessor /usr/local/airflow/dags/pipelines/SampleDAG.py
user    6305 62.5  0.6 3054100 872168 ?      S    09:33   0:00      |   |   |           \_ airflow scheduler - DagFileProcessor /usr/local/airflow/dags/pipelines/SampleDAG.py
user   24596  0.0  0.1 1609316 131960 ?      S    Jul06   0:13      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26085  0.0  5.4 9312000 7126408 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26087  0.0  5.4 9311996 7127384 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26089  0.0  5.4 9311996 7127388 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26094  0.0  5.4 9311996 7127456 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26097  0.0  5.4 9311996 7127392 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26100  0.0  5.4 9311996 7127468 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   26101  0.0  5.4 9311996 7127380 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user   24759  0.0  0.0   7824   676 ?        S+   Jul09   0:00          \_ tail -f /logs/airflow/scheduler_health_monitor.log
root   17414  0.1  0.0  13304  3524 ?        Ss   08:53   0:02 /opt/hostmetrics/bin/hm_scheduler

root# py-spy --pid 26089
Error: No such file or directory (os error 2)

root# py-spy top --pid $(pgrep -f 'airflow scheduler')
Error: No such file or directory (os error 2)

[Avphy]

I ran these commands as root user

[Avphy]

root# sudo py-spy top --pid $(pgrep -f 'airflow scheduler')
Error: No such file or directory (os error 2)

[potiuk]

Did you ask in py-spy forums ? I am for sure not going to look at your hands when you are typing it, but possibly you did some typo or mistake or you will find solution there.

[potiuk]

BTW. It would also be helpful if you format the output of your processes in the way that it is easy to read - right now it's not easy to find out too much from the way you submitted it here.

[potiuk]

It looks rather messy this way

[Avphy]

root      5231  0.0  0.0 1050208 34864 ?       Ssl  Jul06   0:57 /opt/docker/bin/containerd --config /opt/docker/etc/containerd-config.toml
root     23824  0.0  0.0  11796  5076 ?        Sl   Jul06   0:13  \_ containerd-shim -namespace moby -workdir /var/lib/containerd/io.containerd.runtime.v1.linux/moby/14a05121f803bef82de399f0fab87c0c39d3ccbcf6c9
user     23841  0.0  0.0  54572  9080 ?        Ss   Jul06   0:00      \_ /bin/python2.7 /sbin/simple_init.py
user     23862  0.0  0.0   4396  1136 ?        S    Jul06   0:02      |   \_ /sbin/runsvdir -P /run/sv CMD_L..........................................................................................................
user     23864  0.0  0.0   4244   668 ?        Ss   Jul06   0:00      |   |   \_ runsv prometheus
user     23871  0.0  0.0  15136  3092 ?        S    Jul06   0:00      |   |   |   \_ /bin/bash ./run
user     23879  0.0  0.0 1589020 85848 ?       Sl   Jul06   4:24      |   |   |       \_ ./prometheus --web.listen-address=127.0.0.1:9999 --storage.tsdb.retention.size=1GB --storage.tsdb.retention.time=2h --storage
user     23880  0.0  0.0   7784  1788 ?        S    Jul06   0:00      |   |   |       \_ tee -a /logs/airflow/prometheus.log
user     23866  0.0  0.0   4244   648 ?        Ss   Jul06   0:00      |   |   \_ runsv airflow
user     23876  0.0  0.0   4388  1196 ?        S    Jul06   2:59      |   |   |   \_ svlogd -tt /logs/airflow
user     13879 15.6  0.6 3053844 901124 ?      Sl   Jul09 254:15      |   |   |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     30961 15.9  0.6 3054100 875352 ?      D    00:48 100:03      |   |   |       \_ airflow scheduler -- DagFileProcessorManager
user      2060  3.1  0.0      0     0 ?        Z    11:16   0:00      |   |   |           \_ [airflow schedul] <defunct>
user     23867  0.0  0.0   4244   696 ?        Ss   Jul06   0:00      |   |   \_ runsv supercronic
user     12582  0.0  0.0 1726548 13716 ?       Sl   Jul09   0:01      |   |   |   \_ /usr/local/bin/supercronic /etc/crontab
user.    23868  0.0  0.0   4244   668 ?        Ss   Jul06   0:00      |   |   \_ runsv otelcol
user     23875  0.1  0.0 1335108 72820 ?       Sl   Jul06   7:30      |   |   |   \_ /usr/bin/otelcol --config=/etc/otelcol/otel-collector-config.yml
user     23869  0.0  0.0   4244   692 ?        Ss   Jul06   0:00      |   |   \_ runsv mysqlrouter
user     24541  6.1  0.0 1314352 85532 ?       Sl   Jul06 338:38      |   |   |   \_ /usr/bin/mysqlrouter -c /var/mysqlrouter/mysqlrouter.conf
user.    23870  0.0  0.0   4244   644 ?        Ss   Jul06   0:00      |   |   \_ runsv log_aggregator
user     23878  0.0  0.0  15140  3204 ?        S    Jul06   0:00      |   |       \_ /bin/bash ./run
user     23889  0.5  0.0 666908 21732 ?        S    Jul06  28:13      |   |           \_ /usr/bin/python3 di-log-aggr-server.py
user.    24490  0.7  0.0 1239880 30744 ?       Sl   Jul06  41:32      |   \_ /etc/runit/artifacts/statsd_exporter --web.listen-address=localhost:7002 --statsd.listen-udp=:7725 --statsd.listen-tcp=:7725 --statsd.uni
user     24596  0.0  0.1 1609316 131960 ?      S    Jul06   0:13      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     26085  0.0  5.4 9312000 7126408 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     26087  0.0  5.4 9311996 7127384 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     26089  0.0  5.4 9311996 7127388 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     26094  0.0  5.4 9311996 7127456 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     26097  0.0  5.4 9311996 7127392 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user    26100  0.0  5.4 9311996 7127468 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user.    26101  0.0  5.4 9311996 7127380 ?     S    Jul08   0:00      |   \_ /opt/rh/rh-python38/root/usr/bin/python3 /opt/rh/rh-python38/root/usr/local/bin/airflow scheduler
user     25179  0.0  0.0  15272  3584 pts/0    Ss+  Jul06   0:00      \_ sh
user     12550  0.0  0.0  15272  3476 ?        Ss   Jul09   0:00      \_ bash
user     24759  0.0  0.0   7824   676 ?        S+   Jul09   0:00          \_ tail -f /logs/airflow/scheduler_health_monitor.log

py-spy is able identify other python programs running i.e. di-log-aggr-server.py , however not recognising airflow scheduler process. I'm checking in py-spy forums too

root# py-spy top --pid 23889

[potiuk]

This is a problem with your image and init process that behaves wrongly. When you decide to run your own image, you shoudl now what you are doing in detail - there are plenty of sources that you can find that explain it - first one that I found is here https://daveiscoding.hashnode.dev/why-do-you-need-an-init-process-inside-your-docker-container-pid-1 but I am not sure of it's quality (just googled it) - but you should do your own investigation, understand it and apply good practices on how your container image should have proper init process running.

Your problem is simple_init.py. This is generally a very bad idea to run python program as "init" program and it likely does not do it's job properly.

When you run container (like it is your case), you should make sure that you properly run the init process there - see for example https://airflow.apache.org/docs/docker-stack/entrypoint.html#signal-propagation - airlfow image uses dumb-init for that purpose.

One of the tasks of init prcess is signal propagation, but another - equally important - is reaping the zombie processes. When a process gets into a "deamon" state and detaches itself from the terminal and parent process (this is what happens with Airflow scheduler), it changes its parent to the init process, and whenever any of the processes exit, it's the init process that is responsible to reap such processes (they are called "zombie" processes and the thing init is doing is "reaping the zombie processes".

The processes you see are precisely those zombies which are supposed to be reaped by the init process but they aren't, because likely your "simple_init.py" is not only simple but also wrong and is not doing zombie reaping. Zombie reaping is a low-level system behaviour and I've never heard anyone writing init process in python, and even more so - running the init with unsupported, unsecured and long time END-OF-LIFE python2.7 is very concerning. You should definitely stop doing it.

In short - your image is written in a bad way, your init process is not doing what it is supposed to be doing and you should consider either completely rewriting and changing the way you create your docker image or switch to an image that is "good" (see the link above - our image is using dumb-init and there is a good deal about configuring signal propagation there (which is important in case of celery workers).

[potiuk]

And btw this is why py-spy is not able to show anything - because those are zombie processes that do not run any code, they just take resources - like memory and sockets). This is what gave me the clue.