# Pastebin Lafw7kEC Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-dcd42894-e140-4af4-8f9b-b1a147b5e08c None nova] Authenticating user token {{(pid=11430) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac 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=11430) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac None vishakha] REQUEST_METHOD: `POST` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac None vishakha] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac None vishakha] PATH_INFO: `/v3/auth/tokens` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.auth.core [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac None vishakha] MFA Rules not processed for user `6a8d16c9be9a455aaee4634cc7eb8b51`. Rule list: `[]` (Enabled: `True`). {{(pid=11430) check_auth_methods_against_rules /opt/stack/keystone/keystone/auth/core.py:446}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 7/14] 127.0.0.1 () {64 vars in 1265 bytes} [Thu Nov 8 14:34:45 2018] POST /identity/v3/auth/tokens => generated 572 bytes in 334 msecs (HTTP/1.1 201) 6 headers in 384 bytes (1 switches on core 0) Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-b6ea3b4c-1096-48a6-9065-232618fc0f87 None nova] Authenticating user token {{(pid=11429) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 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=11429) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 None vishakha] REQUEST_METHOD: `GET` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 None vishakha] SCRIPT_NAME: `/identity` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 None vishakha] PATH_INFO: `/v3/users/6a8d16c9be9a455aaee4634cc7eb8b51/projects` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 None vishakha] RBAC: Authorizing `identity:list_user_projects(user_id=6a8d16c9be9a455aaee4634cc7eb8b51)` {{(pid=11429) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:410}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 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=XAlsxSU4QvqcpxBKP2msEw, audit_chain_id=[u'XAlsxSU4QvqcpxBKP2msEw', u'ynKnaffhRryf4Q_aFqMqxw']) at 0x7f7bcc152bd0>, project_id=None)` {{(pid=11429) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:418}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 None vishakha] RBAC: Policy Enforcement Target Data `identity:list_user_projects => target(user_id=6a8d16c9be9a455aaee4634cc7eb8b51)` {{(pid=11429) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:426}} Nov 08 14:34:45 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.rbac_enforcer.enforcer [None req-a66a64fa-152c-4ea3-86d4-a8e26bae2775 None vishakha] RBAC: Authorization granted {{(pid=11429) enforce_call /opt/stack/keystone/keystone/common/rbac_enforcer/enforcer.py:432}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: [pid: 11429|app: 0|req: 8/15] 127.0.0.1 () {60 vars in 1288 bytes} [Thu Nov 8 14:34:45 2018] GET /identity/v3/users/6a8d16c9be9a455aaee4634cc7eb8b51/projects => generated 461 bytes in 720 msecs (HTTP/1.1 200) 5 headers in 177 bytes (1 switches on core 0) Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-a5e7a96d-2040-4e4b-b69b-b15c9c258bac None vishakha] Authenticating user token {{(pid=11430) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-77937d05-7eb5-460f-bef7-3ce3d3d0a6c6 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=11430) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-77937d05-7eb5-460f-bef7-3ce3d3d0a6c6 None vishakha] REQUEST_METHOD: `POST` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-77937d05-7eb5-460f-bef7-3ce3d3d0a6c6 None vishakha] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-77937d05-7eb5-460f-bef7-3ce3d3d0a6c6 None vishakha] PATH_INFO: `/v3/auth/tokens` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.auth.core [None req-77937d05-7eb5-460f-bef7-3ce3d3d0a6c6 None vishakha] MFA Rules not processed for user `6a8d16c9be9a455aaee4634cc7eb8b51`. Rule list: `[]` (Enabled: `True`). {{(pid=11430) check_auth_methods_against_rules /opt/stack/keystone/keystone/auth/core.py:446}} Nov 08 14:34:46 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-77937d05-7eb5-460f-bef7-3ce3d3d0a6c6 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:47 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 8/16] 127.0.0.1 () {64 vars in 1286 bytes} [Thu Nov 8 14:34:46 2018] POST /identity/v3/auth/tokens => generated 3750 bytes in 589 msecs (HTTP/1.1 201) 6 headers in 406 bytes (1 switches on core 0) Nov 08 14:34:47 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-106fa22e-f903-43e6-a63a-cd540ed9aea8 None None] REQUEST_METHOD: `POST` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:47 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-106fa22e-f903-43e6-a63a-cd540ed9aea8 None None] SCRIPT_NAME: `/identity` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:47 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-106fa22e-f903-43e6-a63a-cd540ed9aea8 None None] PATH_INFO: `/v3/auth/OS-FEDERATION/saml2/ecp` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:47 ubuntu devstack@keystone.service[11426]: [pid: 11429|app: 0|req: 9/17] 127.0.0.1 () {62 vars in 1133 bytes} [Thu Nov 8 14:34:47 2018] POST /identity/v3/auth/OS-FEDERATION/saml2/ecp => generated 6987 bytes in 329 msecs (HTTP/1.1 200) 7 headers in 343 bytes (1 switches on core 0) Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-ece90c58-fc8a-45ae-a75d-f2eab8e9acb6 None None] REQUEST_METHOD: `GET` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-ece90c58-fc8a-45ae-a75d-f2eab8e9acb6 None None] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-ece90c58-fc8a-45ae-a75d-f2eab8e9acb6 None None] PATH_INFO: `/` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 9/18] 127.0.0.1 () {58 vars in 987 bytes} [Thu Nov 8 14:34:51 2018] GET /identity => generated 268 bytes in 12 msecs (HTTP/1.1 300) 5 headers in 191 bytes (1 switches on core 0) Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-106fa22e-f903-43e6-a63a-cd540ed9aea8 None None] Authenticating user token {{(pid=11429) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-106fa22e-f903-43e6-a63a-cd540ed9aea8 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=11429) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-106fa22e-f903-43e6-a63a-cd540ed9aea8 None None] Invalid user token Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-7a83018d-fb3d-4058-ba21-f636045b2c53 None None] REQUEST_METHOD: `POST` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-7a83018d-fb3d-4058-ba21-f636045b2c53 None None] SCRIPT_NAME: `/identity` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-7a83018d-fb3d-4058-ba21-f636045b2c53 None None] PATH_INFO: `/v3/auth/tokens` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-7a83018d-fb3d-4058-ba21-f636045b2c53 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=11429) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: WARNING keystone.server.flask.application [None req-7a83018d-fb3d-4058-ba21-f636045b2c53 None None] Could not recognize Fernet token: TokenNotFound: Could not recognize Fernet token Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: [pid: 11429|app: 0|req: 10/19] 127.0.0.1 () {64 vars in 1332 bytes} [Thu Nov 8 14:34:51 2018] POST /identity/v3/auth/tokens => generated 88 bytes in 81 msecs (HTTP/1.1 404) 5 headers in 183 bytes (1 switches on core 0) Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-ece90c58-fc8a-45ae-a75d-f2eab8e9acb6 None None] Authenticating user token {{(pid=11430) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-ece90c58-fc8a-45ae-a75d-f2eab8e9acb6 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 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=11430) fill_context /opt/stack/keystone/keystone/server/flask/request_processing/middleware/auth_context.py:445}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 None neutron] REQUEST_METHOD: `GET` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 None neutron] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 None neutron] PATH_INFO: `/v3/auth/tokens` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: WARNING keystone.server.flask.application [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 None neutron] Could not recognize Fernet token: TokenNotFound: Could not recognize Fernet token Nov 08 14:34:51 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 10/20] 127.0.0.1 () {62 vars in 1430 bytes} [Thu Nov 8 14:34:51 2018] GET /identity/v3/auth/tokens => generated 88 bytes in 741 msecs (HTTP/1.1 404) 5 headers in 183 bytes (1 switches on core 0) Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-e9f6aa41-6c79-4d4e-b646-ff0fca2571ad None None] REQUEST_METHOD: `POST` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-e9f6aa41-6c79-4d4e-b646-ff0fca2571ad None None] SCRIPT_NAME: `/identity` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-e9f6aa41-6c79-4d4e-b646-ff0fca2571ad None None] PATH_INFO: `/tokens` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: [pid: 11429|app: 0|req: 11/21] 127.0.0.1 () {62 vars in 1004 bytes} [Thu Nov 8 14:34:52 2018] POST /identity/tokens => generated 233 bytes in 53 msecs (HTTP/1.1 404) 5 headers in 177 bytes (1 switches on core 0) Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 None neutron] Authenticating user token {{(pid=11430) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-55775ca3-a6b2-4d8e-b563-e3ad83ed64d6 None neutron] Invalid user token Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-79cae181-f23a-433f-acb3-44404ec2d70c None None] REQUEST_METHOD: `GET` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-79cae181-f23a-433f-acb3-44404ec2d70c None None] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-79cae181-f23a-433f-acb3-44404ec2d70c None None] PATH_INFO: `/v3/auth/projects` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: WARNING keystone.server.flask.application [None req-79cae181-f23a-433f-acb3-44404ec2d70c 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 08 14:34:52 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 11/22] 127.0.0.1 () {60 vars in 1207 bytes} [Thu Nov 8 14:34:52 2018] GET /identity/v3/auth/projects => generated 159 bytes in 54 msecs (HTTP/1.1 401) 6 headers in 250 bytes (2 switches on core 0) Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-4f2e0b31-d145-48ea-a8d1-42c7bafb0034 None None] REQUEST_METHOD: `POST` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-4f2e0b31-d145-48ea-a8d1-42c7bafb0034 None None] SCRIPT_NAME: `/identity` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-4f2e0b31-d145-48ea-a8d1-42c7bafb0034 None None] PATH_INFO: `/tokens` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: [pid: 11429|app: 0|req: 12/23] 127.0.0.1 () {62 vars in 1004 bytes} [Thu Nov 8 14:34:52 2018] POST /identity/tokens => generated 233 bytes in 45 msecs (HTTP/1.1 404) 5 headers in 177 bytes (1 switches on core 0) Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-79cae181-f23a-433f-acb3-44404ec2d70c None None] Authenticating user token {{(pid=11430) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-79cae181-f23a-433f-acb3-44404ec2d70c 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: INFO keystone.server.flask.request_processing.middleware.auth_context [None req-79cae181-f23a-433f-acb3-44404ec2d70c None None] Invalid user token Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-e3c52152-f5f3-47a7-a9b8-f5f70764c05f None None] REQUEST_METHOD: `POST` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-e3c52152-f5f3-47a7-a9b8-f5f70764c05f None None] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-e3c52152-f5f3-47a7-a9b8-f5f70764c05f None None] PATH_INFO: `/v3/auth/tokens` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.common.fernet_utils [None req-e3c52152-f5f3-47a7-a9b8-f5f70764c05f 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=11430) load_keys /opt/stack/keystone/keystone/common/fernet_utils.py:307}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: WARNING keystone.server.flask.application [None req-e3c52152-f5f3-47a7-a9b8-f5f70764c05f None None] Could not recognize Fernet token: TokenNotFound: Could not recognize Fernet token Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 12/24] 127.0.0.1 () {64 vars in 1332 bytes} [Thu Nov 8 14:34:52 2018] POST /identity/v3/auth/tokens => generated 88 bytes in 56 msecs (HTTP/1.1 404) 5 headers in 183 bytes (1 switches on core 0) Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-47967fcb-a059-4673-b108-50f2c59b98d6 None None] REQUEST_METHOD: `POST` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-47967fcb-a059-4673-b108-50f2c59b98d6 None None] SCRIPT_NAME: `/identity` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-47967fcb-a059-4673-b108-50f2c59b98d6 None None] PATH_INFO: `/tokens` {{(pid=11429) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: [pid: 11429|app: 0|req: 13/25] 127.0.0.1 () {62 vars in 1004 bytes} [Thu Nov 8 14:34:52 2018] POST /identity/tokens => generated 233 bytes in 40 msecs (HTTP/1.1 404) 5 headers in 177 bytes (1 switches on core 0) Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-537e364c-f8fa-4368-9c8e-dc4e7db1e640 None None] REQUEST_METHOD: `GET` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:27}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-537e364c-f8fa-4368-9c8e-dc4e7db1e640 None None] SCRIPT_NAME: `/identity` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:28}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: DEBUG keystone.server.flask.request_processing.req_logging [None req-537e364c-f8fa-4368-9c8e-dc4e7db1e640 None None] PATH_INFO: `/v3` {{(pid=11430) log_request_info /opt/stack/keystone/keystone/server/flask/request_processing/req_logging.py:29}} Nov 08 14:34:52 ubuntu devstack@keystone.service[11426]: [pid: 11430|app: 0|req: 13/26] 127.0.0.1 () {60 vars in 1104 bytes} [Thu Nov 8 14:34:52 2018] GET /identity/v3 => generated 253 bytes in 18 msecs (HTTP/1.1 200) 5 headers in 177 bytes (1 switches on core 0)