Loop control for failed logins

[minsis]

Something happened with my docker setup when I enabled rbac with LDAP. I'm still trying to troubleshoot why this is happening but one of the containers is continually trying to authenticate my user and basically locked out my account. My password was reset by our IT team but my account is continually locked out. I had to disable LDAP to get this to stop. There needs to be some kind of loop control in place to where the auth container isn't just bombarding the LDAP server every 5 seconds to try and auth someone.

Here's the events in order:

1. LDAP was enabled and working correctly
2. RBAC was then enabled but wasn't running correctly because I didn't have "backend" set
3. Set the backend to "default"
4. My account in LDAP is now locked out.
5. I restarted containers, rebuilt containers, closed all browsers, etc but I couldn't recover this. Eventually had to disable LDAP all together to get it to stop.

Version:
st2 3.4dev (03869c913), on Python 3.6.9

I'm adding this to the release discussion, but the issue of adding some loop control I'm adding here.

[blag]

Can you test this in the same environment, with the same configuration, with StackStorm v3.3? I'd like to figure out if this is a regression for v3.4 or not.

[minsis]

I dont have the enterprise version of 3.3.

[minsis]

Also, I honestly think it was more to do with the RBAC being enabled. LADP has been enabled for over a week, it wasn't until RBAC got enable that everything blew up. Mainly because I didn't have a backend set (which is another thing I'm going to put in for in the rbac repo)

[blag]

Oh, right, you would have to check v3.2, and for that you would need a license.

Alright, well please troubleshoot/debug this further and let us know if it's a bug. For now, since it sounds like a misconfiguration issue, I'm not going to consider it a v3.4 release blocker.

[minsis]

I'm just not sure how to class this as a bug or misconfigure or a bit of both. In the beginning it was probably a misconfigure of RBAC that created some domino effect somewhere and I'm having a difficult time pinpointing this.

Right now I'm stuck because my credentials are cached somewhere and if I reenable ldap and/or rbac the st2auth just starts hammering on the LDAP server every 5 seconds to try and auth my old cached password and I can't seem to get this cleared out.

I assumed that either redis or rabbitmq was caching this login, but restarting those containers doesn't clear anything out.

[blag]

@Kami If you have time, can we get your attention on this?

[Kami]

First step would probably be to enable debug log level for ldap backend / whole StackStorm installation to see if there is anything useful in there.

You say auth backend is hammering LDAP. afaik, auth backend should only try to talk to LDAP when you try to authenticate against st2auth (either via CLI, API call to st2auth or similar). User group membership should also only be synced after successful authentication.

So would also be good to try to figure out why st2auth is constantly calling to LDAP backend.

Only difference when enabling RBAC is that st2auth should also try to retrieve user group membership after successful auth.

Please also attach log files for all the affected services with sensitive data masked (especially st2auth and st2api).

[minsis]

I had everything shutdown last night except rabbitmq and mongo. I tried again this morning with starting up the apps and something is still cached with my username. LDAP debugging has already been turned on, but I also turned on system debugging. The API log since startup has a lot of info in it but none of it shows that its trying to auth, its just showing that its registering triggers and packs, etc. I tried this with both RBAC disabled and RBAC enabled and I get the same results.

ldap logs

2021-03-02 14:51:40,079 DEBUG [-] Match path: /tokens
2021-03-02 14:51:40,079 INFO [-] <--reqid2--> - POST /tokens with query={} (method='POST',path='/tokens',remote_addr='<--dockerip-->',query={},request_id='<--reqid2-->')
2021-03-02 14:51:40,079 DEBUG [-] Received call with WebOb: POST /tokens HTTP/1.0
Accept: */*
Accept-Encoding: gzip, deflate
Authorization: Basic <--token-->
Connection: keep-alive
Content-Length: 2
Content-Type: application/json
Host: st2auth:9100
User-Agent: python-requests/2.23.0
X-Request-Id: <--reqid2-->

{}
2021-03-02 14:51:40,080 DEBUG [-] Match path: /tokens
2021-03-02 14:51:40,080 DEBUG [-] Parsed endpoint: {'x-log-result': False, 'operationId': 'st2auth.controllers.v1.auth:token_controller.post', 'description': 'Authenticates a user with `Authorization` header and returns a `token`\nobject.\n', 'parameters': [{'name': 'authorization', 'in': 'header', 'description': 'base64 encoded string containing login and password', 'type': 'string'}, {'name': 'x-forwarded-for', 'in': 'header', 'description': 'set externally to indicate real source of the request', 'type': 'string'}, {'name': 'request', 'in': 'body', 'description': 'Lifespan of the token', 'schema': {'$ref': '#/definitions/TokenRequest'}}], 'x-parameters': [{'name': 'remote_addr', 'in': 'environ', 'description': 'source of the request', 'type': 'string'}, {'name': 'remote_user', 'in': 'environ', 'description': 'set externally to indicate user identity in case of proxy auth', 'type': 'string'}], 'responses': {'201': {'description': 'New token has been created', 'schema': {'$ref': '#/definitions/Token'}, 'headers': {'x-api-url': {'type': 'string'}}, 'examples': {'application/json': {'user': 'st2admin', 'token': '<--token-->', 'expiry': '2016-05-28T12:39:28.650231Z', 'id': '<--id-->', 'metadata': {}}}}, '401': {'description': 'Invalid or missing credentials has been provided', 'schema': {'$ref': '#/definitions/Error'}, 'examples': {'application/json': {'faultstring': 'Invalid or missing credentials'}}}, 'default': {'description': 'Unexpected error', 'schema': {'$ref': '#/definitions/Error'}}}, 'security': []}
2021-03-02 14:51:40,080 DEBUG [-] Parsed path_vars: {}
2021-03-02 14:51:40,080 DEBUG [-] Missing x-api-model definition for st2auth.controllers.v1.auth:token_controller.post, using generic Body model.
2021-03-02 14:51:40,107 DEBUG [-] Getting LDAP groups for user "<--my-ldap-username-->" from cache
2021-03-02 14:51:40,107 DEBUG [-] Found LDAP groups cache for user "<--my-ldap-username-->"
2021-03-02 14:51:40,107 DEBUG [-] Verifying user group membership using "and" behavior (user needs to be member of all the following groups "['<--ldap-group-->']" for authentication to succeeed)
2021-03-02 14:51:40,163 ERROR [-] Failed authenticating user "<--my-ldap-username-->".
Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth_ldap/ldap_backend.py", line 195, in authenticate
    connection.simple_bind_s(user_dn, password)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/ldap/ldapobject.py", line 444, in simple_bind_s
    resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all=1,timeout=self.timeout)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/ldap/ldapobject.py", line 749, in result3
    resp_ctrl_classes=resp_ctrl_classes
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/ldap/ldapobject.py", line 756, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
    reraise(exc_type, exc_value, exc_traceback)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/ldap/compat.py", line 44, in reraise
    raise exc_value
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
    result = func(*args,**kwargs)
ldap.INVALID_CREDENTIALS: {'desc': 'Invalid credentials', 'info': '80090308: LdapErr: DSID-0C090400, comment: AcceptSecurityContext error, data 775, v1db1'}
2021-03-02 14:51:40,163 AUDIT [-] Invalid credentials provided (auth_backend='LDAPAuthenticationBackend',remote_addr='<--dockerip-->')
2021-03-02 14:51:40,163 ERROR [-] Failed to call controller function "post" for operation "st2auth.controllers.v1.auth:token_controller.post": Invalid or missing credentials
Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 516, in __call__
    resp = func(**kw)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth/controllers/v1/auth.py", line 79, in post
    **kwargs)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth/handlers.py", line 225, in handle_auth
    abort_request()
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth/handlers.py", line 39, in abort_request
    return abort(status_code, message)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 79, in abort
    raise exc.status_map[status_code](message)
webob.exc.HTTPUnauthorized: Invalid or missing credentials
2021-03-02 14:51:40,164 DEBUG [-] API call failed: Invalid or missing credentials (exception_class='HTTPUnauthorized',exception_message='Invalid or missing credentials',exception_data={'_status': '401 Unauthorized', '_headers': None, '_headerlist': [('Content-Type', 'text/html; charset=UTF-8'), ('Content-Length', '0')], 'conditional_response': False, '_app_iter': [b''], 'detail': 'Invalid or missing credentials', 'comment': 'Invalid or missing credentials'})
2021-03-02 14:51:40,164 DEBUG [-] Traceback (most recent call last):
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/middleware/error_handling.py", line 49, in __call__
    return self.app(environ, start_response)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 599, in as_wsgi
    resp = self(req)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 524, in __call__
    raise e
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 516, in __call__
    resp = func(**kw)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth/controllers/v1/auth.py", line 79, in post
    **kwargs)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth/handlers.py", line 225, in handle_auth
    abort_request()
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2auth/handlers.py", line 39, in abort_request
    return abort(status_code, message)
  File "/opt/stackstorm/st2/lib/python3.6/site-packages/st2common/router.py", line 79, in abort
    raise exc.status_map[status_code](message)
webob.exc.HTTPUnauthorized: Invalid or missing credentials

[minsis]

I should also mention this happens when both ldap and RBAC are disabled.

[auth]
mode = standalone
backend = ldap
backend_kwargs = <--ldap-info-->
enable = False
use_ssl = False
logging = /etc/st2/logging.auth.gunicorn.conf
debug = True

[rbac]
enable = False
backend = default

[minsis]

Ok so I think I may have pinpointed the issue. I started up all the containers but when I stop the st2client container it no longer is trying to auth every 5 seconds. So something in that container has my credentials cached and wont release it. So maybe its the st2client that needs to have loop control and not the this package. This could just be specific to the docker version of this setup unless a local install of st2client would do the same thing.

So now the question is: how do I clear the st2client cache so I can revalidate my login?

[Kami]

Client does cache auth token (~/.st2/token-<username>), but if auth token is cached and non-expired, it will try to use that one to directly talk to StackStorm API and will simply skip st2auth.

Client (CLI) will also cache the credentials itself (username + password in ~/.st2/config) if you use --write-password flag with st2 login command, but that's not a default behavior.

And even if the credentials are cached, there isn't any logic in the client to perform authentication request every 5 seconds or similar - it will only try to authenticate when executing a CLI command.

So this "trying to auth every 5 seconds" almost makes it look like there is some kind of cron job or similar running which is constantly calling some st2 CLI command with invalid credentials in ~/.st2/config.

/cc @blag Just FYI, at this point it doesn't look like a bug in CLI or similar.