CPU overflow on Airflow subprocesses

[4andy]

Hi, We have been running a few Airflow instances for the past few years and they have been very stable. We have very lightweight needs. We have upgraded airflow a few times and they have continued to be stable until this issue. Over the past couple of months, all of the instances have gone into a cpu overflow condition on various Airflow subprocesses; however, the issue has occurred at different times on each server seemingly randomly and we have not been able to identify a trigger for the condition. Any ideas on further troubleshooting would be appreciated.

Environment

All servers - Red Hat Enterprise Linux Server 7.9, LocalExecutor
Airflow: 2.2.5, postgresql 12.2
Airflow: 2.5.1, postgresql 15.2

Issue

Airflow subprocesses: (all: airflow scheduler - DagFileProcessor, airflow task runner, airflow task supervisor) begin to consume a full core of the machine or as much as they can get. There are no errors, tasks still complete successfully but they get slower and slower until the machine is overtaken. A task that generally takes 10 sec to run begins to run slower until it takes several minutes to run. Machine CPU usage climbs similarly. Memory usage on the server is flat and unchanging.

On a healthy instance, the airflow subprocesses consume only a percent or two of a core. (We run at all default scheduler parameter settings). The issue cannot be resolved by stopping and restarting the airflow instance. However, if the linux server is restarted, the issue is resolved for days or weeks before it arises again.

Things observed

• I have tried changing many of the scheduler parameters and they seem to have no effect on the issue. We only have ~ 50 dags with a few tasks each.
• Changing the parsing_processes from the default of 2 to many more or less seems to have no effect. E.g. 8 DagFileProcessor process will all each pull a full core of the machine.
• Core airflow processes seem to be unaffected. airflow scheduler -- DagFileProcessorManager continues to run consuming only a percent or two of a core. The webserver is fine.

The fact that restarting the linux server resolves the issue but restarting the airflow instance does not is a puzzlement for me and I have run out of ideas. As such, I thought I would reach out in hopes that someone may have additional insight or ideas that may help find the cause of the issue.

Thanks for any ideas or input you may have.

[potiuk]

IT's really hard to say but maybe a good idea would be use some profilers and see what Airflow is doing when it goes to "overdrive". Tools like https://github.com/benfred/py-spy can connect to running python interpreter and dump information on what's going on.

Maybe you could try it and provide more information?

Without it, it is shooting in the dark.

[4andy]

Thanks for the suggestion @potiuk. We will give it a try and let you know what we find.

[4andy]

One thing I did just notice - when the airflow instance is in the unhealthy state, the DagFileProcessor processes are short lived (perhaps lasting just a few seconds) and constantly being recreated (their pids keep changing).

In a healthy airflow instance, the DagFileProcessor processes are relatively long lived and consume a reasonable amount of cpu.

When unhealthy, is it possible the DagFileProcessor processes are crashing and constantly being restarted?

[4andy]

Thanks for the ideas - and yes I think we are in scenario 2 above and not using a standalone DagFileProcessor. DagFileProcessorManager is not crashing and long lived. Here are better screenshots. In the unhealthy state the DagFileProcessor processes are always present and maxed out cpu-wise. They last for a few seconds and are immediately recreated.

In a healthy state, the DagFileProcessor processes just pop up now and then with the expected refresh schedule I think - I had to wait a bit to get this screen shot when one popped up. They don't last very long either but they don't consume much cpu.

We are looking into the file descriptor/socket possibility.

[4andy]

Additionally, when in the unhealthy state, the airflow task runners and supervisor consume high CPU. Does anyone have insight into what these processes are doing and what may cause them to consume high cpu? When healthy, these processes consume very little cpu.

[potiuk]

Thos are celery processes.

And the sheer fact that you have it happening to those as well - especially the sipervisor indicates that there is a system-level problem not airflow process. You also mentioned that restarting airflow does not help (only restarting server) - that indicates that the theory around some system-wide resources being exhausted - like sockets is very likely to be the root cause.

[potiuk]

Another possibility: I see in your screenshot that your DAG files are on a NAS . There is a likelihood that this it is caused by accessing NAS for some reason - maybe you should check your NAS logs ?

[potiuk]

Maybe you also have done some maintenance/upgrade/change in your OS-level infrastructure and it coincided with airflow upgrade ?

[4andy]

Thanks for all the tips and ideas. I have done some investigation and used py-spy as suggested above. I found that the connection to the postgres backend seems to be the function that is hanging - specifically, this connect call shows up on the airflow runner task.

I did a python profile of a runner task processes on both healthy and non-healthy jobs. The healthy task was very quick and a search for 'psycopg2' in the profile only turned up one item and it was actually a sqlalchemy file.

On the unhealthy runner task was slow and has 7 calls to the hanging connect function mentioned above.

That is far as I was able to work on it today. I'm guessing that the postgres connection is either not found or disconnecting or something of the sort and airflow is having to reconnect or wait for it. I didn't see any major differences on the database side of things in a quick look. I will continue debugging tomorrow but any suggestions or ideas are always welcome.

[4andy]

I made a simple script to connect to the database with psycopg2.connect(). I can confirm that it is very slow on unhealthy servers connecting to the local database as well as remote databases. Conversely, connections from a healthy server are very fast to databases locally and to databases on unhealthy servers. As such this is definitely not an airflow issue; however, I will update this thread with the resolution when we get there if in case anyone else runs into the issue in the future.

[potiuk]

Thanks for being so diligent I would love to hear what it is.

Q: Are you using PgBouncer beetween Airflow and your Postgres ? Because if you DON't then THIS is the most probable reason. Airflow opens a lot of connection to the database and that might cause the memory usage of postgres to go ballistic if you have a lot of parallel tasks and dag file processor parsing tasks. Postgres works in the way that it spawns a new process for every connection, it does not multiplex them in the way that mysql does, so well configured PGBouncer is pretty much a MUST if you want to use Postgres.

If Postgres eats all memory and start swapping out then you might indeed have a VERY slow connection establishing process.

[4andy]

While I have not discovered the root OS item that is progressively overloading causing the db connection time to hang and be slow, PgBouncer did indeed resolve the issue. Thanks for that prompt.

[potiuk]

Glad it helped.