@bolke/@fokko, thoughts?
As an aside, we had an issue seeing task logs, but were able to fix it by
modifying our logging config (and perhaps patching some stuff that we
merged into 1.9.0, don't recall). William Pursell/Joy Gao might be able to
comment more.
On Thu, Nov 30, 2017 at 9:08 AM, Ash Berlin-Taylor <
ash_airflowl...@firemirror.com> wrote:
> 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 <criccom...@apache.org> 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 <
> > ash_airflowl...@firemirror.com> 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 <bdbr...@gmail.com> 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 <
> >> ash_airflowl...@firemirror.com> 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 <
> >> ash_airflowl...@firemirror.com> 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 <
> >> ash_airflowl...@firemirror.com> 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 <criccom...@apache.org>
> >> wrote:
> >>>>>>>>
> >>>>>>>> Anyone else? Last day before I close the vote off.
> >>>>>>>>
> >>>>>>>> On Mon, Nov 27, 2017 at 12:32 PM, Driesprong, Fokko
> >> <fo...@driesprong.frl>
> >>>>>>>> wrote:
> >>>>>>>>
> >>>>>>>>> +1
> >>>>>>>>>
> >>>>>>>>> Op ma 27 nov. 2017 om 21:24 schreef Bolke de Bruin <
> >> bdbr...@gmail.com>
> >>>>>>>>>
> >>>>>>>>>> +1, binding
> >>>>>>>>>>
> >>>>>>>>>> Let’s get it out!
> >>>>>>>>>>
> >>>>>>>>>> Sent from my iPhone
> >>>>>>>>>>
> >>>>>>>>>>> On 27 Nov 2017, at 20:32, Chris Riccomini <
> criccom...@apache.org
> >>>
> >>>>>>>>> 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
> >>>>>>>>>>
> >>>>>>>>>
> >>>>>>>
> >>>>>>
> >>>>>
> >>>>
> >>>
> >>
> >>
>
>
