kamax-matrix / matrix-synapse-rest-password-provider

Password Provider for Synapse fetching data from a REST endpoint
GNU Affero General Public License v3.0
36 stars 41 forks source link

Silent failure on bad endpoint? #9

Closed killua-eu closed 5 years ago

killua-eu commented 5 years ago

While testing the behavior of the provider, I accidentally stumbled upon a silent failure (synapse 0.99.3 on ubuntu 18.04), when the endpoint doesnt serve an expected response. The configuration for pw providers is

password_providers:
  - module: "shared_secret_authenticator.SharedSecretAuthenticator"
    config:
      sharedSecret: iitruitrrtriutrietoieruto
  - module: "rest_auth_provider.RestAuthProvider"
    config:
      endpoint: https://example.com/
      policy:
        registration:
          username:
            enforceLowercase: False
          profile:
            name: True
        login:
          profile:
            name: False

that for logging

loggers:
    synapse:
        level: INFO
    synapse.storage.SQL:
        level: INFO
    rest_auth_provider:
        level: INFO
        handlers: [file, console]
    shared_secret_authenticator:
        level: INFO
        handlers: [file, console]

While logging in, I get:

/opt/venvs/matrix-synapse/bin/python -m synapse.app.homeserver --config-path=/etc/matrix-synapse/homeserver.yaml --config-path=/etc/matrix-synapse/conf.d/
2019-04-19 21:10:14,168 - root - 211 - WARNING - None- ***** STARTING SERVER *****
2019-04-19 21:10:14,178 - root - 214 - WARNING - None- Server /opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/app/homeserver.py version 0.99.3
2019-04-19 21:10:14,187 - twisted - 242 - WARNING - None- /opt/venvs/matrix-synapse/lib/python3.6/site-packages/psycopg2/__init__.py:144: builtins.UserWarning: The psycopg2 wheel package will be renamed from release 2.8; in order to keep installing from binary please use "pip install psycopg2-binary" instead. For details see: <http://initd.org/psycopg/docs/install.html#binary-install-from-pypi>.
2019-04-19 21:12:14,247 - synapse.storage._base - 401 - WARNING - - Starting db txn 'update_presence' from sentinel context
2019-04-19 21:12:14,247 - synapse.storage._base - 437 - WARNING - - Starting db connection from sentinel context: metrics will be lost
2019-04-19 21:13:05,805 - synapse.http.server - 112 - ERROR - POST-53- Failed handle request via 'LoginRestServlet': <XForwardedForRequest at 0x7f24d441b128 method='POST' uri='/_matrix/client/r0/login' clientproto='HTTP/1.1' site=8008>
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
    yield h(self, request)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/http/server.py", line 316, in _async_render
    callback_return = yield callback(request, **kwargs)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/client/v1/login.py", line 149, in on_POST
    result = yield self._do_other_login(login_submission)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/client/v1/login.py", line 246, in _do_other_login
    login_submission,
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/handlers/auth.py", line 679, in validate_login
    qualified_user_id, password,
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/rest_auth_provider.py", line 50, in check_password
    r = r.json()
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/requests/models.py", line 897, in json
    return complexjson.loads(self.text, **kwargs)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/simplejson/__init__.py", line 518, in loads
    return _default_decoder.decode(s)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/simplejson/decoder.py", line 370, in decode
    obj, end = self.raw_decode(s)
  File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/simplejson/decoder.py", line 400, in raw_decode
    return self.scan_once(s, idx=_w(s, idx).end())
simplejson.errors.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
^C2019-04-19 21:13:12,347 - synapse.storage._base - 401 - WARNING - - Starting db txn 'update_presence' from sentinel context
2019-04-19 21:13:12,348 - synapse.storage._base - 437 - WARNING - - Starting db connection from sentinel context: metrics will be lost
2019-04-19 21:13:12,363 - synapse.http.site - 203 - WARNING - GET-48- Error processing request <XForwardedForRequest at 0x7f24d441f2e8 method='GET' uri='/_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_3700_0_6_24_1_1_33_1' clientproto='HTTP/1.1' site=8008>: <class 'twisted.internet.error.ConnectionLost'> Connection to the other side was lost in a non-clean fashion: Connection lost.
2019-04-19 21:13:12,364 - synapse.http.site - 203 - WARNING - GET-50- Error processing request <XForwardedForRequest at 0x7f24d43d37f0 method='GET' uri='/_matrix/client/r0/sync?filter=%7B%7D&timeout=30000&since=s52_3700_0_6_24_1_1_33_1' clientproto='HTTP/1.1' site=8008>: <class 'twisted.internet.error.ConnectionLost'> Connection to the other side was lost in a non-clean fashion: Connection lost.
2019-04-19 21:13:12,365 - synapse.http.site - 203 - WARNING - GET-47- Error processing request <XForwardedForRequest at 0x7f24da7b5f28 method='GET' uri='/_matrix/client/r0/sync?filter=0&timeout=30000&since=s52_3700_0_6_24_1_1_33_1' clientproto='HTTP/1.1' site=8008>: <class 'twisted.internet.error.ConnectionLost'> Connection to the other side was lost in a non-clean fashion: Connection lost.

Would you mind trying if you can reproduce this?

maxidorius commented 5 years ago

What do you see in response of the Matrix /login endpoint exactly (status, headers, body) in your case?

killua-eu commented 5 years ago

In my case I just copied and pasted a wrong url (without noticing) pointing to an instance of wekan. The response was

HTTP/1.1 200 OK
Content-Encoding: gzip
Content-Type: text/html; charset=utf-8
Date: Sat, 20 Apr 2019 08:20:17 GMT
Transfer-Encoding: chunked
Vary: Accept-Encoding
X-Frame-Options: ALLOW-FROM 

<!DOCTYPE html>
<html>
<head>
  <link rel="stylesheet" type="text/css" class="__meteor-css__" href="/aed027224166c3c59a4159d119050f565065cb40.css?meteor_css_resource=true">
<title></title><meta name="viewport" content="maximum-scale=1.0,width=device-width,initial-scale=1.0,user-scalable=0"><meta http-equiv="X-UA-Compatible" content="IE=edge"><link rel="shortcut icon" href="/wekan-favicon.png"><link rel="apple-touch-icon" href="/wekan-favicon.png"><link rel="mask-icon" href="/wekan-logo-150.svg"><link rel="manifest" href="/wekan-manifest.json">

</head>
<body>

  <script type="text/javascript">__meteor_runtime_config__ = JSON.parse(decodeURIComponent("__SNIP_AND_REMOVE__"))</script>

  <script type="text/javascript" src="/20e28275f75243bc75d3915c5a8326100081ec26.js?meteor_js_resource=true"></script>

</body>
</html>

I found the misconfiguration easily enough, but the logged output/error wasn't really helpful.

maxidorius commented 5 years ago

I meant the answer from the Matrix API, not the backend API. The issue title says "Failed silently" - I would like to be sure of what synapse returned to the client in this case.

killua-eu commented 5 years ago

Oh, tried that from Riot and got something like "unknown" response or error. I didn't expect the client would get a meaningful message back. I'll try to retry when back home

maxidorius commented 5 years ago

So far all I see is the expected behaviour: the configuration does not point towards a valid base URL.

Synapse does not return anything meaningful even thought this return the exact error.

maxidorius commented 5 years ago

@killua-eu Any news?

maxidorius commented 5 years ago

Closing due to inactivity from OP. Please re-open if needed.