yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #63680
[Bug 1687073] [NEW] Keystone Memory usage remains high
Public bug reported:
I found something interesting while doing a quick load test of keystone
/ newton . When I started the load test the memory usage for keystone
processes (admin and public wsgi) went up – and it never came down even
hours after the test is stopped. Also found few errors in the log
(given below ) . E
Also, found that many functions in resource/backends/sql.py are not closing the sessions once open .
Do we need to close the sessions explicitly ? Is that the reason for persistent high memory usage ?
Below error is thrown during the test . I guess the error may be due to settings in keystone.conf. Not sure it has anything to do with memory cleanup .
Attached is the script to execute stress test . It will launch 40 threads, and hit keystone at the same time
----------------------------------
Error-
2017-04-28 14:17:20.702 653 INFO keystone.common.wsgi [req-651d1776-9e5c-405c-82d2-3efe7dbcd5f3 - - - - -] POST http://10.10.10.2:5000/v3/auth/tokens
2017-04-28 14:17:20.878 691 INFO keystone.common.wsgi [req-8bd6baa6-976d-41b5-817a-554b3a7d6c54 - - - - -] GET http://192.168.204.2:35357/v3/
2017-04-28 14:17:20.898 691 INFO keystone.common.wsgi [req-da74eaeb-34d9-4190-8477-fd14a16fab3f b94369832d4d41cea555a9e98c216dd7 f9f5aa29f7994730b0fc845aaba5ade5 - default default] GET http://192.168.204.2:35357/v3/projects
2017-04-28 14:17:20.915 692 INFO keystone.common.wsgi [req-38122a48-2c97-4b41-b3a0-b2a9062c68ac - - - - -] POST http://10.10.10.2:5000/v3/auth/tokens
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi [req-2208fddc-6801-4a9c-a6fd-22cfd310427d - - - - -] QueuePool limit of size 1 overflow 10 reached, connection timed out, timeout 30
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi Traceback (most recent call last):
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/common/wsgi.py", line 225, in __call__
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi result = method(req, **params)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 397, in authenticate_for_token
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi auth_info = AuthInfo.create(auth=auth)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 137, in create
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi auth_info._validate_and_normalize_auth_data(scope_only)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 310, in _validate_and_normalize_auth_data
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi self._validate_and_normalize_scope_data()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 252, in _validate_and_normalize_scope_data
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi project_ref = self._lookup_project(self.auth['scope']['project'])
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 215, in _lookup_project
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi domain_ref = self._lookup_domain(project_info['domain'])
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 189, in _lookup_domain
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi domain_ref = self.resource_api.get_domain(domain_id)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 1220, in decorate
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi should_cache_fn)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 825, in get_or_create
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi async_creator) as value:
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/lock.py", line 154, in __enter__
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._enter()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/lock.py", line 94, in _enter
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/lock.py", line 145, in _enter_create
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi created = self.creator()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 792, in gen_value
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi created_value = creator()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 1216, in creator
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return fn(*arg, **kw)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/resource/core.py", line 705, in get_domain
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi project = self.driver.get_project(domain_id)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/resource/backends/sql.py", line 49, in get_project
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._get_project(session, project_id).to_dict()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/resource/backends/sql.py", line 42, in _get_project
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi project_ref = session.query(Project).get(project_id)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 831, in get
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._get_impl(ident, loading.load_on_ident)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 864, in _get_impl
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return fallback_fn(self, key)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/loading.py", line 219, in load_on_ident
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return q.one()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2693, in one
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi ret = list(self)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2736, in __iter__
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._execute_and_instances(context)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2749, in _execute_and_instances
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi close_with_result=True)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2740, in _connection_from_session
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi **kw)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 905, in connection
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi execution_options=execution_options)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 910, in _connection_for_bind
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi engine, execution_options)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 334, in _connection_for_bind
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi conn = bind.contextual_connect()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2039, in contextual_connect
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi self._wrap_pool_connect(self.pool.connect, None),
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2074, in _wrap_pool_connect
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return fn()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 376, in connect
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return _ConnectionFairy._checkout(self)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 713, in _checkout
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi fairy = _ConnectionRecord.checkout(pool)
2017-04-28 14:17:
2017-04-28 14:17:21.176 691 INFO keystone.common.wsgi [req-09fdd07f-4b7c-4a4c-8115-4e4164eea3e5 fbe1c86982b042f8bc942ad45a2bbcbe 5db2b66a3ea34a1ea9899ad9cfe8b2dd - default default] GET http://192.168.204.2:35357/v3/auth/tokens
** Affects: keystone
Importance: Undecided
Status: New
** Tags: keystone memory
** Attachment added: "Load test script"
https://bugs.launchpad.net/bugs/1687073/+attachment/4869249/+files/main_test.py
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Identity (keystone).
https://bugs.launchpad.net/bugs/1687073
Title:
Keystone Memory usage remains high
Status in OpenStack Identity (keystone):
New
Bug description:
I found something interesting while doing a quick load test of
keystone / newton . When I started the load test the memory usage for
keystone processes (admin and public wsgi) went up – and it never came
down even hours after the test is stopped. Also found few errors in
the log (given below ) . E
Also, found that many functions in resource/backends/sql.py are not closing the sessions once open .
Do we need to close the sessions explicitly ? Is that the reason for persistent high memory usage ?
Below error is thrown during the test . I guess the error may be due to settings in keystone.conf. Not sure it has anything to do with memory cleanup .
Attached is the script to execute stress test . It will launch 40 threads, and hit keystone at the same time
----------------------------------
Error-
2017-04-28 14:17:20.702 653 INFO keystone.common.wsgi [req-651d1776-9e5c-405c-82d2-3efe7dbcd5f3 - - - - -] POST http://10.10.10.2:5000/v3/auth/tokens
2017-04-28 14:17:20.878 691 INFO keystone.common.wsgi [req-8bd6baa6-976d-41b5-817a-554b3a7d6c54 - - - - -] GET http://192.168.204.2:35357/v3/
2017-04-28 14:17:20.898 691 INFO keystone.common.wsgi [req-da74eaeb-34d9-4190-8477-fd14a16fab3f b94369832d4d41cea555a9e98c216dd7 f9f5aa29f7994730b0fc845aaba5ade5 - default default] GET http://192.168.204.2:35357/v3/projects
2017-04-28 14:17:20.915 692 INFO keystone.common.wsgi [req-38122a48-2c97-4b41-b3a0-b2a9062c68ac - - - - -] POST http://10.10.10.2:5000/v3/auth/tokens
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi [req-2208fddc-6801-4a9c-a6fd-22cfd310427d - - - - -] QueuePool limit of size 1 overflow 10 reached, connection timed out, timeout 30
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi Traceback (most recent call last):
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/common/wsgi.py", line 225, in __call__
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi result = method(req, **params)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 397, in authenticate_for_token
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi auth_info = AuthInfo.create(auth=auth)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 137, in create
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi auth_info._validate_and_normalize_auth_data(scope_only)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 310, in _validate_and_normalize_auth_data
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi self._validate_and_normalize_scope_data()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 252, in _validate_and_normalize_scope_data
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi project_ref = self._lookup_project(self.auth['scope']['project'])
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 215, in _lookup_project
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi domain_ref = self._lookup_domain(project_info['domain'])
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/auth/controllers.py", line 189, in _lookup_domain
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi domain_ref = self.resource_api.get_domain(domain_id)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/common/manager.py", line 124, in wrapped
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi __ret_val = __f(*args, **kwargs)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 1220, in decorate
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi should_cache_fn)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 825, in get_or_create
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi async_creator) as value:
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/lock.py", line 154, in __enter__
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._enter()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/lock.py", line 94, in _enter
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi generated = self._enter_create(createdtime)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/lock.py", line 145, in _enter_create
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi created = self.creator()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 792, in gen_value
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi created_value = creator()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/dogpile/cache/region.py", line 1216, in creator
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return fn(*arg, **kw)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/resource/core.py", line 705, in get_domain
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi project = self.driver.get_project(domain_id)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/resource/backends/sql.py", line 49, in get_project
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._get_project(session, project_id).to_dict()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib/python2.7/site-packages/keystone/resource/backends/sql.py", line 42, in _get_project
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi project_ref = session.query(Project).get(project_id)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 831, in get
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._get_impl(ident, loading.load_on_ident)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 864, in _get_impl
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return fallback_fn(self, key)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/loading.py", line 219, in load_on_ident
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return q.one()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2693, in one
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi ret = list(self)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2736, in __iter__
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return self._execute_and_instances(context)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2749, in _execute_and_instances
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi close_with_result=True)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2740, in _connection_from_session
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi **kw)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 905, in connection
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi execution_options=execution_options)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 910, in _connection_for_bind
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi engine, execution_options)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 334, in _connection_for_bind
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi conn = bind.contextual_connect()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2039, in contextual_connect
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi self._wrap_pool_connect(self.pool.connect, None),
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2074, in _wrap_pool_connect
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return fn()
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 376, in connect
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi return _ConnectionFairy._checkout(self)
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 713, in _checkout
2017-04-28 14:17:21.001 653 ERROR keystone.common.wsgi fairy = _ConnectionRecord.checkout(pool)
2017-04-28 14:17:
2017-04-28 14:17:21.176 691 INFO keystone.common.wsgi [req-09fdd07f-4b7c-4a4c-8115-4e4164eea3e5 fbe1c86982b042f8bc942ad45a2bbcbe 5db2b66a3ea34a1ea9899ad9cfe8b2dd - default default] GET http://192.168.204.2:35357/v3/auth/tokens
To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1687073/+subscriptions
Follow ups