You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@airflow.apache.org by "goktugkose (via GitHub)" <gi...@apache.org> on 2024/05/14 09:38:01 UTC
[I] Google Stackdriver Logging not working as expected [airflow]
goktugkose opened a new issue, #39613:
URL: https://github.com/apache/airflow/issues/39613
### Apache Airflow version
2.9.1
### If "Other Airflow 2 version" selected, which one?
_No response_
### What happened?
We are experiencing an issue with Stackdriver Logging with Airflow. As changelog suggests, with Airflow 2.9.1 version Google provider is updated to 10.17.0 and solves the bugs with Stackdriver logging. We tested with the latest version. However, we cannot configure remote logging with Stackdriver. As an initial step, we created a log bucket in Cloud Monitoring and also created a log sink to investigate the logs. We use the configuration below in Helm chart, `GOOGLE_APPLICATION_CREDENTIALS` is set as an environment variable and a Google Cloud connection containing the same service account is added to Airflow with these scopes `https://www.googleapis.com/auth/cloud-platform`, `https://www.googleapis.com/auth/logging.admin`
**Findings:**
1. Same service account works fine with GCS Logging.
2. No logs are written in the base_log_folder
**Problems faced:**
1. Documentation states that the logs supposed to be shown in real time. However, we are waiting for logs to be loaded to Airflow UI.
2. Shown logs does not contain the application logs that are printed using logging library. (I will share the DAG file in the thread.)
**Example DAG File:**
```
from datetime import datetime
from airflow import DAG
from airflow.operators.python_operator import PythonOperator
import logging, time
logger = logging.getLogger(__name__)
logging.basicConfig(level=logging.INFO)
default_args = {
'owner': 'admin',
'depends_on_past': False,
'start_date': datetime(2024, 4, 24),
"retries": 0,
}
dag = DAG('test', default_args=default_args, schedule_interval="*/20 * * * *", catchup=False, max_active_runs=1, tags=["test"])
def func():
steps = 10
logger.info(f"Executing {steps} steps...")
for i in range(10):
logger.info(f"Step {i+1} executed.")
time.sleep(1)
logger.info("Successfully finished!")
task_1 = PythonOperator(
dag = dag,
task_id = 'task_1',
python_callable = func
)
task_1
```
**Produced Logs (not real time, they appear after task completion):**
```
[2024-05-09, 16:40:04 +03] {local_task_job_runner.py:120} ▼ Pre task execution logs
[2024-05-09, 16:40:05 +03] {taskinstance.py:2076} INFO - Dependencies all met for dep_context=non-requeueable deps ti=<TaskInstance: test.task_1 scheduled__2024-05-09T13:20:00+00:00 [queued]>
[2024-05-09, 16:40:05 +03] {taskinstance.py:2076} INFO - Dependencies all met for dep_context=requeueable deps ti=<TaskInstance: test.task_1 scheduled__2024-05-09T13:20:00+00:00 [queued]>
[2024-05-09, 16:40:05 +03] {taskinstance.py:2306} INFO - Starting attempt 1 of 1
[2024-05-09, 16:40:06 +03] {taskinstance.py:2330} INFO - Executing <Task(PythonOperator): task_1> on 2024-05-09 13:20:00+00:00
[2024-05-09, 16:40:06 +03] {warnings.py:110} WARNING - /home/airflow/.local/lib/python3.12/site-packages/airflow/task/task_runner/standard_task_runner.py:61: DeprecationWarning: This process (pid=865) is multi-threaded, use of fork() may lead to deadlocks in the child.
pid = os.fork()
[2024-05-09, 16:40:06 +03] {standard_task_runner.py:63} INFO - Started process 882 to run task
[2024-05-09, 16:40:31 +03] {local_task_job_runner.py:310} WARNING - State of this instance has been externally set to success. Terminating instance.
[2024-05-09, 16:40:31 +03] {local_task_job_runner.py:222} ▲▲▲ Log group end
```
```
[2024-05-09, 16:40:31 +03] {process_utils.py:132} INFO - Sending 15 to group 882. PIDs of all processes in the group: [882]
[2024-05-09, 16:40:31 +03] {process_utils.py:87} INFO - Sending the signal 15 to group 882
[2024-05-09, 16:40:31 +03] {process_utils.py:80} INFO - Process psutil.Process(pid=882, status='terminated', exitcode=0, started='13:40:05') (882) terminated with exit code 0
```
### What you think should happen instead?
As suggested by Airflow documentation, logs should be loaded in real time. Other logging configurations such as Elasticsearch provides this behavior. Also, task logs should also be served in the UI. I have tested with GCS Logging and we expect to see the similar logs with Stackdriver logging.
```
```
### How to reproduce
- `GOOGLE_APPLICATION_CREDENTIALS` with roles `roles/logging.admin` and `roles/monitoring.admin`
- `Helm 3.12.3`
- Celery Executor
- `apache-airflow-providers-google==10.17.0`
- Airflow 2.9.1
- Helm Chart values:
```
config:
logging:
remote_logging: 'True'
remote_base_log_folder: "stackdriver:///<log-name>"
remote_log_conn_id: "<connection-id>"
google_key_path: "<path-to-mounted-service-account-file>"
```
### Operating System
Debian GNU/Linux 12 (bookworm)
### Versions of Apache Airflow Providers
```
apache-airflow-providers-amazon | 8.20.0
apache-airflow-providers-celery | 3.6.2
apache-airflow-providers-cncf-kubernetes | 8.1.1
apache-airflow-providers-common-io | 1.3.1
apache-airflow-providers-common-sql | 1.12.0
apache-airflow-providers-docker | 3.10.0
apache-airflow-providers-elasticsearch | 5.3.4
apache-airflow-providers-fab | 1.0.4
apache-airflow-providers-ftp | 3.8.0
apache-airflow-providers-google | 10.17.0
apache-airflow-providers-grpc | 3.4.1
apache-airflow-providers-hashicorp | 3.6.4
apache-airflow-providers-http | 4.10.1
apache-airflow-providers-imap | 3.5.0
apache-airflow-providers-microsoft-azure | 10.0.0
apache-airflow-providers-mysql | 5.5.4
apache-airflow-providers-odbc | 4.5.0
apache-airflow-providers-openlineage | 1.7.0
apache-airflow-providers-postgres | 5.10.2
apache-airflow-providers-redis | 3.6.1
apache-airflow-providers-sendgrid | 3.4.0
apache-airflow-providers-sftp | 4.9.1
apache-airflow-providers-slack | 8.6.2
apache-airflow-providers-smtp | 1.6.1
apache-airflow-providers-snowflake | 5.4.0
apache-airflow-providers-sqlite | 3.7.1
apache-airflow-providers-ssh | 3.10.1
```
### Deployment
Official Apache Airflow Helm Chart
### Deployment details
_No response_
### Anything else?
_No response_
### Are you willing to submit PR?
- [ ] Yes I am willing to submit a PR!
### Code of Conduct
- [X] I agree to follow this project's [Code of Conduct](https://github.com/apache/airflow/blob/main/CODE_OF_CONDUCT.md)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "boring-cyborg[bot] (via GitHub)" <gi...@apache.org>.
boring-cyborg[bot] commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-2109740793
Thanks for opening your first issue here! Be sure to follow the issue template! If you are willing to raise PR to address this issue please do so, no need to wait for approval.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "ashb (via GitHub)" <gi...@apache.org>.
ashb commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-3242358132
Can someone please confirm if this issue is still present or not?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "potiuk (via GitHub)" <gi...@apache.org>.
potiuk commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-3262104870
Agreed.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "random-user-hdbbjw (via GitHub)" <gi...@apache.org>.
random-user-hdbbjw commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-2122202796
#30740
Actually the BackgroundThreadTransport mode of StackdriverTaskHandler is not working properly.
I also have a airflow running KubernetesExecutor and eventually I have to implement custom logging config to override BackgroundThreadTransport with SyncTransport in order to show full log.
Also showing logs from stackdriver is slow.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "kaxil (via GitHub)" <gi...@apache.org>.
kaxil commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-5942897899
This was addressed by #65198, released in apache-airflow-providers-google 22.1.0: on Airflow 3 the handler sends each task log line to Cloud Logging as it is emitted and flushes the transport when the task finishes. If you still see logs missing on the latest release, comment here and we'll reopen.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "VladaZakharova (via GitHub)" <gi...@apache.org>.
VladaZakharova commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-3253239824
After my investigation on this issue I see two big problems with StackdriverTaskHandler. In addition I need to say that StackdriverTaskHandler has never worked as expected. From its creating this StackdriverTaskHandler has these problems and the community several times started discussing these problems. In my opinion the best solution here is refactoring for this StackdriverTaskHandler.
Problems:
- StackdriverTaskHandler sends only partially logs to Google Stackdriver service. This problem happens because BackgroundThreadTransport, which is used as a default transport to send logs to Stackdriver, doesn't work as expected and sends only part of the logs. This issue is inside BackgroundThreadTransport and isn't related to Airflow, more information about it here: https://github.com/googleapis/python-logging/issues/550 Like a temporary solution we can change default transport to SyncTransport and this problem will disappear. But, I didn't find what was the reason to use BackgroundThreadTransport as a default.
- StackdriverTaskHandler doesn't read logs in real time from Google Stackdriver service. For this problem I don't see any solution now. Documentation for StackdriverTaskHandler mentions that this handler prints logs to Airflow UI in real time, but when I run DAG this behavior doesn't happen. At the current moment StackdriverTaskHandler waits for the task ending and then pulls logs from Stackdriver. We can update the docs and describe to users real behavior for this handler or we can start a refactoring for implement behavior which was described in the docs.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "Niltra (via GitHub)" <gi...@apache.org>.
Niltra commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-4970957067
Hi! I'm looking to make my first contribution to Apache Airflow. I'd like to work on this issue if it's still available.
From what I see in the current code (main branch), the two main problems are:
1. `BackgroundThreadTransport` is the default transport — logs arrive with a delay instead of in real time
2. Application-level logs from `logging.getLogger(...)` inside DAGs aren't captured by `StackdriverTaskHandler`
I understand there's ongoing work on the structlog/RemoteLogIO migration (#65191). I'd like to start with fixing the default transport (switching to `SyncTransport` or making it configurable), and then tackle the application log capture issue.
Could you assign this to me? Happy to discuss the approach before submitting a PR.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "potiuk (via GitHub)" <gi...@apache.org>.
potiuk commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-2109880434
cc: @VladaZakharova and Google team
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "VladaZakharova (via GitHub)" <gi...@apache.org>.
VladaZakharova commented on issue #39613:
URL: https://github.com/apache/airflow/issues/39613#issuecomment-2111988297
> cc: @VladaZakharova and Google team
Sure, we will take a look :)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] Google Stackdriver Logging not working as expected [airflow]
Posted by "kaxil (via GitHub)" <gi...@apache.org>.
kaxil closed issue #39613: Google Stackdriver Logging not working as expected
URL: https://github.com/apache/airflow/issues/39613
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org