# Pastebin uRPczdF6 Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-b1c2305e-2be2-4aed-b7d7-8b3824a6ade6 None None] Authenticating user token {{(pid=28583) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] RBAC: auth_context: {'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'trustor_id': None, 'user_domain_id': u'default', 'domain_id': None, 'trust_id': None, 'project_domain_id': None, 'service_roles': [], 'group_ids': [], 'user_id': u'6a8d16c9be9a455aaee4634cc7eb8b51', 'roles': [], 'system_scope': None, 'trustee_id': None, 'domain_name': None, 'is_admin_project': True, 'token': , 'project_id': None} {{(pid=28583) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] REQUEST_METHOD: `POST` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] PATH_INFO: `/v3/auth/tokens` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.auth.core [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] MFA Rules not processed for user `6a8d16c9be9a455aaee4634cc7eb8b51`. Rule list: `[]` (Enabled: `True`). {{(pid=28583) check_auth_methods_against_rules /opt/stack/keystone/keystone/auth/core.py:446}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28583) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 857/1714] 127.0.0.1 () {64 vars in 1250 bytes} [Tue Nov 13 07:11:34 2018] POST /identity/v3/auth/tokens => generated 572 bytes in 181 msecs (HTTP/1.1 201) 6 headers in 384 bytes (1 switches on core 0) Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-dcbc15fd-6e0c-43a9-9029-91ce0c076499 None vishakha] Authenticating user token {{(pid=28582) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] RBAC: auth_context: {'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'trustor_id': None, 'user_domain_id': u'default', 'domain_id': None, 'trust_id': None, 'project_domain_id': None, 'service_roles': [], 'group_ids': [], 'user_id': u'6a8d16c9be9a455aaee4634cc7eb8b51', 'roles': [], 'system_scope': None, 'trustee_id': None, 'domain_name': None, 'is_admin_project': True, 'token': , 'project_id': None} {{(pid=28582) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] REQUEST_METHOD: `GET` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] SCRIPT_NAME: `/identity` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] PATH_INFO: `/v3/users/6a8d16c9be9a455aaee4634cc7eb8b51/projects` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] RBAC: Authorizing `identity:list_user_projects(user_id=6a8d16c9be9a455aaee4634cc7eb8b51)` {{(pid=28582) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:410}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] RBAC: Policy Enforcement Cred Data `identity:list_user_projects creds(service_project_id=None, service_user_id=None, service_user_domain_id=None, service_project_domain_id=None, trustor_id=None, user_domain_id=default, domain_id=None, trust_id=None, project_domain_id=None, service_roles=[], group_ids=[], user_id=6a8d16c9be9a455aaee4634cc7eb8b51, roles=[], system_scope=None, trustee_id=None, domain_name=None, is_admin_project=True, token=*** (audit_id=VjlRgfltTP6-KUw5P4Tc5Q, audit_chain_id=[u'VjlRgfltTP6-KUw5P4Tc5Q', u'qZPt9wcNTIyHC66kuPfOGA']) at 0x7f392e36f050>, project_id=None)` {{(pid=28582) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:418}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] RBAC: Policy Enforcement Target Data `identity:list_user_projects => target(user_id=6a8d16c9be9a455aaee4634cc7eb8b51)` {{(pid=28582) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:426}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-1cd119e9-7068-48cf-8b30-dedeca250140 None vishakha] RBAC: Authorization granted {{(pid=28582) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:432}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: [pid: 28582|app: 0|req: 858/1715] 127.0.0.1 () {60 vars in 1288 bytes} [Tue Nov 13 07:11:34 2018] GET /identity/v3/users/6a8d16c9be9a455aaee4634cc7eb8b51/projects => generated 461 bytes in 117 msecs (HTTP/1.1 200) 5 headers in 177 bytes (1 switches on core 0) Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-119a4d92-3998-4b22-8732-95e12ff7e592 None vishakha] Authenticating user token {{(pid=28583) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-eb1a3cbd-e4e8-47e5-a28b-e60bb986f6e3 None vishakha] RBAC: auth_context: {'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'trustor_id': None, 'user_domain_id': u'default', 'domain_id': None, 'trust_id': None, 'project_domain_id': None, 'service_roles': [], 'group_ids': [], 'user_id': u'6a8d16c9be9a455aaee4634cc7eb8b51', 'roles': [], 'system_scope': None, 'trustee_id': None, 'domain_name': None, 'is_admin_project': True, 'token': , 'project_id': None} {{(pid=28583) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-eb1a3cbd-e4e8-47e5-a28b-e60bb986f6e3 None vishakha] REQUEST_METHOD: `POST` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-eb1a3cbd-e4e8-47e5-a28b-e60bb986f6e3 None vishakha] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-eb1a3cbd-e4e8-47e5-a28b-e60bb986f6e3 None vishakha] PATH_INFO: `/v3/auth/tokens` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.auth.core [None req-eb1a3cbd-e4e8-47e5-a28b-e60bb986f6e3 None vishakha] MFA Rules not processed for user `6a8d16c9be9a455aaee4634cc7eb8b51`. Rule list: `[]` (Enabled: `True`). {{(pid=28583) check_auth_methods_against_rules /opt/stack/keystone/keystone/auth/core.py:446}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-eb1a3cbd-e4e8-47e5-a28b-e60bb986f6e3 None vishakha] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28583) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 858/1716] 127.0.0.1 () {64 vars in 1271 bytes} [Tue Nov 13 07:11:34 2018] POST /identity/v3/auth/tokens => generated 3750 bytes in 183 msecs (HTTP/1.1 201) 6 headers in 406 bytes (1 switches on core 0) Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-ef8e43c1-2e34-4ad0-9a9a-285b827c67fe None None] REQUEST_METHOD: `POST` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-ef8e43c1-2e34-4ad0-9a9a-285b827c67fe None None] SCRIPT_NAME: `/identity` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-ef8e43c1-2e34-4ad0-9a9a-285b827c67fe None None] PATH_INFO: `/v3/auth/OS-FEDERATION/saml2/ecp` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:34 ubuntu devstack@keystone.service[28577]: [pid: 28582|app: 0|req: 859/1717] 127.0.0.1 () {62 vars in 1118 bytes} [Tue Nov 13 07:11:34 2018] POST /identity/v3/auth/OS-FEDERATION/saml2/ecp => generated 6987 bytes in 268 msecs (HTTP/1.1 200) 7 headers in 343 bytes (1 switches on core 0) Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-29c66678-2f9f-402f-a6ca-6371a6730e34 None None] REQUEST_METHOD: `GET` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-29c66678-2f9f-402f-a6ca-6371a6730e34 None None] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-29c66678-2f9f-402f-a6ca-6371a6730e34 None None] PATH_INFO: `/` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 859/1718] 127.0.0.1 () {58 vars in 987 bytes} [Tue Nov 13 07:11:39 2018] GET /identity => generated 268 bytes in 13 msecs (HTTP/1.1 300) 5 headers in 191 bytes (1 switches on core 0) Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-ef8e43c1-2e34-4ad0-9a9a-285b827c67fe None None] Authenticating user token {{(pid=28582) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-ef8e43c1-2e34-4ad0-9a9a-285b827c67fe None None] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28582) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-ef8e43c1-2e34-4ad0-9a9a-285b827c67fe None None] Invalid user token Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-8ab9a856-79d6-43f1-b78e-aeb4c11714e0 None None] REQUEST_METHOD: `POST` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-8ab9a856-79d6-43f1-b78e-aeb4c11714e0 None None] SCRIPT_NAME: `/identity` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-8ab9a856-79d6-43f1-b78e-aeb4c11714e0 None None] PATH_INFO: `/v3/auth/tokens` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: WARNING keystone.auth.core [None req-8ab9a856-79d6-43f1-b78e-aeb4c11714e0 None None] Could not find project: 8d5c2f4c615941cc8f7a8969b3618445.: ProjectNotFound: Could not find project: 8d5c2f4c615941cc8f7a8969b3618445. Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: WARNING keystone.server.flask.application [None req-8ab9a856-79d6-43f1-b78e-aeb4c11714e0 None None] Authorization failed. Could not find project: 8d5c2f4c615941cc8f7a8969b3618445. (Disable insecure_debug mode to suppress these details.) from 127.0.0.1: Unauthorized: Could not find project: 8d5c2f4c615941cc8f7a8969b3618445. (Disable insecure_debug mode to suppress these details.) Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: [pid: 28582|app: 0|req: 860/1719] 127.0.0.1 () {64 vars in 1332 bytes} [Tue Nov 13 07:11:39 2018] POST /identity/v3/auth/tokens => generated 173 bytes in 112 msecs (HTTP/1.1 401) 6 headers in 250 bytes (1 switches on core 0) Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-29c66678-2f9f-402f-a6ca-6371a6730e34 None None] Authenticating user token {{(pid=28583) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-29c66678-2f9f-402f-a6ca-6371a6730e34 None None] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28583) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-29c66678-2f9f-402f-a6ca-6371a6730e34 None None] Invalid user token Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-eda0b59d-cb41-4e71-b821-b792c1f297bf None None] REQUEST_METHOD: `GET` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-eda0b59d-cb41-4e71-b821-b792c1f297bf None None] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-eda0b59d-cb41-4e71-b821-b792c1f297bf None None] PATH_INFO: `/v3/auth/projects` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: WARNING keystone.server.flask.application [None req-eda0b59d-cb41-4e71-b821-b792c1f297bf None None] Authorization failed. auth_context did not decode anything useful (Disable insecure_debug mode to suppress these details.) from 127.0.0.1: Unauthorized: auth_context did not decode anything useful (Disable insecure_debug mode to suppress these details.) Nov 13 07:11:39 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 860/1720] 127.0.0.1 () {60 vars in 1207 bytes} [Tue Nov 13 07:11:39 2018] GET /identity/v3/auth/projects => generated 159 bytes in 48 msecs (HTTP/1.1 401) 6 headers in 250 bytes (2 switches on core 0) Nov 13 07:11:40 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-8ab9a856-79d6-43f1-b78e-aeb4c11714e0 None None] Authenticating user token {{(pid=28582) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] RBAC: auth_context: {'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'trustor_id': None, 'user_domain_id': u'default', 'domain_id': None, 'trust_id': None, 'project_domain_id': u'default', 'service_roles': [], 'group_ids': [], 'user_id': '313885f6a6fb45cf9d31cac8fad79a69', 'roles': [u'service'], 'system_scope': None, 'trustee_id': None, 'domain_name': None, 'is_admin_project': True, 'token': , 'project_id': u'8f1fc3d7899f4697a44c1af21fe33f33'} {{(pid=28582) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] REQUEST_METHOD: `GET` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] SCRIPT_NAME: `/identity` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] PATH_INFO: `/v3/auth/tokens` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28582) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: WARNING keystone.server.flask.application [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] Could not recognize Fernet token: TokenNotFound: Could not recognize Fernet token Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: [pid: 28582|app: 0|req: 861/1721] 127.0.0.1 () {62 vars in 1430 bytes} [Tue Nov 13 07:11:40 2018] GET /identity/v3/auth/tokens => generated 88 bytes in 160 msecs (HTTP/1.1 404) 5 headers in 183 bytes (1 switches on core 0) Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a8c4c628-cbf8-409a-99e8-897d31d4911c None None] REQUEST_METHOD: `POST` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a8c4c628-cbf8-409a-99e8-897d31d4911c None None] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a8c4c628-cbf8-409a-99e8-897d31d4911c None None] PATH_INFO: `/tokens` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 861/1722] 127.0.0.1 () {62 vars in 1004 bytes} [Tue Nov 13 07:11:41 2018] POST /identity/tokens => generated 233 bytes in 34 msecs (HTTP/1.1 404) 5 headers in 177 bytes (1 switches on core 0) Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] Authenticating user token {{(pid=28582) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28582) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-0965c34f-3ee0-4be5-820a-07f4890d7197 None neutron] Invalid user token Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a13d24ee-6e44-417e-b7d0-095422788e1d None None] REQUEST_METHOD: `POST` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a13d24ee-6e44-417e-b7d0-095422788e1d None None] SCRIPT_NAME: `/identity` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a13d24ee-6e44-417e-b7d0-095422788e1d None None] PATH_INFO: `/v3/auth/tokens` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: WARNING keystone.auth.core [None req-a13d24ee-6e44-417e-b7d0-095422788e1d None None] Could not find project: 8d5c2f4c615941cc8f7a8969b3618445.: ProjectNotFound: Could not find project: 8d5c2f4c615941cc8f7a8969b3618445. Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: WARNING keystone.server.flask.application [None req-a13d24ee-6e44-417e-b7d0-095422788e1d None None] Authorization failed. Could not find project: 8d5c2f4c615941cc8f7a8969b3618445. (Disable insecure_debug mode to suppress these details.) from 127.0.0.1: Unauthorized: Could not find project: 8d5c2f4c615941cc8f7a8969b3618445. (Disable insecure_debug mode to suppress these details.) Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: [pid: 28582|app: 0|req: 862/1723] 127.0.0.1 () {64 vars in 1332 bytes} [Tue Nov 13 07:11:41 2018] POST /identity/v3/auth/tokens => generated 173 bytes in 98 msecs (HTTP/1.1 401) 6 headers in 250 bytes (1 switches on core 0) Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-88df7d42-d0cc-4b81-92af-ff16069ff3e4 None None] REQUEST_METHOD: `POST` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-88df7d42-d0cc-4b81-92af-ff16069ff3e4 None None] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-88df7d42-d0cc-4b81-92af-ff16069ff3e4 None None] PATH_INFO: `/tokens` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 862/1724] 127.0.0.1 () {62 vars in 1004 bytes} [Tue Nov 13 07:11:41 2018] POST /identity/tokens => generated 233 bytes in 34 msecs (HTTP/1.1 404) 5 headers in 177 bytes (1 switches on core 0) Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-28d2d415-57f7-4630-8121-2ecfb05736be None None] REQUEST_METHOD: `GET` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-28d2d415-57f7-4630-8121-2ecfb05736be None None] SCRIPT_NAME: `/identity` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-28d2d415-57f7-4630-8121-2ecfb05736be None None] PATH_INFO: `/v3` {{(pid=28582) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:41 ubuntu devstack@keystone.service[28577]: [pid: 28582|app: 0|req: 863/1725] 127.0.0.1 () {60 vars in 1064 bytes} [Tue Nov 13 07:11:41 2018] GET /identity/v3 => generated 253 bytes in 16 msecs (HTTP/1.1 200) 5 headers in 177 bytes (1 switches on core 0) Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-88df7d42-d0cc-4b81-92af-ff16069ff3e4 None None] Authenticating user token {{(pid=28583) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: DEBUG keystone.common.fernet_utils [None req-88df7d42-d0cc-4b81-92af-ff16069ff3e4 None None] Loaded 2 Fernet keys from /etc/keystone/fernet-keys/, but `[fernet_tokens] max_active_keys = 3`; perhaps there have not been enough key rotations to reach `max_active_keys` yet? {{(pid=28583) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-88df7d42-d0cc-4b81-92af-ff16069ff3e4 None None] Invalid user token Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-8f5c800c-bedd-401a-b34d-d1b17bb080b1 None None] REQUEST_METHOD: `GET` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-8f5c800c-bedd-401a-b34d-d1b17bb080b1 None None] SCRIPT_NAME: `/identity` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: DEBUG keystone.server.flask.request_processing.req_logging [None req-8f5c800c-bedd-401a-b34d-d1b17bb080b1 None None] PATH_INFO: `/v3/auth/projects` {{(pid=28583) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: WARNING keystone.server.flask.application [None req-8f5c800c-bedd-401a-b34d-d1b17bb080b1 None None] Authorization failed. auth_context did not decode anything useful (Disable insecure_debug mode to suppress these details.) from 127.0.0.1: Unauthorized: auth_context did not decode anything useful (Disable insecure_debug mode to suppress these details.) Nov 13 07:11:44 ubuntu devstack@keystone.service[28577]: [pid: 28583|app: 0|req: 863/1726] 127.0.0.1 () {60 vars in 1207 bytes} [Tue Nov 13 07:11:44 2018] GET /identity/v3/auth/projects => generated 159 bytes in 56 msecs (HTTP/1.1 401) 6 headers in 250 bytes (1 switches on core 0)