heat authentication failure in devstack

asked 2014-10-10 20:33:00 -0500

9lives gravatar image

updated 2014-10-14 02:37:55 -0500

Dear stackers,

We are using devstack master branch to take heat research, however, when we are trying to create stack authentication error like this occurred

UPDATED with keystone log

2014-10-13 22:25:43.072242 5433 DEBUG keystone.middleware.core [-] Auth token not in the request header. Will not build auth context. process_request /opt/stack/keystone/keystone/middleware/core.py:270
enforce identity:revocation_list: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'67f28fb027dc4d279850be49e7f6bb4a', 'roles': [u'admin', u'_member_', u'ResellerAdmin'], 'trustee_id': None, 'trustor_id': None, 'consumer_id': None, 'token': <KeystoneToken (audit_id=Vj2WkQmsSj-Din2-drD8CA, audit_chain_id=Vj2WkQmsSj-Din2-drD8CA) at 0x7fb4ac15e3c8>, 'project_id': u'cc21b411a45e4e4b93887b9617528997', 'trust_id': None} enforce /opt/stack/keystone/keystone/policy/backends/rules.py:100
2014-10-13 22:25:43.445255 5439 DEBUG keystone.common.controller [-] RBAC: Authorization granted inner /opt/stack/keystone/keystone/common/controller.py:155
2014-10-13 22:25:43.551526 5442 DEBUG keystone.middleware.core [-] Auth token not in the request header. Will not build auth context. process_request /opt/stack/keystone/keystone/middleware/core.py:270
core [-] RBAC: auth_context: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'1418cd627d5246e791d35fb7f67c7260', 'roles': [u'admin', u'_member_'], 'trustee_id': None, 'trustor_id': None, 'consumer_id': None, 'token': <KeystoneToken (audit_id=6HCsdK94QCusRiEcK0N-vQ, audit_chain_id=6HCsdK94QCusRiEcK0N-vQ) at 0x7fb4ac170740>, 'project_id': u'cc21b411a45e4e4b93887b9617528997', 'trust_id': None} process_request /opt/stack/keystone/keystone/middleware/core.py:280
:25:43.686512 5441 DEBUG keystone.middleware.core [-] RBAC: auth_context: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'3e76ea44b3ee42bb903ef22ee9314143', 'roles': [u'_member_', u'service'], 'trustee_id': None, 'trustor_id': Noneild_policy_check_credentials /opt/stack/keystone/keystone/common/controller.py:55
udit_chain_id=bgj2Uy__Q-KqqZxRArkpBg) at 0x7fb4ac0febe0>, 'project_id': u'cc21b411a45e4e4b93887b9617528997', 'trust_id': None} process_request /opt/stack/keystone/keystone/mi/keystone/common/controller.py:60
:25:43.687957 5441 DEBUG keystone.common.wsgi [-] arg_dict: {} __call__ /opt/stack/keystone/keystone/common/wsgi.py:191
2014-10-13 22:25:43.688404 5441 DEBUG keystone.common.controller [-] RBAC: Authorizing identity:revocation_list() _build_policy_check_credentials /opt/stack/keystone/keystone/common/controller.py:55
2014-10-13 22:25:43.688564 5441 DEBUG keystone.common.controller [-] RBAC: using auth context from the request environment _build_policy_check_credentials /opt/stack/keystone/keystone/common/controller.py:60
2014-10-13 22:25:43.688864 5441 DEBUG keystone.policy.backends.rules [-] enforce identity:revocation_list: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'3e76ea44b3ee42bb903ef22ee9314143', 'roles': [u'_member_', u'service'], 'trustee_id': None, 'trustor_id': None, 'consumer_id': None, 'token': <KeystoneToken (audit_id=bgj2Uy__Q-KqqZxRArkpBg, audit_chain_id=bgj2Uy__Q-KqqZxRArkpBg) at 0x7fb4ac0febe0>, 'project_id': u'cc21b411a45e4e4b93887b9617528997', 'trust_id': None} enforce /opt/stack/keystone/keystone/policy/backends/rules.py:100
2014-10-13 22:25:43.689347 5441 DEBUG keystone.common.controller [-] RBAC: Authorization granted inner /opt/stack/keystone/keystone/common/controller.py:155
2014-10-13 22:25:43.768196 5440 DEBUG keystone.common.kvs.core [-] KVS lock acquired for: os-revoke-events acquire /opt/stack/keystone/keystone/common/kvs/core.py:380
2014-10-13 22:25:43.768656 5440 DEBUG keystone.common.kvs.core [-] KVS lock released for: os-revoke-events release /opt/stack/keystone/keystone/common/kvs/core.py:399
2014-10-13 22:25:43.769186 5440 DEBUG keystone.middleware.core [-] RBAC: auth_context: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'3e76ea44b3ee42bb903ef22ee9314510 5439 DEBUG keystone.common.controller [-] RBAC: Authorizing identity:revocation_list() _build_policy_check_credentials /opt/stack/keystone/keystone/common/controller.py:55
KrAY8bDAREmgaOSO6jbrow) at 0x7fb4ac0d2d08>, 'project_id': u'cc21b411a45e4e4b93887b9617528997', 'trust_id': None} process_request /opt ...
(more)
edit retag flag offensive close merge delete

Comments

I assume that you show heat-api log above ^^. Do you see anything in heat-engine log? It is my understanding that the AuthorizationFailure happened on heat-engine side and probably there are more details in the log.

dmitrymex gravatar imagedmitrymex ( 2014-10-11 03:08:14 -0500 )edit

Hi dmitrymex, thanks for the comments, i have updated the question with the h-engine log , please help to take a look, it seemed the heat uses the keystone v3 to create the token and it failed.

9lives gravatar image9lives ( 2014-10-13 02:34:14 -0500 )edit

The (500 Internal server) error seems to be in Keystone, I would suggest you check the Keystone service logs to determine the root cause. You can check out keystone commands (eg. keystone user-list) with the same user you used to create the stack.

unmesh-gurjar gravatar imageunmesh-gurjar ( 2014-10-14 01:08:52 -0500 )edit

Hi unmesh-gurjar, thanks for the comments.i have updated the question with keystone log and result of keystone user-list,looks like there is no obvious clue for this 500 error :-(

9lives gravatar image9lives ( 2014-10-14 02:42:23 -0500 )edit

heat-engine.log 22:19:46.291 shows that keystone raised a 500 error in heat create_trust_context.

However the pasted keystone log only goes back to 22:25:43 so we can't see possible causes for the error.

Steve Baker gravatar imageSteve Baker ( 2014-10-16 18:33:09 -0500 )edit