Non-obvious error message when trying to login with user who is lacking permissions in RBAC service

[Vladimir Grevtsev]

tl;dr: user is getting error message instead of being authenticated in the MAAS:

"Error getting login link:
The requested URL was not found on the server. If you entered the URL manually please check your spelling and try again."

Following candid.yaml is used: https://pastebin.canonical.com/p/spQsPYfxTR/

Steps to reproduce:

1) Login with admin/admin user to the MAAS, everything is OK
2) Logout
3) Login with <email address hidden> user, Candid will tell "authentication succeeded", however MAAS will stay on initial "Go to the login page" error
4) After some time an error message "error getting login link" would be shown.

In the same time, in regiond.log:

2019-10-08 11:31:09 maasserver: [error] ################################ Exception: The requested URL was not found on the server. If you entered the URL manually please check your spelling and try again. ################################
2019-10-08 11:31:09 maasserver: [error] Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/django/core/handlers/base.py", line 185, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/usr/lib/python3/dist-packages/maasserver/utils/views.py", line 277, in view_atomic_with_post_commit_savepoint
    return view_atomic(*args, **kwargs)
  File "/usr/lib/python3.6/contextlib.py", line 52, in inner
    return func(*args, **kwds)
  File "/usr/lib/python3/dist-packages/maasserver/macaroon_auth.py", line 162, in __call__
    user = authenticate(request, identity=auth_info.identity)
  File "/usr/lib/python3/dist-packages/django/contrib/auth/__init__.py", line 70, in authenticate
    user = _authenticate_with_backend(backend, backend_path, request, credentials)
  File "/usr/lib/python3/dist-packages/django/contrib/auth/__init__.py", line 116, in _authenticate_with_backend
    return backend.authenticate(*args, **credentials)
  File "/usr/lib/python3/dist-packages/maasserver/macaroon_auth.py", line 84, in authenticate
    user, external_auth_info, force_check=True):
  File "/usr/lib/python3/dist-packages/maasserver/macaroon_auth.py", line 356, in validate_user_external_auth
    auth_info, user.username, client=rbac_client)
  File "/usr/lib/python3/dist-packages/maasserver/macaroon_auth.py", line 408, in _validate_user_rbac
    client.get_user_details(username))
  File "/usr/lib/python3/dist-packages/maasserver/rbac.py", line 75, in get_user_details
    details = self._request('GET', url)
  File "/usr/lib/python3/dist-packages/maasserver/macaroon_auth.py", line 292, in _request
    raise APIError(resp.status_code, content.get('message'))
maasserver.macaroon_auth.APIError: The requested URL was not found on the server. If you entered the URL manually please check your spelling and try again.

canonical-rbac.uwgsi logs:

Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: 2019-10-08 11:47:40 - INFO - request - [5742068113befe1e89e31a387c7ce615] - 172.27.84.1 "GET https://maas.orangebox84.ru:5000/api/service/v1/resources/maas/allowed-for-user?u=vgrevtsev%40localdomain.com&p=admin HTTP/1.1" 401 779 0.019
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: [pid: 2161|app: 0|req: 19413/35855] 172.27.84.1 () {42 vars in 700 bytes} [Tue Oct 8 11:47:40 2019] GET /api/service/v1/resources/maas/allowed-for-user?u=vgrevtsev%40localdomain.com&p=admin => generated 779 bytes in 19 msecs (HTTP/1.1 401) 4 headers in 158 bytes (2 switches on core 0)
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: 2019-10-08 11:47:40 - INFO - request - [9ae0be16974683eeb475b2686eeb7984] - 172.27.84.1 "GET https://maas.orangebox84.ru:5000/api/service/v1/resources/maas/allowed-for-user?u=vgrevtsev%40localdomain.com&p=admin HTTP/1.1" 200 13 0.043
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: [pid: 2161|app: 0|req: 19414/35856] 172.27.84.1 () {44 vars in 1531 bytes} [Tue Oct 8 11:47:40 2019] GET /api/service/v1/resources/maas/allowed-for-user?u=vgrevtsev%40localdomain.com&p=admin => generated 13 bytes in 43 msecs (HTTP/1.1 200) 3 headers in 119 bytes (2 switches on core 3)
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: 2019-10-08 11:47:40 - INFO - request - [251fe891c01b3c74f6f3d7b948b072f5] - 172.27.84.1 "GET https://maas.orangebox84.ru:5000/api/service/v1/resources/resource-pool/allowed-for-user?u=vgrevtsev%40localdomain.com&p=view&p=view-all&p=deploy-machines&p=admin-machines HTTP/1.1" 200 73 0.078
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: [pid: 2161|app: 0|req: 19415/35857] 172.27.84.1 () {44 vars in 1639 bytes} [Tue Oct 8 11:47:40 2019] GET /api/service/v1/resources/resource-pool/allowed-for-user?u=vgrevtsev%40localdomain.com&p=view&p=view-all&p=deploy-machines&p=admin-machines => generated 73 bytes in 78 msecs (HTTP/1.1 200) 3 headers in 119 bytes (2 switches on core 2)
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: 2019-10-08 11:47:40 - INFO - request - [7ee186d054f9cfd84d12ab1dad302f51] - 172.27.84.1 "GET https://maas.orangebox84.ru:<email address hidden> HTTP/1.1" 404 150 0.035
Oct 08 11:47:40 OrangeBox84 canonical-rbac.uwsgi[1213]: [pid: 2161|app: 0|req: 19416/35858] 172.27.84.1 () {44 vars in 1456 bytes} [Tue Oct 8 11:47:40 2019] GET /api/service/v1/user/vgrevtsev%40localdomain.com => generated 150 bytes in 36 msecs (HTTP/1.1 404) 3 headers in 127 bytes (2 switches on core 1)
Oct 08 11:48:05 OrangeBox84 canonical-rbac.uwsgi[1213]: 2019-10-08 11:48:05 - INFO - request - [8ac86e3b30f3da8f654352aabdfa0a84] - 172.27.84.1 "GET https://maas.orangebox84.ru:5000/auth/discharge/info HTTP/1.1" 200 73 0.005
Oct 08 11:48:05 OrangeBox84 canonical-rbac.uwsgi[1213]: [pid: 2161|app: 0|req: 19417/35859] 172.27.84.1 () {42 vars in 571 bytes} [Tue Oct 8 11:48:05 2019] GET /auth/discharge/info => generated 73 bytes in 5 msecs (HTTP/1.1 200) 3 headers in 119 bytes (2 switches on core 0)
Oct 08 11:48:32 OrangeBox84 canonical-rbac.uwsgi[1213]: 2019-10-08 11:48:32 - INFO - request - [b2fe939d3dad63d7be879f27ecde1932] - 172.27.84.1 "GET https://maas.orangebox84.ru:5000/auth/discharge/info HTTP/1.1" 200 73 0.004
Oct 08 11:48:32 OrangeBox84 canonical-rbac.uwsgi[1213]: [pid: 2161|app: 0|req: 19418/35860] 172.27.84.1 () {42 vars in 571 bytes} [Tue Oct 8 11:48:32 2019] GET /auth/discharge/info => generated 73 bytes in 4 msecs (HTTP/1.1 200) 3 headers in 119 bytes (2 switches on core 3)

Packages:

$ dpkg -l | grep maas
ii maas 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all "Metal as a Service" is a physical cloud and IPAM
ii maas-cli 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS client and command-line interface
ii maas-common 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS server common files
ii maas-dhcp 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS DHCP server
ii maas-proxy 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS Caching Proxy
ii maas-rack-controller 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all Rack Controller for MAAS
ii maas-region-api 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all Region controller API service for MAAS
ii maas-region-controller 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all Region Controller for MAAS
ii python3-django-maas 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS server Django web framework (Python 3)
ii python3-maas-client 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS python API client (Python 3)
ii python3-maas-provisioningserver 2.6.1-7832-g17912cdc9-0ubuntu1~18.04.1 all MAAS server provisioning libraries (Python 3)

$ snap list
Name Version Rev Tracking Publisher Notes
candid v1.2.2 550 stable canonical✓ -
canonical-rbac 1.0.1-394-g.1950b9b 139 - canonical✓ -

[Vladimir Grevtsev (vlgrevtsev)]

Subscribing field-high as this is affecting ongoing delivery

[Vladimir Grevtsev (vlgrevtsev)]

Update: This user has appeared in RBAC without any permissions set. However, when I enabled some checkboxes for that user, he was able to login.

So can we improve this output to let user understand he's lacking RBAC permissions, rather than seeing standard 404 error output without any clue what exactly went wrong?

[Vladimir Grevtsev (vlgrevtsev)]

Any news on this?

[Huw Wilkins (huwshimi)]

I am seeing a similar issue with a user that has not been added to the service in RBAC.

If I try and log in I see a 500 from /MAAS/accounts/discharge-request/ with the response body of "The requested URL was not found on the server. If you entered the URL manually please check your spelling and try again."

[Alberto Donato (ack)]

@huwshimi can you please attach (or paste) logs from regiond.log when this happens?

[Huw Wilkins (huwshimi)]

Alberto, here is the relevant part of the logs: https://pastebin.canonical.com/p/qTnKHHp9X2/