From commits-return-18139-archive-asf-public=cust-asf.ponee.io@airflow.incubator.apache.org Mon Aug 13 19:55:11 2018 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id 1753B180629 for ; Mon, 13 Aug 2018 19:55:09 +0200 (CEST) Received: (qmail 4408 invoked by uid 500); 13 Aug 2018 17:55:09 -0000 Mailing-List: contact commits-help@airflow.incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@airflow.incubator.apache.org Delivered-To: mailing list commits@airflow.incubator.apache.org Received: (qmail 4399 invoked by uid 99); 13 Aug 2018 17:55:09 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 13 Aug 2018 17:55:09 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id 4622218098D for ; Mon, 13 Aug 2018 17:55:08 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -109.501 X-Spam-Level: X-Spam-Status: No, score=-109.501 tagged_above=-999 required=6.31 tests=[ENV_AND_HDR_SPF_MATCH=-0.5, KAM_ASCII_DIVIDERS=0.8, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, USER_IN_DEF_SPF_WL=-7.5, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id GDwPbuUUXhoc for ; Mon, 13 Aug 2018 17:55:01 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id 6CE9A5F3AF for ; Mon, 13 Aug 2018 17:55:01 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 7B0B0E070F for ; Mon, 13 Aug 2018 17:55:00 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 2686123F9D for ; Mon, 13 Aug 2018 17:55:00 +0000 (UTC) Date: Mon, 13 Aug 2018 17:55:00 +0000 (UTC) From: "Taylor Edmiston (JIRA)" To: commits@airflow.incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (AIRFLOW-2844) Airflow Logs BrokenPipeException MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/AIRFLOW-2844?page=3Dcom.atlassi= an.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=3D16= 578708#comment-16578708 ]=20 Taylor Edmiston commented on AIRFLOW-2844: ------------------------------------------ [~Kyle Bridenstine] Given your answer above, do you think this issue should= remain open? > Airflow Logs BrokenPipeException > -------------------------------- > > Key: AIRFLOW-2844 > URL: https://issues.apache.org/jira/browse/AIRFLOW-2844 > Project: Apache Airflow > Issue Type: Bug > Components: logging > Affects Versions: 1.9.0 > Reporter: Kyle Bridenstine > Priority: Critical > > I'm using a clustered Airflow environment where I have four AWS ec2-insta= nces for the servers. > *ec2-instances* > - Server 1: Webserver, Scheduler, Redis Queue, PostgreSQL Database > - Server 2: Webserver > - Server 3: Worker > - Server 4: Worker > My setup has been working perfectly fine for three months now but sporadi= cally about once a week I get a Broken Pipe Exception when Airflow is attem= pting to log something. > {code:java} > Log file isn't local. > Fetching here: http://ip-1-2-3-4:8793/log/foobar/task_1/2018-07-13T00:00:= 00/1.log > [2018-07-16 00:00:15,521] {cli.py:374} INFO - Running on host ip-1-2-3-4 > [2018-07-16 00:00:15,698] {models.py:1197} INFO - Dependencies all met fo= r > [2018-07-16 00:00:15,710] {models.py:1197} INFO - Dependencies all met fo= r > [2018-07-16 00:00:15,710] {models.py:1407} INFO -=20 > -------------------------------------------------------------------------= ------- > Starting attempt 1 of 1 > -------------------------------------------------------------------------= ------- > [2018-07-16 00:00:15,719] {models.py:1428} INFO - Executing on 2018-07-13 00:00:00 > [2018-07-16 00:00:15,720] {base_task_runner.py:115} INFO - Running: ['bas= h', '-c', 'airflow run foobar task_1 2018-07-13T00:00:00 --job_id 1320 --ra= w -sd DAGS_FOLDER/datalake_digitalplatform_arl_workflow_schedule_test_2.py'= ] > [2018-07-16 00:00:16,532] {base_task_runner.py:98} INFO - Subtask: [2018-= 07-16 00:00:16,532] {configuration.py:206} WARNING - section/key [celery/ce= lery_ssl_active] not found in config > [2018-07-16 00:00:16,532] {base_task_runner.py:98} INFO - Subtask: [2018-= 07-16 00:00:16,532] {default_celery.py:41} WARNING - Celery Executor will r= un without SSL > [2018-07-16 00:00:16,534] {base_task_runner.py:98} INFO - Subtask: [2018-= 07-16 00:00:16,533] {_init_.py:45} INFO - Using executor CeleryExecutor > [2018-07-16 00:00:16,597] {base_task_runner.py:98} INFO - Subtask: [2018-= 07-16 00:00:16,597] {models.py:189} INFO - Filling up the DagBag from /home= /ec2-user/airflow/dags/datalake_digitalplatform_arl_workflow_schedule_test_= 2.py > [2018-07-16 00:00:16,768] {cli.py:374} INFO - Running on host ip-1-2-3-4 > [2018-07-16 00:16:24,931] {logging_mixin.py:84} WARNING - =E2=80=94 Loggi= ng error =E2=80=94 > [2018-07-16 00:16:24,931] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-07-16 00:16:24,931] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/_init_.py", line 996, in emit > self.flush() > [2018-07-16 00:16:24,932] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/_init_.py", line 976, in flush > self.stream.flush() > [2018-07-16 00:16:24,932] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-07-16 00:16:24,932] {logging_mixin.py:84} WARNING - Call stack: > [2018-07-16 00:16:24,933] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 78, in ex= ecute > while not self.poke(context): > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - File "/home/ec2= -user/airflow/plugins/custom_plugins.py", line 35, in poke > directory =3D os.listdir(full_path) > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/timeout.py", line 36, in handle= _timeout > self.log.error("Process timed out") > [2018-07-16 00:16:24,934] {logging_mixin.py:84} WARNING - Message: 'Proce= ss timed out' > Arguments: () > [2018-07-16 00:16:24,942] {models.py:1595} ERROR - Timeout > Traceback (most recent call last): > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 148= 8, in _run_raw_task > result =3D task_copy.execute(context=3Dcontext) > File "/usr/local/lib/python3.6/site-packages/airflow/operators/sensors.py= ", line 78, in execute > while not self.poke(context): > File "/home/ec2-user/airflow/plugins/custom_plugins.py", line 35, in poke > directory =3D os.listdir(full_path) > File "/usr/local/lib/python3.6/site-packages/airflow/utils/timeout.py", l= ine 37, in handle_timeout > raise AirflowTaskTimeout(self.error_message) > airflow.exceptions.AirflowTaskTimeout: Timeout > [2018-07-16 00:16:24,942] {models.py:1624} INFO - Marking task as FAILED. > [2018-07-16 00:16:24,956] {models.py:1644} ERROR - Timeout > {code} > Sometimes the error will also say > {code:java} > Log file isn't local. > Fetching here: http://ip-1-2-3-4:8793/log/foobar/task_1/2018-07-12T00:00:= 00/1.log > Failed to fetch log file from worker. 404 Client Error: NOT FOUND for url= : http://ip-1-2-3-4:8793/log/foobar/task_1/2018-07-12T00:00:00/1.log > {code} > I'm not sure why the logs are working ~95% of the time but are randomly f= ailing at other times. Here are my log settings in my Airflow.cfg file, > {code:java} > # The folder where airflow should store its log files > # This path must be absolute > base_log_folder =3D /home/ec2-user/airflow/logs > # Airflow can store logs remotely in AWS S3 or Google Cloud Storage. User= s > # must supply an Airflow connection id that provides access to the storag= e > # location. > remote_log_conn_id =3D > encrypt_s3_logs =3D False > # Logging level > logging_level =3D INFO > # Logging class > # Specify the class that will specify the logging configuration > # This class has to be on the python classpath > # logging_config_class =3D my.path.default_local_settings.LOGGING_CONFIG > logging_config_class =3D > # Log format > log_format =3D [%%(asctime)s] {%%(filename)s:%%(lineno)d} %%(levelname)s = - %%(message)s > simple_log_format =3D %%(asctime)s %%(levelname)s - %%(message)s > # Name of handler to read task instance logs. > # Default to use file task handler. > task_log_reader =3D file.task > # Log files for the gunicorn webserver. '-' means log to stderr. > access_logfile =3D - > error_logfile =3D=20 > # The amount of time (in secs) webserver will wait for initial handshake > # while fetching logs from other worker machine > log_fetch_timeout_sec =3D 5 > # When you start an airflow worker, airflow starts a tiny web server > # subprocess to serve the workers local log files to the airflow main > # web server, who then builds pages and sends them to users. This defines > # the port on which the logs are served. It needs to be unused, and open > # visible from the main web server to connect into the workers. > worker_log_server_port =3D 8793 > # How often should stats be printed to the logs > print_stats_interval =3D 30 > child_process_log_directory =3D /home/ec2-user/airflow/logs/scheduler{cod= e} > I'm wondering if maybe I should try a different technique for my logging = such as writing to an S3 Bucket or if there is something else I can do to f= ix this issue. > *Update:* > Writing the logs to S3 did not resolve this issue. Also, the error is mor= e consistent now (still sporadic). It's happening more like 50% of the time= now. One thing I noticed is that the task it's happening on is my AWS EMR = creation task. Starting an AWS EMR cluster takes about 20 minutes and then = the task has to wait for the Spark commands to run on the EMR cluster. So t= he single task is running for about 30 minutes. I'm wondering if this is to= o long for an Airflow task to be running and if that's why it starts to fai= l writing to the logs. If this is the case then I could breakup the EMR tas= k so that there is one task for the EMR creation, then another task for the= Spark commands on the EMR cluster. > =C2=A0*Update 2:* > Sometimes I see slightly different details in the output of the error suc= h as this > {code:java} > *** Log file isn't local. > *** Fetching here: http://ip-1-2-3-4:1234/log/dag_name/task_name/2018-07-= 30T00:00:00/9.log > [2018-08-01 15:24:52,002] {cli.py:374} INFO - Running on host ip-1-2-3-4 > [2018-08-01 15:24:52,383] {models.py:1197} INFO - Dependencies all met fo= r > [2018-08-01 15:24:52,538] {models.py:1197} INFO - Dependencies all met fo= r > [2018-08-01 15:24:52,538] {models.py:1407} INFO -=20 > -------------------------------------------------------------------------= ------- > Starting attempt 9 of 9 > -------------------------------------------------------------------------= ------- > [2018-08-01 15:24:52,618] {models.py:1428} INFO - Executing on 2018-07-30 00:00:00 > [2018-08-01 15:24:52,619] {base_task_runner.py:115} INFO - Running: ['bas= h', '-c', 'airflow run dag_name task_name 2018-07-30T00:00:00 --job_id 410 = --raw -sd DAGS_FOLDER/dag_name.py'] > [2018-08-01 15:25:00,650] {base_task_runner.py:98} INFO - Subtask: [2018-= 08-01 15:25:00,649] {configuration.py:206} WARNING - section/key [celery/ce= lery_ssl_active] not found in config > [2018-08-01 15:25:00,682] {base_task_runner.py:98} INFO - Subtask: [2018-= 08-01 15:25:00,682] {default_celery.py:41} WARNING - Celery Executor will r= un without SSL > [2018-08-01 15:25:00,684] {base_task_runner.py:98} INFO - Subtask: [2018-= 08-01 15:25:00,683] {__init__.py:45} INFO - Using executor CeleryExecutor > [2018-08-01 15:25:01,151] {base_task_runner.py:98} INFO - Subtask: [2018-= 08-01 15:25:01,151] {models.py:189} INFO - Filling up the DagBag from /var/= lib/airflow/dags/dag_name.py > [2018-08-01 15:25:03,909] {cli.py:374} INFO - Running on host ip-1-2-3-4 > [2018-08-02 13:13:47,130] {models.py:1470} ERROR - Killing subprocess > [2018-08-02 13:13:47,560] {models.py:1595} ERROR - Task received SIGTERM = signal > Traceback (most recent call last): > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 148= 8, in _run_raw_task > result =3D task_copy.execute(context=3Dcontext) > File "/usr/local/lib/python3.6/site-packages/airflow/operators/sensors.py= ", line 84, in execute > sleep(self.poke_interval) > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 147= 2, in signal_handler > raise AirflowException("Task received SIGTERM signal") > airflow.exceptions.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:47,561] {models.py:1624} INFO - Marking task as FAILED. > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:47,639] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,640] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:47,640] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:47,640] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:47,640] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 70,= in execute > self.log.info("Tmp dir root location: \n %s", gettempdir()) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - Message: 'Tmp d= ir root location: \n %s' > Arguments: ('/tmp',) > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,641] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:47,642] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:47,642] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:47,642] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:47,642] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:47,642] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,719] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 80,= in execute > script_location > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - Message: 'Tempo= rary script location: %s' > Arguments: ('/tmp/airflowtmp81ztdhnm//tmp/airflowtmp81ztdhnm/failure_task= _notificationlzixk4ar',) > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:47,720] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 88,= in execute > self.log.info("Running command: %s", bash_command) > [2018-08-02 13:13:47,721] {logging_mixin.py:84} WARNING - Message: 'Runni= ng command: %s' > Arguments: ('aws sns publish --topic-arn arn:aws:sns:us-east-1:4648168634= 26:datalake_digital_platform_arl_airflow_workflow --message "The ARL Airflo= w Workflow = task has failed." --region us-east-1',) > [2018-08-02 13:13:47,835] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:47,836] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:47,837] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:47,837] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:47,837] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 97,= in execute > self.log.info("Output:") > [2018-08-02 13:13:47,837] {logging_mixin.py:84} WARNING - Message: 'Outpu= t:' > Arguments: () > [2018-08-02 13:13:57,731] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:57,731] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:57,731] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:57,731] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:57,731] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 101= , in execute > self.log.info(line) > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - Message: '{' > Arguments: () > [2018-08-02 13:13:57,732] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:57,733] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 101= , in execute > self.log.info(line) > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - Message: '"Mess= ageId": "7c284092-dc0c-539b-97b9-134fe219aacd"' > Arguments: () > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - --- Logging err= or --- > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1488, in _run_raw_ta= sk > result =3D task_copy.execute(context=3Dcontext) > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/sensors.py", line 84, in ex= ecute > sleep(self.poke_interval) > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1472, in signal_hand= ler > raise AirflowException("Task received SIGTERM signal") > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - airflow.excepti= ons.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING -=20 > During handling of the above exception, another exception occurred: > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - Traceback (most= recent call last): > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 996, in emit > self.flush() > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/lib6= 4/python3.6/logging/__init__.py", line 976, in flush > self.stream.flush() > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - BrokenPipeError= : [Errno 32] Broken pipe > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - Call stack: > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/bin/= airflow", line 27, in > args.func(args) > [2018-08-02 13:13:57,734] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/bin/cli.py", line 392, in run > pool=3Dargs.pool, > [2018-08-02 13:13:57,735] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/utils/db.py", line 50, in wrapper > result =3D func(*args, **kwargs) > [2018-08-02 13:13:57,735] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1530, in _run_raw_ta= sk > self.handle_failure(e, test_mode, context) > [2018-08-02 13:13:57,735] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/models.py", line 1636, in handle_fail= ure > task.on_failure_callback(context) > [2018-08-02 13:13:57,735] {logging_mixin.py:84} WARNING - File "/var/lib/= airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > [2018-08-02 13:13:57,735] {logging_mixin.py:84} WARNING - File "/usr/loca= l/lib/python3.6/site-packages/airflow/operators/bash_operator.py", line 101= , in execute > self.log.info(line) > [2018-08-02 13:13:57,735] {logging_mixin.py:84} WARNING - Message: '}' > Arguments: () > [2018-08-02 13:13:58,639] {models.py:1470} ERROR - Killing subprocess > [2018-08-02 13:13:58,640] {models.py:1638} ERROR - Failed at executing ca= llback > [2018-08-02 13:13:58,640] {models.py:1639} ERROR - Task received SIGTERM = signal > Traceback (most recent call last): > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 148= 8, in _run_raw_task > result =3D task_copy.execute(context=3Dcontext) > File "/usr/local/lib/python3.6/site-packages/airflow/operators/sensors.py= ", line 84, in execute > sleep(self.poke_interval) > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 147= 2, in signal_handler > raise AirflowException("Task received SIGTERM signal") > airflow.exceptions.AirflowException: Task received SIGTERM signal > During handling of the above exception, another exception occurred: > Traceback (most recent call last): > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 163= 6, in handle_failure > task.on_failure_callback(context) > File "/var/lib/airflow/dags/dag_name.py", line 36, in on_failure_callback > return failure_task_notification.execute(context=3Dcontext) > File "/usr/local/lib/python3.6/site-packages/airflow/operators/bash_opera= tor.py", line 99, in execute > for line in iter(sp.stdout.readline, b''): > File "/usr/local/lib/python3.6/site-packages/airflow/models.py", line 147= 2, in signal_handler > raise AirflowException("Task received SIGTERM signal") > airflow.exceptions.AirflowException: Task received SIGTERM signal > [2018-08-02 13:13:59,126] {models.py:1644} ERROR - Task received SIGTERM = signal{code} > *Note:* > I've also created a Stackoverflow question for this issue here=C2=A0[http= s://stackoverflow.com/questions/51365911/airflow-logs-brokenpipeexception] -- This message was sent by Atlassian JIRA (v7.6.3#76005)