Cannot fetch log from Celery worker

[emredjan]

Apache Airflow version

2.4.0

What happened

When running tasks on a remote celery worker, webserver fails to fetch logs from the machine, giving a '403 - Forbidden' error on version 2.4.0. This behavior does not happen on 2.3.3, where the remote logs are retrieved and displayed successfully.
The webserver / secret_key configuration is the same in all nodes (the config files are synced), and their time is synchronized using a central NTP server, making the solution in the warning message not applicable.

My limited analysis pointed to the serve_logs.py file, and the flask request object that's passed to it, but couldn't find the root cause.

What you think should happen instead

It should fetch and show remote celery worker logs on the webserver UI correctly, as it did in previous versions.

How to reproduce

Use airflow version 2.4.0
Use CeleryExecutor with RabbitMQ
Use a separate Celery worker machine
Run a dag/task on the remote worker
Try to display task log on the web UI

Operating System

Red Hat Enterprise Linux 8.6 (Ootpa)

Versions of Apache Airflow Providers

apache-airflow-providers-celery==3.0.0
apache-airflow-providers-common-sql==1.1.0
apache-airflow-providers-ftp==3.0.0
apache-airflow-providers-hashicorp==3.0.0
apache-airflow-providers-http==3.0.0
apache-airflow-providers-imap==3.0.0
apache-airflow-providers-microsoft-mssql==3.0.0
apache-airflow-providers-mysql==3.0.0
apache-airflow-providers-odbc==3.0.0
apache-airflow-providers-sftp==3.0.0
apache-airflow-providers-sqlite==3.0.0
apache-airflow-providers-ssh==3.0.0

Deployment

Virtualenv installation

Deployment details

Using CeleryExecutor / rabbitmq with 2 servers

Anything else

All remote task executions has the same problem.

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct

[boring-cyborg[bot]]

Thanks for opening your first issue here! Be sure to follow the issue template!

[potiuk]

Could be connected to IPV6 issue #24846 - which has been fixed in Airflow 2.4.0 (relased today) see #26201 - please upgrade to 2.4.0 and see if the problem persists (and please comment here). If it does not fix it (or even before) - taje a look at the logs of webserver and they should contain error logs/explanation where it was from.

Converting to discussion as this is likely solved or need more detailed looking in the logs.

[emredjan]

Sorry if not clear, but this already happened in 2.4.0, which I installed today (It was fine on 2.3.3 and before).
Running on Python 3.10.5.

This is the message from the web UI:

This is the relevant log from the remote celery worker when the web UI requests the task log:

Sep 19 15:55:05 airflow[3734318]: [2022-09-19 15:55:05,027: INFO/ForkPoolWorker-15] Task airflow.executors.celery_executor.execute_command[af1dec61-b437-4605-980c-de2d65f60bd7] succeeded in 0.9207695280201733s: None
Sep 19 15:55:11 airflow[3734281]: [2022-09-19 15:55:11,177] {serve_logs.py:104} WARNING - Unknown error
Sep 19 15:55:11 airflow[3734281]: Traceback (most recent call last):
Sep 19 15:55:11 airflow[3734281]:   File "/data/apps/.pyenv/versions/3.10.5/envs/airflow-py310/lib/python3.10/site-packages/airflow/utils/serve_logs.py", line 64, in validate_pre_signed_url
Sep 19 15:55:11 airflow[3734281]:     request_filename = request.view_args['filename']
Sep 19 15:55:11 airflow[3734281]: TypeError: 'NoneType' object is not subscriptable

Looks like the request.view_args is None in the validation function. Don't know whether it's the root cause though.

Do you need any additional logs?

[patricker]

We are seeing the same exact error in our worker logs coming from serve_logs.py during upgrade testing from 2.3.4 to 2.4.0.
Python 3.9, Celery, Kubernetes.

[patricker]

I think this was resolved on #26492?

[potiuk]

Yes. There was a bug in 2.4.0 that has a workaround you can apply manually from #26493 and it will be fixed permanently in 2.4.1

[potiuk]

It was my bug too, so I am not sure if I can take a credit for that one :D

[HassanAlahmed]

@potiuk We all make them mistakes. You found and fixed the issue promptly, so of course you can take credit.

So I checked tag 2.4.0 from airflow, add the bug fix, and built and image using docker build --tag <tag>. When I used the image in the helm chart deployment, the run-migration-job failed with the following error:

alembic.util.exc.CommandError: Can't locate revision identified by 'ecb43d2a1842'

I checked the alembic_version table in my metadata db, and ecb43d2a1842 is already applied. I'm not sure why the run-migration-job is trying to apply this migration, and I'm not sure why the revision cannot be located. Could you please shed some light on this? Sorry for bothering you so much with my questions. I really appreciate your help.

[potiuk]

I think the problem is that for some reson your image is not based on airflow 2.4.0. That would be the error. There might be multiple reasons for that - wrong tag, wrong docker image, accidental downgrade of airflow by some unrelated dependency. I think you should verify if your Docker image really contains the right version and look closely that the output of your docker build.

[potiuk]

(ultimately I think waiting for 2.4.1 - rc planned today or tomorrow) is probably a good idea :)

[potiuk]

2.4.1 is out with the fix :)