If anyone else is seeing this (and I think I'm on stock configuration now) yes I do, as I'm not seeing _any_ logs form task operators appearing.
There's another problem after applying a local fix for `handler.set_context()`, to do with try_numbers: The `airflow run tests test-logging 2017-11-26T00:00:00 --local -sd /usr/local/airflow/dags/example/.py` command sends logs to .../14.log The `airflow run tests test-logging 2017-11-26T00:00:00 --job_id 33 --raw -sd /usr/local/airflow/dags/example/.py` command (that the previous command invokes) sends logs to .../15.log However the UI doesn't know about try 15 (yes try 15. I've been running this a bit) so any future runs will write to this file. At this point I might be a bit deep and might need to look with fresh eyes and a clean slate tomorrow. Someone confirming if they do or don't see logs from inside an operator would help me. -ash > On 30 Nov 2017, at 17:03, Chris Riccomini <[email protected]> wrote: > > @Ash, do you think this issue is blocking for 1.9.0? > > On Thu, Nov 30, 2017 at 8:22 AM, Ash Berlin-Taylor < > [email protected]> wrote: > >> Ah, I think I've got it. >> >> The problem is that airflow.task.raw doesn't have an explicit config >> anymore(?), so when we do: >> >> log = logging.getLogger('airflow.task.raw') >> >> and look at its handlers, it doesn't have any. But log.parent.handlers >> _does_ have them. >> >> A few options to fix this: >> >> - I can add an explicit handler for .task.raw in my logging config. >> - We can always call set_context on airflow.task instead of >> airflow.task.raw >> - We walk up the .parent links if .propagate is True (possibly stopping >> once we find any handlers) >> >> -ash >> >> >>> On 30 Nov 2017, at 16:02, Ash Berlin-Taylor <ash_airflowlist@firemirror. >> com> wrote: >>> >>> I'm fairly sure I'm back to stock config now. Here is the DAG I am >> testing with: >>> >>> from datetime import datetime >>> from airflow import DAG >>> from airflow.operators.python_operator import PythonOperator >>> >>> dag_args = { >>> "start_date": datetime(2017, 11, 20), >>> } >>> dag = DAG("tests", default_args=dag_args) >>> >>> >>> def print_stuff(ti, **kwargs): >>> print("Hi from", __file__) >>> ti.log.error("Hello") >>> >>> with dag: >>> PythonOperator( >>> task_id="test-logging", >>> dag=dag, >>> python_callable=print_stuff, >>> provide_context=True, >>> ) >>> >>> >>> And I don't see either of the "Hi from" or "Hello" lines in the >> resulting log file. I have edited airflow/logging_config.py to print the >> config before it uses it, and this is the config I'm getting: >>> >>> {'disable_existing_loggers': False, >>> 'formatters': {'airflow.processor': {'format': '[%(asctime)s] ' >>> >> '{%(filename)s:%(lineno)d} ' >>> '%(levelname)s - >> %(message)s'}, >>> 'airflow.task': {'format': '[%(asctime)s] ' >>> '{%(filename)s:%(lineno)d} ' >>> '%(levelname)s - >> %(message)s'}}, >>> 'handlers': {'console': {'class': 'logging.StreamHandler', >>> 'formatter': 'airflow.task', >>> 'stream': 'ext://sys.stdout'}, >>> 'file.processor': {'base_log_folder': >> '/usr/local/airflow/logs/scheduler', >>> 'class': 'airflow.utils.log.file_ >> processor_handler.FileProcessorHandler', >>> 'filename_template': '{{ filename >> }}.log', >>> 'formatter': 'airflow.processor'}, >>> 'file.task': {'base_log_folder': '/usr/local/airflow/logs/', >>> 'class': 'airflow.utils.log.file_task_ >> handler.FileTaskHandler', >>> 'filename_template': '{{ ti.dag_id }}/{{ ' >>> 'ti.task_id }}/{{ ts >> }}/{{ ' >>> 'try_number }}.log', >>> 'formatter': 'airflow.task'}}, >>> 'loggers': {'': {'handlers': ['console'], 'level': 'INFO'}, >>> 'airflow': {'handlers': ['console'], >>> 'level': 'INFO', >>> 'propagate': False}, >>> 'airflow.processor': {'handlers': ['file.processor'], >>> 'level': 'INFO', >>> 'propagate': True}, >>> 'airflow.task': {'handlers': ['file.task'], >>> 'level': 'INFO', >>> 'propagate': False}, >>> 'airflow.task_runner': {'handlers': ['file.task'], >>> 'level': 'INFO', >>> 'propagate': True}}, >>> >>> >>> If I edit run() in in bin/cli.py to print the log.handlers under this >> circumstance I get an empty list []. >>> >>> I guess since we don't specify 'airflow.task.raw' in the loggers that it >> should go up to the next level in 'airflow.task'? Except it doesn't seem to >> be for me. I'm digging further. >>> >>> -ash >>> >>> >>> >>>> On 30 Nov 2017, at 15:38, Bolke de Bruin <[email protected]> wrote: >>>> >>>> airflow.task.raw points to airflow.task by default, which does have a >> handler and that is the one that is travelled. And yes we know the code is >> incorrect in this area, but the default does work correctly. >>>> >>>> Bolke. >>>> >>>> >>>>> On 30 Nov 2017, at 16:27, Ash Berlin-Taylor < >> [email protected]> wrote: >>>>> >>>>> Okay I think the problem (if not the cause) is around here: >> https://github.com/apache/incubator-airflow/blob/master/ >> airflow/bin/cli.py#L366-L376 >>>>> >>>>> >>>>> >>>>> log = logging.getLogger('airflow.task') >>>>> if args.raw: >>>>> log = logging.getLogger('airflow.task.raw') >>>>> >>>>> for handler in log.handlers: >>>>> try: >>>>> handler.set_context(ti) >>>>> except AttributeError: >>>>> # Not all handlers need to have context passed in so we ignore >>>>> # the error when handlers do not have set_context defined. >>>>> pass >>>>> >>>>> The problem seems to be that airflow.task.raw is no longer configured >> explicitly, so it's log.handlers is an empty list. >>>>> >>>>> This in turn means that any log calls end up not writing anything as >> our FileTaskHandler's self.handler property is None, meaning it doesn't >> emit anything. >>>>> >>>>> Does this ring any bells to anyone? >>>>> >>>>> >>>>>> On 30 Nov 2017, at 15:18, Ash Berlin-Taylor < >> [email protected]> wrote: >>>>>> >>>>>> Hmmm is anyone else seeing logs from inside operators? Right now >> we're not getting any logs out of operators. I'm in the process of >> debugging to work out if it's our logging config or something in Airflow, >> but right now I don't seem to get any output from the operator itself, >> neither print(), or `ti.log.info()` >>>>>> >>>>>> Anyone else noticed similar, or is it something specific to our >> environment? >>>>>> >>>>>> -ash >>>>>> >>>>>>> On 30 Nov 2017, at 09:52, Ash Berlin-Taylor < >> [email protected]> wrote: >>>>>>> >>>>>>> We're running more tests (day of meetings meant we couldn't do as >> many as I'd have liked yesterday) but looking good so far. >>>>>>> >>>>>>> +0.5 (non binding) >>>>>>> >>>>>>> -ash >>>>>>> >>>>>>>> On 29 Nov 2017, at 18:31, Chris Riccomini <[email protected]> >> wrote: >>>>>>>> >>>>>>>> Anyone else? Last day before I close the vote off. >>>>>>>> >>>>>>>> On Mon, Nov 27, 2017 at 12:32 PM, Driesprong, Fokko >> <[email protected]> >>>>>>>> wrote: >>>>>>>> >>>>>>>>> +1 >>>>>>>>> >>>>>>>>> Op ma 27 nov. 2017 om 21:24 schreef Bolke de Bruin < >> [email protected]> >>>>>>>>> >>>>>>>>>> +1, binding >>>>>>>>>> >>>>>>>>>> Let’s get it out! >>>>>>>>>> >>>>>>>>>> Sent from my iPhone >>>>>>>>>> >>>>>>>>>>> On 27 Nov 2017, at 20:32, Chris Riccomini <[email protected] >>> >>>>>>>>> wrote: >>>>>>>>>>> >>>>>>>>>>> Hey all, >>>>>>>>>>> >>>>>>>>>>> I have cut Airflow 1.9.0 RC4. This email is calling a vote on the >>>>>>>>>> release, >>>>>>>>>>> which will last for 72 hours. Consider this my (binding) +1. >>>>>>>>>>> >>>>>>>>>>> Airflow 1.9.0 RC4 is available at: >>>>>>>>>>> >>>>>>>>>>> https://dist.apache.org/repos/dist/dev/incubator/airflow/1. >> 9.0rc4/ >>>>>>>>>>> >>>>>>>>>>> apache-airflow-1.9.0rc4+incubating-source.tar.gz is a source >> release >>>>>>>>> that >>>>>>>>>>> comes with INSTALL instructions. >>>>>>>>>>> apache-airflow-1.9.0rc4+incubating-bin.tar.gz is the binary >> Python >>>>>>>>>> "sdist" >>>>>>>>>>> release. >>>>>>>>>>> >>>>>>>>>>> Public keys are available at: >>>>>>>>>>> >>>>>>>>>>> https://dist.apache.org/repos/dist/release/incubator/airflow/ >>>>>>>>>>> >>>>>>>>>>> The release contains the following JIRAs: >>>>>>>>>>> >>>>>>>>>>> *https://issues.apache.org/jira/browse/AIRFLOW-1839 >>>>>>>>>>> <https://issues.apache.org/jira/browse/AIRFLOW-1839>* >>>>>>>>>>> >>>>>>>>>>> Along with all JIRAs that were in 1.9.0RC3 (see previous VOTE >> email for >>>>>>>>>>> full list). >>>>>>>>>>> >>>>>>>>>>> Cheers, >>>>>>>>>>> Chris >>>>>>>>>> >>>>>>>>> >>>>>>> >>>>>> >>>>> >>>> >>> >> >>
