Terminating process, that starts API workers does not terminate the workers, when run under tox

[Kirill Zaitsev]

Experiencing an issue with master, my HEAD points to 7e27d6ef05ec856e7b62f65218bdef3896ac55a2

Here is full log of glance-api

$ tox -e venv -- glance-api --config-file=/home/teferi/glance/etc/glance-api.conf
venv develop-inst-noop: /home/teferi/glance
venv installed: aioeventlet==0.4,alembic==0.8.4,amqp==1.4.9,anyjson==0.3.3,-e git+https://git.openstack.org/openstack/app-catalog@2ea8f13555a07ac3b32abcf6b5ef40c4012bb5f2#egg=app_catalog_artifact_plugin&subdirectory=contrib/glare,appdirs==1.4.0,automaton==1.2.0,Babel==2.2.0,cachetools==1.1.5,castellan==0.3.1,cffi==1.5.2,contextlib2==0.5.1,coverage==4.0.3,cryptography==1.2.2,debtcollector==1.3.0,decorator==4.0.9,docutils==0.12,enum34==1.1.2,eventlet==0.18.4,extras==0.0.3,fasteners==0.14.1,fixtures==1.4.0,flake8==2.2.4,funcsigs==0.4,functools32==3.2.3.post2,futures==3.0.5,futurist==0.12.0,-e git+https://git.openstack.org/openstack/glance@7e27d6ef05ec856e7b62f65218bdef3896ac55a2#egg=glance,glance-store==0.11.0,greenlet==0.4.9,hacking==0.10.2,httplib2==0.9.2,idna==2.0,ipaddress==1.0.16,iso8601==0.1.11,Jinja2==2.8,jsonschema==2.5.1,keystoneauth1==2.3.0,keystonemiddleware==4.3.0,kombu==3.0.33,linecache2==1.0.0,Mako==1.0.3,MarkupSafe==0.23,mccabe==0.2.1,mock==1.3.0,monotonic==0.6,mox3==0.14.0,msgpack-python==0.4.7,netaddr==0.7.18,netifaces==0.10.4,networkx==1.11,os-client-config==1.15.0,oslo.concurrency==3.4.0,oslo.config==3.7.0,oslo.context==2.0.0,oslo.db==4.5.0,oslo.i18n==3.3.0,oslo.log==3.0.0,oslo.messaging==4.3.0,oslo.middleware==3.6.0,oslo.policy==1.4.0,oslo.serialization==2.3.0,oslo.service==1.5.0,oslo.utils==3.6.0,oslosphinx==4.3.0,oslotest==2.1.0,osprofiler==1.1.0,Paste==2.0.2,PasteDeploy==1.5.2,pbr==1.8.1,pep8==1.5.7,pika==0.10.0,pika-pool==0.1.3,positional==1.0.1,prettytable==0.7.2,psutil==1.2.1,psycopg2==2.6.1,pyasn1==0.1.9,pycadf==2.1.0,pycparser==2.14,pycrypto==2.6.1,pyflakes==0.8.1,Pygments==2.1.1,pyinotify==0.9.6,PyMySQL==0.7.1,pyOpenSSL==0.15.1,pyrsistent==0.11.12,pysendfile==2.0.1,python-dateutil==2.4.2,python-editor==0.5,python-keystoneclient==2.2.0,python-mimeparse==1.5.1,python-subunit==1.2.0,python-swiftclient==2.7.0,pytz==2015.7,PyYAML==3.11,qpid-python==0.32,reno==1.5.0,repoze.lru==0.6,requests==2.9.1,requestsexceptions==1.1.3,retrying==1.3.3,Routes==2.2,semantic-version==2.5.0,simplegeneric==0.8.1,six==1.10.0,Sphinx==1.2.3,SQLAlchemy==1.0.12,sqlalchemy-migrate==0.10.0,sqlparse==0.1.18,stevedore==1.11.0,taskflow==1.28.0,Tempita==0.5.2,testrepository==0.0.20,testresources==1.0.0,testscenarios==0.5.0,testtools==2.0.0,traceback2==1.4.0,trollius==2.1,unittest2==1.1.0,WebOb==1.5.1,wheel==0.29.0,wrapt==1.10.6,WSME==0.8.0,xattr==0.7.9
venv runtests: PYTHONHASHSEED='1343193181'
venv runtests: commands[0] | glance-api --config-file=/home/teferi/glance/etc/glance-api.conf
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/oslo_middleware/ssl.py:28: DeprecationWarning: The 'oslo_middleware.ssl' module usage is deprecated, please use oslo_middleware.http_proxy_to_wsgi instead
  "oslo_middleware.http_proxy_to_wsgi")
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/cryptography/x509/__init__.py:32: PendingDeprecationWarning: CRLExtensionOID has been renamed to CRLEntryExtensionOID
  from cryptography.x509.oid import (
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
/home/teferi/glance/.tox/venv/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py:22: DeprecationWarning: Parameters to load are deprecated. Call .resolve and .require separately.
  return pkg_resources.EntryPoint.parse("x=" + s).load(False)
2016-02-22 22:48:56.511 28167 INFO glance_store._drivers.filesystem [-] Directory to write image files does not exist (/var/lib/glance/images). Creating.
2016-02-22 22:48:56.512 28167 ERROR glance_store._drivers.filesystem [-] Unable to create datadir: /var/lib/glance/images
2016-02-22 22:48:56.512 28167 WARNING glance_store.driver [-] Failed to configure store correctly: Store filesystem could not be configured correctly. Reason: Unable to create datadir: /var/lib/glance/images Disabling add method.
2016-02-22 22:48:56.513 28167 INFO glance.common.wsgi [-] Starting 2 workers
2016-02-22 22:48:56.515 28167 INFO glance.common.wsgi [-] Started child 28174
2016-02-22 22:48:56.518 28167 INFO glance.common.wsgi [-] Started child 28175
2016-02-22 22:48:56.519 28174 INFO eventlet.wsgi.server [-] (28174) wsgi starting up on http://0.0.0.0:9292
2016-02-22 22:48:56.522 28175 INFO eventlet.wsgi.server [-] (28175) wsgi starting up on http://0.0.0.0:9292
^CERROR: KEYBOARDINTERRUPT

process hangs, seemingly forever, another Ctrl+C kills it

^CERROR: keyboardinterrupt

Same behaviour is experienced when sending a TERM signal to the proc, that forked the workers.

But the worker processes are still there.

$ ps ax | grep glance-api
28167 pts/0 S 0:01 /home/teferi/glance/.tox/venv/bin/python .tox/venv/bin/glance-api --config-file=/home/teferi/glance/etc/glance-api.conf
28174 pts/0 S 0:00 /home/teferi/glance/.tox/venv/bin/python .tox/venv/bin/glance-api --config-file=/home/teferi/glance/etc/glance-api.conf
28175 pts/0 S 0:00 /home/teferi/glance/.tox/venv/bin/python .tox/venv/bin/glance-api --config-file=/home/teferi/glance/etc/glance-api.conf
28188 pts/0 S+ 0:00 grep --color=auto glance-api

$ uname -a
Linux 3.13.0-52-generic #86-Ubuntu SMP Mon May 4 04:32:59 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

[Kirill Zaitsev (kzaitsev)]

This behaviour is not being reproduced if running glance-api directly (i.e by activating the venv environment and running glance-api directly)

[Stuart McLaren (stuart-mclaren)]

I checked this for glance-api running under systemd. A SIGTERM sent to the parent process did result in the child processes successfully being terminated.

I wonder if the behaviour may be due to tox intercepting the interrupts. If so, there's no change we can make to glance which would result in the children being terminated.

A SIGKILL may be a workaround (or as Kirill says, source the virtual env and run the api server directly).