Create stack fails on a multi core VM

[Waseem Malik]

On a multi core VM the stack create call fails with following exception

2015-06-10 09:39:31.261 2880 DEBUG keystoneclient.session [req-b4e32ed5-92e6-4397-94f0-061bef916f6e - admin] RESP: [201] content-length: 722 vary: X-Auth-Token connection: keep-alive date: Wed, 10 Jun 2015 16:39:31 GMT content-type: application/json x-openstack-request-id: req-b93a3fc7-e677-43bd-8292-23f002d29021
RESP BODY: {"trust": {"impersonation": true, "roles_links": {"self": "http://localhost:35357/v3/OS-TRUST/trusts/8b4ec0965d8843b891066be569a77a08/roles", "previous": null, "next": null}, "deleted_at": null, "trustor_user_id": "e631e6ad22804335985f7b649b153646", "links": {"self": "http://localhost:35357/v3/OS-TRUST/trusts/8b4ec0965d8843b891066be569a77a08"}, "roles": [{"id": "be0e7cedf14944a6b0fe957f99a06506", "links": {"self": "http://localhost:35357/v3/roles/be0e7cedf14944a6b0fe957f99a06506"}, "name": "admin"}], "redelegation_count": 0, "remaining_uses": null, "expires_at": null, "trustee_user_id": "ae21a19e0fbb460eb68592cf6c6f5d34", "project_id": "50a0a9df745141cdb78b8adb340d8875", "id": "8b4ec0965d8843b891066be569a77a08"}}
 _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:224
2015-06-10 09:39:31.262 2880 ERROR oslo_messaging.rpc.dispatcher [req-b4e32ed5-92e6-4397-94f0-061bef916f6e - admin] Exception during message handling: PID check failed. RNG must be re-initialized after fork(). Hint: Try Random.atfork()
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher executor_callback))
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher executor_callback)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/common/context.py", line 300, in wrapped
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return func(self, ctx, *args, **kwargs)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/engine/service.py", line 671, in create_stack
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher stack.store()
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/engine/stack.py", line 458, in store
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher new_creds = ucreds_object.UserCreds.create(trust_ctx)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/objects/user_creds.py", line 62, in create
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher user_creds_db = db_api.user_creds_create(context)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/db/api.py", line 180, in user_creds_create
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return IMPL.user_creds_create(context)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/db/sqlalchemy/api.py", line 507, in user_creds_create
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher method, trust_id = _encrypt(values.get('trust_id'))
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/db/sqlalchemy/api.py", line 205, in _encrypt
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return crypt.encrypt(value.encode('utf-8'))
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/common/crypt.py", line 38, in encrypt
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher auth_info, b64encode=True)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/heat/openstack/common/crypto/utils.py", line 145, in encrypt
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher iv = Random.new().read(self.cipher.block_size)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/Crypto/Random/_UserFriendlyRNG.py", line 202, in read
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return self._singleton.read(bytes)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/Crypto/Random/_UserFriendlyRNG.py", line 178, in read
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher return _UserFriendlyRNG.read(self, bytes)
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/Crypto/Random/_UserFriendlyRNG.py", line 137, in read
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher self._check_pid()
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/site-packages/Crypto/Random/_UserFriendlyRNG.py", line 153, in _check_pid
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher raise AssertionError("PID check failed. RNG must be re-initialized after fork(). Hint: Try Random.atfork()")
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher AssertionError: PID check failed. RNG must be re-initialized after fork(). Hint: Try Random.atfork()
2015-06-10 09:39:31.262 2880 TRACE oslo_messaging.rpc.dispatcher
2015-06-10 09:39:31.281 2880 DEBUG oslo_messaging._drivers.amqp [req-b4e32ed5-92e6-4397-94f0-061bef916f6e - admin] Pool creating new connection create /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqp.py:92

Details about the environment

Number of Virtual Sockets: 1
Number of cores per socket: 4
OS: Redhat Enterprise 7.1
Openstack Kilo
Pycrypto 2.6.1

[Steve Baker (steve-stevebaker)]

Our encrypt function comes from the oslo-incubator project. Can you see if you can reproduce the error either by running the oslo-incubator unit tests, or adding a unit test to http://git.openstack.org/cgit/openstack/oslo-incubator/tree/tests/unit/crypto/test_utils.py

[Waseem Malik (malikwaseem)]

I forgot to mention one thing here. When i edit settings of the same VM and make it single core processor then the stack provisioning works without any issues.

[Steve Baker (steve-stevebaker)]

Actually, heat-engine's forking is done by another piece of oslo-incubator, service.ProcessLauncher. The correct fix may be for Random.atfork() to be called after os.fork() in ProcessLauncher._start_child.

As a workaround you could try setting heat.conf num_engine_workers=0 then restarting heat-engine.

[Steve Baker (steve-stevebaker)]

I mean heat.conf num_engine_workers=1

[Waseem Malik (malikwaseem)]

Yes the workaround of setting num_engine_workers=1 is working.

[Davanum Srinivas (DIMS) (dims-v)]

https://review.openstack.org/#/c/191581/

[Davanum Srinivas (DIMS) (dims-v)]

All code in oslo-incubator will be deleted soon. Please fix this up in heat itself.

http://markmail.org/message/kgdnukenoni3hbmw

thanks,
dims

[Neetu Jain (nutshi)]

does that meant that in Heat repo the default needs to be changed ?
 https://github.com/openstack/heat/search?utf8=%E2%9C%93&q=num_engine_workers
or to be configured explicitly ?

[Steven Hardy (shardy)]

No, the default shouldn't be changed, ref https://bugs.launchpad.net/heat/+bug/1526045 other problems occur when using num_engine_workers=1 and relatively large stacks.

So we have to fix the code, either in the heat tree or by moving to a non-incubator oslo library.

[Davanum Srinivas (DIMS) (dims-v)]

Steven, Folks,

openstack/common/crypto/utils.py does not exist in oslo-incubator anymore, so please feel free to edit the copy in heat do what's needed.

Thanks,
Dims

[Zane Bitter (zaneb)]

This was likely fixed in Liberty by https://review.openstack.org/#/c/195018/