Unauthorized request: Identity server rejects authorization necessary to fetch token data

[Dinesh Bhor]

Token authorization is failing for masakari. Masakari sends request for token
authorization to keystone but keystone rejects the request and sends 503 to
masakari with below error:

CRITICAL keystonemiddleware.auth_token [-] Unable to validate token:
Identity server rejected authorization necessary to fetch token data: ServiceError:
Identity server rejected authorization necessary to fetch token data

Steps to reproduce:
===================

1. Install devstack stable/queens with all services of stable/queens including
   masakari
  1.1. Add below parameter in your local.conf with value as False:
       ENABLE_HTTPD_MOD_WSGI_SERVICES=False

       The use of this parameter is explained in below doc:
       https://docs.openstack.org/devstack/latest/configuration.html#apache-frontend

2. After the successful devstack installation, try to execute masakari commands
   using masakariclient.

   You will get below error:
   HttpException: Unknown error

   Debug logs of command shows below error:

REQ: curl -g -i -X GET http://192.168.108.132:15868/v1/segments -H "User-Agent: osc-lib/1.9.0 keystoneauth1/3.4.0 python-requests/2.18.4 CPython/2.7.12" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}29d20fd66e900ff9e6235dc2b466056b9a9e318e"
Starting new HTTP connection (1): 192.168.108.132
http://192.168.108.132:15868 "GET /v1/segments HTTP/1.1" 503 218
RESP: [503] Content-Length: 218 Content-Type: application/json X-Openstack-Request-Id: req-14c0eaca-823c-45bd-824c-cc71d05080a7 Date: Tue, 22 May 2018 05:19:43 GMT Connection: keep-alive
RESP BODY: {"message": "The server is currently unavailable. Please try again at a later time.<br /><br />\nThe Keystone service is temporarily unavailable.\n\n", "code": "503 Service Unavailable", "title": "Service Unavailable"}

GET call to ha for http://192.168.108.132:15868/v1/segments used request id req-14c0eaca-823c-45bd-824c-cc71d05080a7
Manager ha ran task ha.GET.segments in 0.166582107544s
HttpException: Unknown error
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/cliff/app.py", line 400, in run_subcommand
    result = cmd.run(parsed_args)
  File "/usr/local/lib/python2.7/dist-packages/osc_lib/command/command.py", line 41, in run
    return super(Command, self).run(parsed_args)
  File "/usr/local/lib/python2.7/dist-packages/cliff/display.py", line 119, in run
    self.produce_output(parsed_args, column_names, data)
  File "/usr/local/lib/python2.7/dist-packages/cliff/lister.py", line 82, in produce_output
    parsed_args,
  File "/usr/local/lib/python2.7/dist-packages/cliff/formatters/table.py", line 101, in emit_list
    self.add_rows(x, column_names, data)
  File "/usr/local/lib/python2.7/dist-packages/cliff/formatters/table.py", line 80, in add_rows
    first_row = next(data_iter)
  File "/usr/local/lib/python2.7/dist-packages/masakariclient/osc/v1/segment.py", line 75, in <genexpr>
    (utils.get_item_properties(p, columns, formatters=formatters)
  File "/usr/local/lib/python2.7/dist-packages/openstack/resource.py", line 898, in list
    exceptions.raise_from_response(response)
  File "/usr/local/lib/python2.7/dist-packages/openstack/exceptions.py", line 205, in raise_from_response
    http_status=http_status, request_id=request_id
HttpException: HttpException: Unknown error

Service logs:

masakari-api:

May 22 00:36:59 ubuntu masakari-api[817]: 2018-05-22 00:36:59.422 DEBUG masakari.masakari_api.wsgi.server [-] (2785) accepted ('192.168.108.132', 39654) from (pid=2785) server /usr/local/lib/python2.7/dist-packages/eventlet/wsgi.py:883
May 22 00:36:59 ubuntu masakari-api[817]: 2018-05-22 00:36:59.679 WARNING keystonemiddleware.auth_token [-] Identity response: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}}: Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-d737b6bf-d9aa-4060-91ab-e591ec77a89b)
May 22 00:36:59 ubuntu masakari-api[817]: 2018-05-22 00:36:59.766 WARNING keystonemiddleware.auth_token [-] Identity response: {"error": {"message": "The request you have made requires authentication.", "code": 401, "title": "Unauthorized"}}: Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-1baa575a-dbb5-4251-8563-906e2725280e)
May 22 00:36:59 ubuntu masakari-api[817]: 2018-05-22 00:36:59.767 CRITICAL keystonemiddleware.auth_token [-] Unable to validate token: Identity server rejected authorization necessary to fetch token data: ServiceError: Identity server rejected authorization necessary to fetch token data
May 22 00:36:59 ubuntu masakari-api[817]: 2018-05-22 00:36:59.768 INFO masakari.masakari_api.wsgi.server [-] 192.168.108.132 "GET /v1/5da0b9234bc7401baeaf2464ded87fa5/segments HTTP/1.1" status: 503 len: 434 time: 0.3281999

Keystone service:

May 22 00:29:53 ubuntu <email address hidden>[67860]: DEBUG keystone.auth.core [None req-c124ac51-11f1-49e0-a14f-c7c6b4cfa8ca None None] MFA Rules not processed for user `ddf7da81583d440ca848a668b023a447`. Rule list: `[]` (Enabled: `True`). {{(pid=67863) check_auth_methods_against_rules /opt/stack/keystone/keystone/auth/core.py:454}}
May 22 00:29:53 ubuntu <email address hidden>[67860]: DEBUG keystone.common.token_utils [None req-c124ac51-11f1-49e0-a14f-c7c6b4cfa8ca 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=67863) load_keys /opt/stack/keystone/keystone/common/token_utils.py:306}}
May 22 00:29:53 ubuntu <email address hidden>[67860]: [pid: 67863|app: 0|req: 981/1948] 192.168.108.132 () {62 vars in 1118 bytes} [Tue May 22 00:29:53 2018] POST /identity/v3/auth/tokens => generated 4057 bytes in 92 msecs (HTTP/1.1 201) 6 headers in 385 bytes (1 switches on core 0)
May 22 00:29:53 ubuntu <email address hidden>[67860]: INFO keystone.common.wsgi [None req-05d36133-502b-4a02-9d1f-4d0dadfa6983 None None] POST http://192.168.108.132/identity/v3/auth/tokens
May 22 00:29:53 ubuntu <email address hidden>[67860]: WARNING keystone.common.wsgi [None req-05d36133-502b-4a02-9d1f-4d0dadfa6983 None None] Authorization failed. The request you have made requires authentication. from 192.168.108.132: Unauthorized: The request you have made requires authentication.
May 22 00:29:53 ubuntu <email address hidden>[67860]: [pid: 67864|app: 0|req: 968/1949] 192.168.108.132 () {62 vars in 1164 bytes} [Tue May 22 00:29:53 2018] POST /identity/v3/auth/tokens => generated 114 bytes in 120 msecs (HTTP/1.1 401) 6 headers in 253 bytes (1 switches on core 0)
May 22 00:29:53 ubuntu <email address hidden>[67860]: INFO keystone.common.wsgi [None req-bea3a2ab-37c3-46ba-be34-83a078837618 None None] POST http://192.168.108.132/identity/v3/auth/tokens

NOTE:
Other commands like 'nova list', 'cinder list' are working fine.

Observation:
============

If you set "ENABLE_HTTPD_MOD_WSGI_SERVICES" to True or remove it from local.conf as
its default value is True masakari commands executes successfully without error.

Environment details:

devstack:
stable/queens

commit fec37dada38c4ac3023abc740a9c018bf32bb198
Author: Daniel Mellado <email address hidden>
Date: Thu Apr 12 11:41:59 2018 -0400

    Apply contraints to tempest plugins

    This commit applies the constraints for the tempest plugin installation
    so they won't go over the upper reqs.

    Closes-Bug: 1763436
    Change-Id: I5cf91157bbdae79dec01d5b3db32efea21f1b2b7
    (cherry picked from commit dc5d88bc0b2233ee8490d31ce67d6a8f6e503b23)

masakari:
stable/queens

commit 7ba3de5544759a62450a3ec13cb840652ebcff52
Author: OpenStack Release Bot <email address hidden>
Date: Sat Mar 3 13:52:02 2018 +0000

    Update UPPER_CONSTRAINTS_FILE for stable/queens

    The new stable upper-constraints file is only available
    after the openstack/requirements repository is branched.
    This will happen around the RC1 timeframe.

    Recheck and merge this change once the requirements
    repository has been branched.

    The CI system will work with this patch before the requirements
    repository is branched because zuul configues the job to run
    with a local copy of the file and defaults to the master branch.
    However, accepting the patch will break the test configuration
    on developers' local systems, so please wait until after the
    requirements repository is branched to merge the patch.

    Change-Id: I133002dd6c6dcc1c148d23d936883cf4a750f4ac

[Radosław Piliszek (yoctozepto)]

very old and unknown how to reproduce