[ 
https://issues.apache.org/jira/browse/AIRFLOW-3064?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16649455#comment-16649455
 ] 

ASF GitHub Bot commented on AIRFLOW-3064:
-----------------------------------------

kaxil closed pull request #4051: [AIRFLOW-3064] Show logs/output from operators 
in `airflow test` command
URL: https://github.com/apache/incubator-airflow/pull/4051
 
 
   

This is a PR merged from a forked repository.
As GitHub hides the original diff on merge, it is displayed below for
the sake of provenance:

As this is a foreign pull request (from a fork), the diff is supplied
below (as it won't show otherwise due to GitHub magic):

diff --git a/airflow/bin/cli.py b/airflow/bin/cli.py
index eeef6e5eff..675a88a63c 100644
--- a/airflow/bin/cli.py
+++ b/airflow/bin/cli.py
@@ -641,6 +641,11 @@ def list_tasks(args, dag=None):
 
 @cli_utils.action_logging
 def test(args, dag=None):
+    # We want log outout from operators etc to show up here. Normally
+    # airflow.task would redirect to a file, but here we want it to propagate
+    # up to the normal airflow handler.
+    logging.getLogger('airflow.task').propagate = True
+
     dag = dag or get_dag(args)
 
     task = dag.get_task(task_id=args.task_id)
diff --git a/tests/cli/test_cli.py b/tests/cli/test_cli.py
index aeafdd85fe..f274fe907d 100644
--- a/tests/cli/test_cli.py
+++ b/tests/cli/test_cli.py
@@ -18,6 +18,8 @@
 # under the License.
 #
 
+from six import StringIO
+import sys
 import unittest
 
 from datetime import datetime, timedelta, time
@@ -28,6 +30,7 @@
 import subprocess
 from argparse import Namespace
 from airflow import settings
+import airflow.bin.cli as cli
 from airflow.bin.cli import get_num_ready_workers_running, run, get_dag
 from airflow.models import TaskInstance
 from airflow.utils import timezone
@@ -183,6 +186,29 @@ def test_local_run(self):
             state = ti.current_state()
             self.assertEqual(state, State.SUCCESS)
 
+    def test_test(self):
+        """Test the `airflow test` command"""
+        args = create_mock_args(
+            task_id='print_the_context',
+            dag_id='example_python_operator',
+            subdir=None,
+            execution_date=timezone.parse('2018-01-01')
+        )
+
+        saved_stdout = sys.stdout
+        try:
+            sys.stdout = out = StringIO()
+            cli.test(args)
+
+            output = out.getvalue()
+            # Check that prints, and log messages, are shown
+            self.assertIn('Done. Returned value was: Whatever you return gets 
printed in the logs',
+                          output)
+            
self.assertIn("'example_python_operator__print_the_context__20180101'",
+                          output)
+        finally:
+            sys.stdout = saved_stdout
+
     def test_next_execution(self):
         # A scaffolding function
         def reset_dr_db(dag_id):


 

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
[email protected]


> 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
>            Assignee: Ash Berlin-Taylor
>            Priority: Minor
>
> 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)

Reply via email to