[jira] [Created] (AIRFLOW-3064) Tutorial says to expect output, but no output due to default logging config

["Brian King (JIRA)" <ji...@apache.org>]

Brian King created AIRFLOW-3064:
-----------------------------------

             Summary: Tutorial says to expect output, but no output due to default logging config
                 Key: AIRFLOW-3064
                 URL: https://issues.apache.org/jira/browse/AIRFLOW-3064
             Project: Apache Airflow
          Issue Type: Bug
          Components: Documentation, logging
    Affects Versions: 1.10.0
         Environment: CentOS release 6.5, Python 2.7.5
            Reporter: Brian King


On [https://airflow.incubator.apache.org/tutorial.html#id1] , it says about running the test commands:
{quote}This should result in displaying a verbose log of events and ultimately running your bash command and printing the result. 

Note that the {{airflow test}} command runs task instances locally, outputs their log to stdout (on screen), ...
{quote}
 In fact, there is some logging output, but no output of the tasks:
{code:java}
$ airflow test tutorial print_date 2015-06-01
[2018-09-14 14:43:58,380] {__init__.py:51} INFO - Using executor SequentialExecutor
[2018-09-14 14:43:58,493] {models.py:258} INFO - Filling up the DagBag from /vagrant/airflow/dags
[2018-09-14 14:43:58,571] {example_kubernetes_operator.py:54} WARNING - Could not import KubernetesPodOperator: No module named kubernetes
[2018-09-14 14:43:58,572] {example_kubernetes_operator.py:55} WARNING - Install kubernetes dependencies with:     pip install airflow['kubernetes']{code}
 

I looked at the logging config, and thought that perhaps the task output would be logged to a file (since the default logging config's task handler logs to files), but I didn't find anything (relevant) in the log directory.

To see the task output, I had to use a custom logging config, based on the DEFAULT_LOGGING_CONFIG, that used the console handler instead of the task handler for the 'airflow.task' logger:
{code:java}
'loggers': {
    'airflow.task': {
        # 'handlers': ['task'],
        'handlers': ['console'],
        'level': 'INFO',
        'propagate': False,
    },{code}
This results in the task output showing up:
{code:java}
$ airflow test tutorial print_date 2015-06-01
[2018-09-14 14:49:16,897] {__init__.py:51} INFO - Using executor SequentialExecutor
[2018-09-14 14:49:17,017] {models.py:258} INFO - Filling up the DagBag from /vagrant/airflow/dags
[2018-09-14 14:49:17,093] {example_kubernetes_operator.py:54} WARNING - Could not import KubernetesPodOperator: No module named kubernetes
[2018-09-14 14:49:17,093] {example_kubernetes_operator.py:55} WARNING - Install kubernetes dependencies with:     pip install airflow['kubernetes']
[2018-09-14 14:49:17,176] {models.py:1335} INFO - Dependencies all met for <TaskInstance: tutorial.print_date 2015-06-01T00:00:00+00:00 [None]>
[2018-09-14 14:49:17,179] {models.py:1335} INFO - Dependencies all met for <TaskInstance: tutorial.print_date 2015-06-01T00:00:00+00:00 [None]>
[2018-09-14 14:49:17,179] {models.py:1547} INFO -
--------------------------------------------------------------------------------
Starting attempt 1 of 2
--------------------------------------------------------------------------------

[2018-09-14 14:49:17,180] {models.py:1569} INFO - Executing <Task(BashOperator): print_date> on 2015-06-01T00:00:00+00:00
[2018-09-14 14:49:17,236] {bash_operator.py:74} INFO - Tmp dir root location:
 /tmp
[2018-09-14 14:49:17,237] {bash_operator.py:87} INFO - Temporary script location: /tmp/airflowtmp6ieJDv/print_dateZV3cw8
[2018-09-14 14:49:17,237] {bash_operator.py:97} INFO - Running command: date
[2018-09-14 14:49:17,241] {bash_operator.py:106} INFO - Output:
[2018-09-14 14:49:17,250] {bash_operator.py:110} INFO - Fri Sep 14 14:49:17 UTC 2018
[2018-09-14 14:49:17,252] {bash_operator.py:114} INFO - Command exited with return code 0{code}
 

That change to the logging config is probably not the appropriate change to make for real life usage, but for someone working through the tutorial, it's nice to see the output.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)