You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@airflow.apache.org by "Erik Forsberg (JIRA)" <ji...@apache.org> on 2017/06/01 06:34:04 UTC
[jira] [Created] (AIRFLOW-1259) Spontaneous death of gunicorn
workers due to import error
Erik Forsberg created AIRFLOW-1259:
--------------------------------------
Summary: Spontaneous death of gunicorn workers due to import error
Key: AIRFLOW-1259
URL: https://issues.apache.org/jira/browse/AIRFLOW-1259
Project: Apache Airflow
Issue Type: Bug
Affects Versions: 1.8.1
Reporter: Erik Forsberg
I'm running apache-airflow 1.8.1 in a python 3.4 virtualenv, and I'm having trouble with the webserver component going offline almost daily.
It gets worse due to AIRFLOW-1235, since the death of the process is not detected by systemd, which could otherwise restart it.
The root cause seems to be all-of-a-sudden import errors. Here's how it looked in the log from yesterday evening:
{noformat}
May 31 17:23:18 airmaster01 airflow[26096]: [2017-05-31 17:23:18 +0000] [26108] [INFO] Handling signal: ttin
May 31 17:23:18 airmaster01 airflow[26096]: [2017-05-31 17:23:18 +0000] [1412] [INFO] Booting worker with pid: 1412
May 31 17:23:18 airmaster01 airflow[26096]: [2017-05-31 17:23:18,912] [1412] {models.py:168} INFO - Filling up the DagBag from /home/airflow/production/dags
May 31 17:23:20 airmaster01 airflow[26096]: [2017-05-31 17:23:20 +0000] [26108] [INFO] Handling signal: ttou
May 31 17:23:20 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:23:20 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:23:20 airmaster01 airflow[26096]: [2017-05-31 17:23:20 +0000] [710] [INFO] Worker exiting (pid: 710)
May 31 17:23:51 airmaster01 airflow[26096]: [2017-05-31 17:23:51 +0000] [26108] [INFO] Handling signal: ttin
May 31 17:23:51 airmaster01 airflow[26096]: [2017-05-31 17:23:51 +0000] [1595] [INFO] Booting worker with pid: 1595
May 31 17:23:51 airmaster01 airflow[26096]: [2017-05-31 17:23:51,850] [1595] {models.py:168} INFO - Filling up the DagBag from /home/airflow/production/dags
May 31 17:23:53 airmaster01 airflow[26096]: [2017-05-31 17:23:53 +0000] [26108] [INFO] Handling signal: ttou
May 31 17:23:53 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:23:53 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:23:53 airmaster01 airflow[26096]: [2017-05-31 17:23:53 +0000] [895] [INFO] Worker exiting (pid: 895)
May 31 17:24:24 airmaster01 airflow[26096]: [2017-05-31 17:24:24 +0000] [26108] [INFO] Handling signal: ttin
May 31 17:24:24 airmaster01 airflow[26096]: [2017-05-31 17:24:24 +0000] [1786] [INFO] Booting worker with pid: 1786
May 31 17:24:25 airmaster01 airflow[26096]: [2017-05-31 17:24:25,008] [1786] {models.py:168} INFO - Filling up the DagBag from /home/airflow/production/dags
May 31 17:24:26 airmaster01 airflow[26096]: [2017-05-31 17:24:26 +0000] [26108] [INFO] Handling signal: ttou
...skipping...
May 31 17:29:56 airmaster01 airflow[26096]: [2017-05-31 17:29:56 +0000] [26108] [INFO] Handling signal: ttou
May 31 17:29:56 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:29:56 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:29:56 airmaster01 airflow[26096]: [2017-05-31 17:29:56 +0000] [2805] [INFO] Worker exiting (pid: 2805)
May 31 17:30:27 airmaster01 airflow[26096]: [2017-05-31 17:30:27 +0000] [26108] [INFO] Handling signal: ttin
May 31 17:30:27 airmaster01 airflow[26096]: [2017-05-31 17:30:27 +0000] [3710] [INFO] Booting worker with pid: 3710
May 31 17:30:27 airmaster01 airflow[26096]: [2017-05-31 17:30:27,859] [3710] {models.py:168} INFO - Filling up the DagBag from /home/airflow/production/dags
May 31 17:30:30 airmaster01 airflow[26096]: [2017-05-31 17:30:30 +0000] [26108] [INFO] Handling signal: ttou
May 31 17:30:30 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:30:30 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:30:30 airmaster01 airflow[26096]: [2017-05-31 17:30:30 +0000] [2994] [INFO] Worker exiting (pid: 2994)
May 31 17:31:01 airmaster01 airflow[26096]: [2017-05-31 17:31:01 +0000] [26108] [INFO] Handling signal: ttin
May 31 17:31:01 airmaster01 airflow[26096]: [2017-05-31 17:31:01 +0000] [4240] [INFO] Booting worker with pid: 4240
May 31 17:31:02 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:31:02 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:31:02 airmaster01 airflow[26096]: [2017-05-31 17:31:02 +0000] [4240] [ERROR] Exception in worker process:
May 31 17:31:02 airmaster01 airflow[26096]: Traceback (most recent call last):
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/arbiter.py", line 507, in spawn_worker
May 31 17:31:02 airmaster01 airflow[26096]: worker.init_process()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/workers/base.py", line 118, in init_process
May 31 17:31:02 airmaster01 airflow[26096]: self.wsgi = self.app.wsgi()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/base.py", line 67, in wsgi
May 31 17:31:02 airmaster01 airflow[26096]: self.callable = self.load()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/wsgiapp.py", line 65, in load
May 31 17:31:02 airmaster01 airflow[26096]: return self.load_wsgiapp()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/wsgiapp.py", line 52, in load_wsgiapp
May 31 17:31:02 airmaster01 airflow[26096]: return util.import_app(self.app_uri)
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/util.py", line 366, in import_app
May 31 17:31:02 airmaster01 airflow[26096]: app = eval(obj, mod.__dict__)
May 31 17:31:02 airmaster01 airflow[26096]: File "<string>", line 1, in <module>
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 161, in cached_app
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 60, in create_app
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/views.py", line 74, in <module>
May 31 17:31:02 airmaster01 airflow[26096]: ImportError: cannot import name 'utils'
May 31 17:31:02 airmaster01 airflow[26096]: Traceback (most recent call last):
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/arbiter.py", line 507, in spawn_worker
May 31 17:31:02 airmaster01 airflow[26096]: worker.init_process()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/workers/base.py", line 118, in init_process
May 31 17:31:02 airmaster01 airflow[26096]: self.wsgi = self.app.wsgi()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/base.py", line 67, in wsgi
May 31 17:31:02 airmaster01 airflow[26096]: self.callable = self.load()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/wsgiapp.py", line 65, in load
May 31 17:31:02 airmaster01 airflow[26096]: return self.load_wsgiapp()
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/wsgiapp.py", line 52, in load_wsgiapp
May 31 17:31:02 airmaster01 airflow[26096]: return util.import_app(self.app_uri)
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/util.py", line 366, in import_app
May 31 17:31:02 airmaster01 airflow[26096]: app = eval(obj, mod.__dict__)
May 31 17:31:02 airmaster01 airflow[26096]: File "<string>", line 1, in <module>
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 161, in cached_app
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 60, in create_app
May 31 17:31:02 airmaster01 airflow[26096]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/views.py", line 74, in <module>
May 31 17:31:02 airmaster01 airflow[26096]: ImportError: cannot import name 'utils'
May 31 17:31:02 airmaster01 airflow[26096]: [2017-05-31 17:31:02 +0000] [4240] [INFO] Worker exiting (pid: 4240)
May 31 17:31:02 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:31:02 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:31:02 airmaster01 airflow[26096]: [2017-05-31 17:31:02 +0000] [3176] [INFO] Worker exiting (pid: 3176)
May 31 17:31:02 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:31:02 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:31:02 airmaster01 airflow[26096]: [2017-05-31 17:31:02 +0000] [3510] [INFO] Worker exiting (pid: 3510)
May 31 17:31:02 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:31:02 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:31:02 airmaster01 airflow[26096]: [2017-05-31 17:31:02 +0000] [3319] [INFO] Worker exiting (pid: 3319)
May 31 17:31:02 airmaster01 airflow[26096]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 31 17:31:02 airmaster01 airflow[26096]: .format(x=modname), ExtDeprecationWarning
May 31 17:31:02 airmaster01 airflow[26096]: [2017-05-31 17:31:02 +0000] [3710] [INFO] Worker exiting (pid: 3710)
May 31 17:31:03 airmaster01 airflow[26096]: [2017-05-31 17:31:03 +0000] [26108] [INFO] Shutting down: Master
May 31 17:31:03 airmaster01 airflow[26096]: [2017-05-31 17:31:03 +0000] [26108] [INFO] Reason: Worker failed to boot.
{noformat}
Here's another example from the day before:
{noformat}
May 30 12:31:23 airmaster01 airflow[24741]: [2017-05-30 12:31:23 +0000] [24764] [INFO] Reason: Worker failed to boot.
May 30 12:31:23 airmaster01 airflow[24741]: [2017-05-30 12:31:23 +0000] [24764] [INFO] Shutting down: Master
May 30 12:31:22 airmaster01 airflow[24741]: [2017-05-30 12:31:22 +0000] [5521] [INFO] Worker exiting (pid: 5521)
May 30 12:31:22 airmaster01 airflow[24741]: .format(x=modname), ExtDeprecationWarning
May 30 12:31:22 airmaster01 airflow[24741]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 30 12:31:22 airmaster01 airflow[24741]: [2017-05-30 12:31:22 +0000] [5879] [INFO] Worker exiting (pid: 5879)
May 30 12:31:22 airmaster01 airflow[24741]: .format(x=modname), ExtDeprecationWarning
May 30 12:31:22 airmaster01 airflow[24741]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 30 12:31:22 airmaster01 airflow[24741]: [2017-05-30 12:31:22 +0000] [6036] [INFO] Worker exiting (pid: 6036)
May 30 12:31:22 airmaster01 airflow[24741]: .format(x=modname), ExtDeprecationWarning
May 30 12:31:22 airmaster01 airflow[24741]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 30 12:31:22 airmaster01 airflow[24741]: [2017-05-30 12:31:22 +0000] [5699] [INFO] Worker exiting (pid: 5699)
May 30 12:31:22 airmaster01 airflow[24741]: .format(x=modname), ExtDeprecationWarning
May 30 12:31:22 airmaster01 airflow[24741]: /opt/airflow/production/lib/python3.4/site-packages/flask/exthook.py:71: ExtDeprecationWarning: Importing flask.ext.cache is deprecated, use flask_cache instead.
May 30 12:31:21 airmaster01 airflow[24741]: [2017-05-30 12:31:21 +0000] [6554] [INFO] Worker exiting (pid: 6554)
May 30 12:31:21 airmaster01 airflow[24741]: ImportError: No module named 'airflow.www.api'
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 131, in create_app
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 161, in cached_app
May 30 12:31:21 airmaster01 airflow[24741]: File "<string>", line 1, in <module>
May 30 12:31:21 airmaster01 airflow[24741]: app = eval(obj, mod.__dict__)
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/util.py", line 366, in import_app
May 30 12:31:21 airmaster01 airflow[24741]: return util.import_app(self.app_uri)
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/wsgiapp.py", line 52, in load_wsgiapp
May 30 12:31:21 airmaster01 airflow[24741]: return self.load_wsgiapp()
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/wsgiapp.py", line 65, in load
May 30 12:31:21 airmaster01 airflow[24741]: self.callable = self.load()
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/app/base.py", line 67, in wsgi
May 30 12:31:21 airmaster01 airflow[24741]: self.wsgi = self.app.wsgi()
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/workers/base.py", line 118, in init_process
May 30 12:31:21 airmaster01 airflow[24741]: worker.init_process()
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/gunicorn/arbiter.py", line 507, in spawn_worker
May 30 12:31:21 airmaster01 airflow[24741]: Traceback (most recent call last):
May 30 12:31:21 airmaster01 airflow[24741]: ImportError: No module named 'airflow.www.api'
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 131, in create_app
May 30 12:31:21 airmaster01 airflow[24741]: File "/opt/airflow/production/lib/python3.4/site-packages/airflow/www/app.py", line 161, in cached_app
{noformat}
Here's my systemd unit file, if it's relevant:
{noformat}
[Unit]
Description=Airflow webserver production-webserver
After=network.target postgresql.service mysql.service redis.service rabbitmq-server.service
Wants=postgresql.service mysql.service redis.service rabbitmq-server.service
[Service]
Environment=PATH=/usr/sbin:/usr/bin:/sbin:/bin:/opt/airflow/production/bin
Environment=AIRFLOW_HOME=/home/airflow/production
User=airflow
Group=airflow
Type=simple
ExecStart=/opt/airflow/production/bin/airflow webserver --pid /run/airflow-production-airflow/webserver.pid
Restart=always
RestartSec=5s
[Install]
WantedBy=multi-user.target
{noformat}
Very confusing.
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)