You should always init the logger. It is bad practice not to do it. Log = logging.getLogger(__name__)
Is the canonical way. In Airflow we provide some convenience functions for operators etc. The loggingmixin can help out. Bolke Verstuurd vanaf mijn iPad > Op 17 okt. 2017 om 20:21 heeft Boris Tyukin <[email protected]> het > volgende geschreven: > > thank you both! so my understanding instead one liner like > logging.info("something") > > I need to init logger first in a python operator and only after that I can > invoke logger.info like below. This is a bit unexpected and a bit more work > but it does work now - thanks. Maybe I was not doing it right in the first > place but hey it did work in 1.8 :) > > logger = logging.getLogger('airflow.python_test_logging') > logger.info('hi from loggin info') > > On Tue, Oct 17, 2017 at 6:35 AM, Driesprong, Fokko <[email protected]> > wrote: > >> Hi Boris, >> >> This is interesting. >> >> When I run the example you provide with the latest Airflow release, I get: >> root@9e3cf03c0544:~# airflow test python_test_logging print_the_context >> 2017-01-01 >> [2017-10-17 10:27:38,321] {__init__.py:45} INFO - Using executor >> SequentialExecutor >> [2017-10-17 10:27:38,359] {models.py:186} INFO - Filling up the DagBag from >> /root/airflow/dags >> [2017-10-17 10:27:38,406] {dag.py:30} WARNING - test warn >> [2017-10-17 10:27:38,406] {dag.py:31} INFO - test info >> [2017-10-17 10:27:38,429] {models.py:1165} INFO - Dependencies all met for >> <TaskInstance: python_test_logging.print_the_context 2017-01-01 00:00:00 >> [None]> >> [2017-10-17 10:27:38,432] {models.py:1165} INFO - Dependencies all met for >> <TaskInstance: python_test_logging.print_the_context 2017-01-01 00:00:00 >> [None]> >> [2017-10-17 10:27:38,432] {models.py:1375} INFO - >> ------------------------------------------------------------ >> -------------------- >> Starting attempt 1 of 1 >> ------------------------------------------------------------ >> -------------------- >> >> [2017-10-17 10:27:38,433] {models.py:1396} INFO - Executing >> <Task(PythonOperator): print_the_context> on 2017-01-01 00:00:00 >> {'END_DATE': '2017-01-01', >> 'conf': <module 'airflow.configuration' from >> '/usr/local/lib/python3.6/site-packages/airflow/configuration.py'>, >> 'dag': <DAG: python_test_logging>, >> 'dag_run': None, >> 'ds_nodash': '20170101', >> 'end_date': '2017-01-01', >> 'execution_date': datetime.datetime(2017, 1, 1, 0, 0), >> 'latest_date': '2017-01-01', >> 'macros': <module 'airflow.macros' from >> '/usr/local/lib/python3.6/site-packages/airflow/macros/__init__.py'>, >> 'next_execution_date': None, >> 'params': {}, >> 'prev_execution_date': None, >> 'run_id': None, >> 'tables': None, >> 'task': <Task(PythonOperator): print_the_context>, >> 'task_instance': <TaskInstance: python_test_logging.print_the_context >> 2017-01-01 00:00:00 [None]>, >> 'task_instance_key_str': >> 'python_test_logging__print_the_context__20170101', >> 'templates_dict': None, >> 'test_mode': True, >> 'ti': <TaskInstance: python_test_logging.print_the_context 2017-01-01 >> 00:00:00 [None]>, >> 'tomorrow_ds': '2017-01-02', >> 'tomorrow_ds_nodash': '20170102', >> 'ts': '2017-01-01T00:00:00', >> 'ts_nodash': '20170101T000000', >> 'var': {'json': None, 'value': None}, >> 'yesterday_ds': '2016-12-31', >> 'yesterday_ds_nodash': '20161231'} >> hi from print >> [2017-10-17 10:27:38,441] {python_operator.py:90} INFO - Done. Returned >> value was: None >> >> When I change it to `warn`, I do get: >> WARNING:root:hi from loggin info >> >> By giving an explicit logger, as Daniel suggested, that starts with >> airflow%: >> def print_context(ds, **kwargs): >> pprint(kwargs) >> print('hi from print') >> logger = logging.getLogger('airflow.python_test_logging') >> logger.info('hi from loggin info') >> >> Then it is picked up by the Airflow logging context: >> [2017-10-17 10:31:05,639] {dag.py:23} INFO - hi from loggin info >> >> This is how the current logging is set: >> https://github.com/apache/incubator-airflow/blob/master/ >> airflow/config_templates/airflow_local_settings.py >> >> Currently I'm investigating why it used to work in Airflow 1.8. This is not >> yet clear to me. >> >> Cheers, Fokko >> >> >> 2017-10-17 7:58 GMT+02:00 Daniel Lamblin [Data Science & Platform Center] < >> [email protected]>: >> >>> Boris, I don't see where you configured the default logger >>> <https://docs.python.org/2/howto/logging.html#configuring-logging>. I >>> think >>> you'd have to at least throw in: >>> logger = logging.getLogger('python_test_logging') >>> and then use the logger.info(…) instead of logging.info(…) >>> >>> On Tue, Oct 17, 2017 at 3:00 AM, Boris Tyukin <[email protected]> >>> wrote: >>> >>>> sorry i was not clear. >>>> >>>> In DAG definition file, I would normally import logging and when use >> with >>>> python operator like below (see print_context). >>>> >>>> In 1.8.2 i would see in Airflow log file (for that task) both 'hi from >>>> print' and 'hi from logging'. >>>> >>>> now I can only see 'hi from print'. >>>> >>>> I installed from master (pip install), and used newer airflow.cfg file. >>>> Only updated it to use local executor and mysql db. Did not change any >>>> other settings. >>>> >>>> So my question if it is supposed to work like that and how do I log now >>>> from python operators in a dag. >>>> >>>> >>>> from __future__ import print_function >>>> from builtins import range >>>> import airflow >>>> from airflow.operators.python_operator import PythonOperator >>>> from airflow.models import DAG >>>> import logging >>>> import time >>>> from pprint import pprint >>>> >>>> args = { >>>> 'owner': 'airflow', >>>> 'start_date': airflow.utils.dates.days_ago(2) >>>> } >>>> >>>> dag = DAG( >>>> dag_id='python_test_logging', default_args=args, >>>> schedule_interval=None) >>>> >>>> def print_context(ds, **kwargs): >>>> pprint(kwargs) >>>> print('hi from print') >>>> logging.info('hi from loggin info') >>>> >>>> run_this = PythonOperator( >>>> task_id='print_the_context', >>>> provide_context=True, >>>> python_callable=print_context, >>>> dag=dag) >>>> >>>> >>>> On Mon, Oct 16, 2017 at 1:09 PM, Driesprong, Fokko >> <[email protected] >>>> >>>> wrote: >>>> >>>>> Hi Boris, >>>>> >>>>> Can you please elaborate? Where did the output used to end up? Did >> you >>>>> provide any custom logging config, or are you using the default >> config? >>>>> Maybe drop some example code. >>>>> >>>>> Cheers, Fokko >>>>> >>>>> 2017-10-16 19:02 GMT+02:00 Boris <[email protected]>: >>>>> >>>>>> Hi guys, >>>>>> >>>>>> I used to do logging.info("somthing") from airflow python >> operators >>>> so i >>>>>> can see output in airflow logs. Worked fine in 1.8.2. >>>>>> >>>>>> Looks like this is no longer the case with master branch.I did look >>> at >>>>>> updating.md but still not clear how to log custom messages from >>> python >>>>>> operators. >>>>>> >>>>>> please advise. >>>>>> >>>>> >>>> >>> >>> >>> >>> -- >>> -Daniel Lamblin >>> >>
