potiuk commented on issue #21013:
URL: https://github.com/apache/airflow/issues/21013#issuecomment-1018656967
Cannot reproduce it with "standard" airflow configuration. You must have
some custom logging configuration in local settings that causes it:
```python
import datetime
from airflow import DAG
from airflow.decorators import task
from airflow.operators.python import PythonOperator
def test_log():
import logging
logger = logging.getLogger("airflow.task")
logger.info("airflow.task >>> INFO logger test")
logger.warn("airflow.task >>> WARN logger test")
logger.error("airflow.task >>> ERROR logger test")
logger.critical("airflow.task >>> CRITICAL logger test")
with DAG(
'test_log',
description='test log',
schedule_interval=None,
start_date=datetime.datetime(2022, 1, 19),
catchup=False,
tags=['log'],
) as dag:
task = PythonOperator(
task_id='test_log_task',
python_callable=test_log,
dag=dag
)
```
Resulting log:
```
*** Reading local file:
/root/airflow/logs/test_log/test_log_task/2022-01-21T16:17:12.235643+00:00/1.log
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1032} INFO - Dependencies all
met for <TaskInstance: test_log.test_log_task
manual__2022-01-21T16:17:12.235643+00:00 [queued]>
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1032} INFO - Dependencies all
met for <TaskInstance: test_log.test_log_task
manual__2022-01-21T16:17:12.235643+00:00 [queued]>
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1238} INFO -
--------------------------------------------------------------------------------
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1239} INFO - Starting attempt 1
of 1
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1240} INFO -
--------------------------------------------------------------------------------
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1259} INFO - Executing
<Task(PythonOperator): test_log_task> on 2022-01-21 16:17:12.235643+00:00
[2022-01-21, 16:17:12 UTC] {standard_task_runner.py:52} INFO - Started
process 465 to run task
[2022-01-21, 16:17:12 UTC] {standard_task_runner.py:76} INFO - Running:
['***', 'tasks', 'run', 'test_log', 'test_log_task',
'manual__2022-01-21T16:17:12.235643+00:00', '--job-id', '3', '--raw',
'--subdir', 'DAGS_FOLDER/test.py', '--cfg-path', '/tmp/tmpjrm_lflu',
'--error-file', '/tmp/tmpowwm0hd3']
[2022-01-21, 16:17:12 UTC] {standard_task_runner.py:77} INFO - Job 3:
Subtask test_log_task
[2022-01-21, 16:17:12 UTC] {logging_mixin.py:109} INFO - Running
<TaskInstance: test_log.test_log_task manual__2022-01-21T16:17:12.235643+00:00
[running]> on host afc5ced1b873
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1426} INFO - Exporting the
following env vars:
AIRFLOW_CTX_DAG_OWNER=***
AIRFLOW_CTX_DAG_ID=test_log
AIRFLOW_CTX_TASK_ID=test_log_task
AIRFLOW_CTX_EXECUTION_DATE=2022-01-21T16:17:12.235643+00:00
AIRFLOW_CTX_DAG_RUN_ID=manual__2022-01-21T16:17:12.235643+00:00
[2022-01-21, 16:17:12 UTC] {test.py:12} INFO - ***.task >>> INFO logger test
[2022-01-21, 16:17:12 UTC] {test.py:13} WARNING - ***.task >>> WARN logger
test
[2022-01-21, 16:17:12 UTC] {test.py:14} ERROR - ***.task >>> ERROR logger
test
[2022-01-21, 16:17:12 UTC] {test.py:15} CRITICAL - ***.task >>> CRITICAL
logger test
[2022-01-21, 16:17:12 UTC] {python.py:175} INFO - Done. Returned value was:
None
[2022-01-21, 16:17:12 UTC] {taskinstance.py:1277} INFO - Marking task as
SUCCESS. dag_id=test_log, task_id=test_log_task,
execution_date=20220121T161712, start_date=20220121T161712,
end_date=20220121T161712
[2022-01-21, 16:17:12 UTC] {local_task_job.py:154} INFO - Task exited with
return code 0
[2022-01-21, 16:17:12 UTC] {local_task_job.py:264} INFO - 0 downstream tasks
scheduled from follow-on schedule check
```
--
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: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
